fix: report bounded ASCII Box cleanup progress

CHANGELOG.md

@@ -2,6 +2,7 @@
 
 ## Unreleased
 
+- Show periodic ASCII Box cleanup progress and preserve the deletion phase and last observed status on timeout, while retaining incomplete cleanup claims. [PR 1789](https://github.com/openclaw/crabbox/pull/1789). Thanks @shunkakinoki.
 - Avoid unnecessary Git metadata lookups during configuration loading, lease claim refreshes, and sync planning while preserving repository and credential trust boundaries. [PR 1783](https://github.com/openclaw/crabbox/pull/1783). Thanks @steipete.
 - Preserve finish-submission and receipt-verification errors, attempt counts, and recovery guidance when terminal run recording times out, without changing retry limits or receipt verification.
 - Closed and joined lease-owned SSH connection masters after confirmed brokered deletion, preserving native connection reuse and lease/host-key isolation while retaining failed local cleanup for a local-only retry. [PR 1774](https://github.com/openclaw/crabbox/pull/1774). Thanks @steipete.

docs/providers/ascii-box.md

@@ -115,6 +115,15 @@ BOX_ORG
    lookups, and cancellation retain the claim without recording completion. The
    shared native CLI SSH key is retained.
 
+Cleanup reports its current native-call phase and elapsed time at roughly
+ten-second intervals, including while a native command is blocked. A remaining
+budget is shown only when that command's context has a deadline; progress does
+not extend it or impose a new whole-command timeout. Claim-lock waits and
+best-effort remote teardown are outside this native-call progress reporter.
+Deletion-wait failures retain the exact operation and its last validated status
+in the error. Native command capture is capped at 8 MiB per stream; oversized or
+incomplete output is an error, never evidence of completed deletion.
+
 If this release observes a valid native deletion acceptance but cannot finish
 waiting because of a timeout, cancellation, or operation lookup failure, it
 durably records the exact operation ID and its claim binding before returning

internal/providers/asciibox/backend.go

@@ -111,6 +111,7 @@ func (b *backend) Acquire(ctx context.Context, req AcquireRequest) (LeaseTarget,
 func (b *backend) rollbackBox(ctx context.Context, client api, leaseID string, box boxData, claim LeaseClaim, exists bool) error {
 	cleanupCtx, cancel := context.WithTimeout(context.WithoutCancel(ctx), boxReleaseTimeout)
 	defer cancel()
+	cleanupCtx = withBoxCleanupProgress(cleanupCtx, b.rt.Stderr)
 	if exists {
 		if claim.LeaseID != leaseID || box.ID != box.createdID || !concreteBoxID(box.createdID) {
 			return exit(2, "ascii-box rollback has no matching original publication identity")
@@ -139,6 +140,9 @@ func (b *backend) rollbackBox(ctx context.Context, client api, leaseID string, b
 }
 
 func (b *backend) Resolve(ctx context.Context, req ResolveRequest) (LeaseTarget, error) {
+	if req.ReleaseOnly {
+		ctx = withBoxCleanupProgress(ctx, b.rt.Stderr)
+	}
 	cfg, err := b.configForRun()
 	if err != nil {
 		return LeaseTarget{}, err
@@ -316,6 +320,7 @@ func (b *backend) ReleaseLease(ctx context.Context, req ReleaseLeaseRequest) err
 	}
 	ctx, cancel := context.WithTimeout(ctx, boxReleaseTimeout)
 	defer cancel()
+	ctx = withBoxCleanupProgress(ctx, b.rt.Stderr)
 	return releaseClaimedBox(ctx, client, claim, func(box boxData) {
 		if req.GuardedRemoteCleanup != nil {
 			lease := req.Lease

internal/providers/asciibox/backend_test.go

@@ -86,6 +86,11 @@ func TestClientUsesOfficialAsciiBoxCLI(t *testing.T) {
 	if !reflect.DeepEqual(runner.commands, want) {
 		t.Fatalf("commands=%v want=%v", runner.commands, want)
 	}
+	for _, req := range runner.requests {
+		if req.MaxCapturedOutputBytes <= 0 || req.MaxCapturedOutputBytes > 8<<20 || req.DisableOutputCapture || req.Stdout != nil || req.Stderr != nil {
+			t.Fatalf("native command must use bounded, non-streaming capture: %+v", req.Args)
+		}
+	}
 	for _, env := range runner.env {
 		if !hasEnv(env, "BOX_API_KEY=box_key") {
 			t.Fatal("child environment missing the synthetic BOX_API_KEY")
@@ -286,6 +291,135 @@ func TestReleaseBoxPendingOperationHonorsDeadline(t *testing.T) {
 	}
 }
 
+func TestReleaseBoxReportsLastDeletionStatusWhenNativeLookupTimesOut(t *testing.T) {
+	ctx, cancel := context.WithTimeout(context.Background(), 500*time.Millisecond)
+	defer cancel()
+	lookups := 0
+	runner := &releaseCommandRunner{configPath: filepath.Join(t.TempDir(), "config.json"), outcomes: map[string][]commandOutcome{
+		"stop":   {{result: LocalCommandResult{}}},
+		"delete": {deletionOutcome(testDeletionID, "bx_guard", "box", "pending")},
+		"deletion": {
+			deletionOutcome(testDeletionID, "bx_guard", "box", "blocked"),
+			{err: context.DeadlineExceeded},
+		},
+	}, onAction: func(action string) {
+		if action == "deletion" {
+			lookups++
+			if lookups == 2 {
+				<-ctx.Done()
+			}
+		}
+	}}
+	c := &client{apiKey: "box_key", apiURL: "https://ascii.dev", cliPath: "box", home: t.TempDir(), runner: runner, releasePollInterval: time.Nanosecond}
+	err := c.ReleaseBox(ctx, "bx_guard", func(context.Context) error { return nil })
+	if !errors.Is(err, context.DeadlineExceeded) {
+		t.Fatalf("lost deadline cause: %v", err)
+	}
+	for _, want := range []string{"phase=deletion-operation", testDeletionID, "last_observed_status=blocked", "retaining claim"} {
+		if !strings.Contains(err.Error(), want) {
+			t.Fatalf("missing %q in %v", want, err)
+		}
+	}
+	var incomplete *boxDeletionIncompleteError
+	if !errors.As(err, &incomplete) || incomplete.operation.ID != testDeletionID || incomplete.operation.Status != "pending" {
+		t.Fatalf("lost original accepted operation: %v", err)
+	}
+}
+
+func TestBoxCleanupProgressReportsDuringNativeCallAndJoins(t *testing.T) {
+	output := make(boxProgressOutput, 32)
+	ctx, cancel := context.WithTimeout(withBoxCleanupProgress(context.Background(), output), time.Second)
+	defer cancel()
+	ctx.Value(boxCleanupProgressKey{}).(*boxCleanupProgress).interval = 5 * time.Millisecond
+	entered := make(chan struct{})
+	runner := boxCommandRunnerFunc(func(ctx context.Context, req LocalCommandRequest) (LocalCommandResult, error) {
+		close(entered)
+		<-ctx.Done()
+		return LocalCommandResult{Stdout: "native output must not become progress"}, ctx.Err()
+	})
+	c := &client{cliPath: "box", runner: runner}
+	done := make(chan error, 1)
+	go func() { _, err := c.runPrepared(ctx, "delete", "bx_guard", "--yes"); done <- err }()
+	<-entered
+	for range 2 {
+		select {
+		case line := <-output:
+			if !strings.Contains(line, "phase=native-delete") || !strings.Contains(line, "remaining=") || strings.Contains(line, "native output") {
+				t.Fatalf("unexpected progress: %s", line)
+			}
+		case <-time.After(time.Second):
+			t.Fatal("no progress while native command was blocked")
+		}
+	}
+	cancel()
+	if err := <-done; !errors.Is(err, context.Canceled) {
+		t.Fatalf("native cancellation lost: %v", err)
+	}
+	for len(output) > 0 {
+		<-output
+	}
+	select {
+	case line := <-output:
+		t.Fatalf("progress after native command returned: %s", line)
+	case <-time.After(15 * time.Millisecond):
+	}
+}
+
+func TestBoxCleanupProgressRetainsCadenceAcrossFastPolls(t *testing.T) {
+	output := make(boxProgressOutput, 32)
+	ctx := withBoxCleanupProgress(context.Background(), output)
+	ctx.Value(boxCleanupProgressKey{}).(*boxCleanupProgress).interval = 5 * time.Millisecond
+	c := &client{cliPath: "box", runner: boxCommandRunnerFunc(func(context.Context, LocalCommandRequest) (LocalCommandResult, error) {
+		return LocalCommandResult{}, nil
+	})}
+	deadline := time.Now().Add(time.Second)
+	for len(output) < 2 && time.Now().Before(deadline) {
+		if _, err := c.runPrepared(ctx, "deletion", "status", testDeletionID); err != nil {
+			t.Fatal(err)
+		}
+		time.Sleep(2 * time.Millisecond)
+	}
+	if len(output) < 2 {
+		t.Fatal("fast native calls reset progress cadence")
+	}
+	for len(output) > 0 {
+		if line := <-output; !strings.Contains(line, "phase=deletion-operation") || strings.Contains(line, "remaining=-") {
+			t.Fatalf("unexpected progress: %s", line)
+		}
+	}
+}
+
+func TestNativeCaptureErrorCannotAuthorizeCleanupJSON(t *testing.T) {
+	for _, action := range []string{"status", "list", "deletion"} {
+		t.Run(action, func(t *testing.T) {
+			configPath := filepath.Join(t.TempDir(), "config.json")
+			runner := boxCommandRunnerFunc(func(_ context.Context, req LocalCommandRequest) (LocalCommandResult, error) {
+				current := boxCLIAction(req.Args)
+				result := LocalCommandResult{Stdout: fmt.Sprintf(`{"config":{"path":%q}}`, configPath)}
+				if current == "list" {
+					result.Stdout = `{"boxes":[],"pageInfo":{"hasMore":false}}`
+				} else if current == "deletion" {
+					result = deletionOutcome(testDeletionID, "bx_guard", "box", "completed").result
+				}
+				if current == action {
+					return result, errors.New("captured command output exceeded limit")
+				}
+				return result, nil
+			})
+			c := &client{apiKey: "box_key", apiURL: "https://ascii.dev", cliPath: "box", home: t.TempDir(), runner: runner}
+			var err error
+			if action == "deletion" {
+				_, err = c.GetDeletionOperation(context.Background(), "bx_guard", testDeletionID)
+			} else {
+				_, err = c.ListBoxes(context.Background(), true)
+			}
+			if err == nil {
+				t.Fatal("valid-looking JSON from failed capture was accepted")
+			}
+		})
+	}
+}
+
 func TestAsciiBoxBaseURLValidation(t *testing.T) {
 	for _, test := range []struct {
 		name string
@@ -865,6 +999,7 @@ func (f *fakeAPI) GetDeletionOperation(_ context.Context, targetID, operationID
 
 type fakeCommandRunner struct {
 	commands   []string
+	requests   []LocalCommandRequest
 	env        [][]string
 	configPath string
 	newStdout  string
@@ -921,6 +1056,7 @@ func snapshotGuardOutcome() commandOutcome {
 }
 
 func (r *fakeCommandRunner) Run(_ context.Context, req LocalCommandRequest) (LocalCommandResult, error) {
+	r.requests = append(r.requests, req)
 	r.commands = append(r.commands, strings.Join(append([]string{req.Name}, req.Args...), " "))
 	r.env = append(r.env, req.Env)
 	joined := strings.Join(req.Args, " ")
@@ -960,6 +1096,19 @@ func (r *fakeCommandRunner) Run(_ context.Context, req LocalCommandRequest) (Loc
 	}
 }
 
+type boxCommandRunnerFunc func(context.Context, LocalCommandRequest) (LocalCommandResult, error)
+
+func (f boxCommandRunnerFunc) Run(ctx context.Context, req LocalCommandRequest) (LocalCommandResult, error) {
+	return f(ctx, req)
+}
+
+type boxProgressOutput chan string
+
+func (out boxProgressOutput) Write(data []byte) (int, error) {
+	out <- string(data)
+	return len(data), nil
+}
+
 func hasEnv(env []string, want string) bool {
 	for _, value := range env {
 		if value == want {

internal/providers/asciibox/cleanup_progress.go

@@ -0,0 +1,94 @@
+package asciibox
+
+import (
+	"context"
+	"fmt"
+	"io"
+	"sync"
+	"time"
+)
+
+type boxCleanupProgressKey struct{}
+type boxCleanupPhaseKey struct{}
+
+type boxCleanupProgress struct {
+	mu       sync.Mutex
+	writer   io.Writer
+	started  time.Time
+	last     time.Time
+	interval time.Duration
+}
+
+func withBoxCleanupProgress(ctx context.Context, writer io.Writer) context.Context {
+	if writer == nil || ctx.Value(boxCleanupProgressKey{}) != nil {
+		return ctx
+	}
+	return context.WithValue(ctx, boxCleanupProgressKey{}, &boxCleanupProgress{
+		writer: writer, started: time.Now(), interval: 10 * time.Second,
+	})
+}
+
+func boxCleanupPhaseContext(ctx context.Context, phase string) context.Context {
+	return context.WithValue(ctx, boxCleanupPhaseKey{}, phase)
+}
+
+func boxCommandPhase(args []string) string {
+	if len(args) > 0 {
+		switch args[0] {
+		case "stop":
+			return "native-stop"
+		case "delete":
+			return "native-delete"
+		case "extend":
+			return "snapshot-recovery"
+		case "deletion":
+			return "deletion-operation"
+		}
+	}
+	return "configuration"
+}
+
+func startBoxCommandProgress(ctx context.Context, phase string) func() {
+	progress, _ := ctx.Value(boxCleanupProgressKey{}).(*boxCleanupProgress)
+	if progress == nil {
+		return func() {}
+	}
+	if override, ok := ctx.Value(boxCleanupPhaseKey{}).(string); ok {
+		phase = override
+	}
+	write := func() {
+		progress.mu.Lock()
+		defer progress.mu.Unlock()
+		now := time.Now()
+		if ctx.Err() != nil || !progress.last.IsZero() && now.Sub(progress.last) < progress.interval {
+			return
+		}
+		progress.last = now
+		remaining := "deadline=none"
+		if deadline, ok := ctx.Deadline(); ok {
+			remaining = fmt.Sprintf("remaining=%s", max(time.Duration(0), deadline.Sub(now)).Round(time.Second))
+		}
+		fmt.Fprintf(progress.writer, "ascii-box cleanup phase=%s elapsed=%s %s; waiting for native CLI\n", phase, now.Sub(progress.started).Round(time.Second), remaining)
+	}
+	// Shared cadence also reports fast polls whose individual timers never fire.
+	write()
+	stop := make(chan struct{})
+	joined := make(chan struct{})
+	go func() {
+		defer close(joined)
+		ticker := time.NewTicker(progress.interval)
+		defer ticker.Stop()
+		for {
+			select {
+			case <-stop:
+				return
+			case <-ctx.Done():
+				return
+			case <-ticker.C:
+				write()
+			}
+		}
+	}()
+	// Join before returning to core or its guarded-cleanup writer.
+	return func() { close(stop); <-joined }
+}