fix: match blacksmith sync markers

Author: steipete

CHANGELOG.md

@@ -18,6 +18,7 @@
 
 ### Fixed
 
+- Fixed the Blacksmith Testbox sync-stall guard to match current `blacksmith` CLI sync start and completion messages.
 - Fixed GCP leases so exact `--type` requests still use configured zone and Spot-to-on-demand fallback, aliases derive GCP class defaults, explicit brokered tags replace Worker default tags, custom networks and ingress policies get separate SSH firewall rules, and brokered pool views include instances outside the Worker's default zone.
 - Fixed `crabbox actions hydrate/register` so AWS Windows WSL2 leases can use Linux GitHub Actions hydration instead of being rejected as Windows targets, including root-runner and stale apt-list handling.
 - Fixed `scripts/openclaw-wsl2-tests.sh` so follow-up hydrate/run/cleanup commands keep the AWS Windows WSL2 target configuration and warmup failures print captured output.

internal/providers/blacksmith/backend.go

@@ -271,7 +271,7 @@ func (b *blacksmithBackend) runTestbox(ctx context.Context, leaseID string, comm
 	if timedOut {
 		fmt.Fprintf(
 			b.rt.Stderr,
-			"Blacksmith Testbox sync produced no post-sync output for %s; terminating local runner. "+
+			"Blacksmith Testbox sync did not print a completion marker for %s; terminating local runner. "+
 				"Rerun with CRABBOX_BLACKSMITH_SYNC_TIMEOUT_MS=0 to disable this guard.\n",
 			blacksmithSyncTimeout(os.Getenv),
 		)
@@ -344,18 +344,37 @@ func (b *blacksmithBackend) runCommandWithSyncGuard(ctx context.Context, args []
 type blacksmithSyncTracker struct {
 	mu           sync.Mutex
 	syncingSince time.Time
+	pending      string
 }
 
 func (t *blacksmithSyncTracker) observe(text string, now time.Time) {
 	t.mu.Lock()
 	defer t.mu.Unlock()
-	if strings.Contains(text, "Syncing...") {
+	t.pending += text
+	if len(t.pending) > 4096 {
+		t.pending = t.pending[len(t.pending)-4096:]
+	}
+	for {
+		i := strings.IndexByte(t.pending, '\n')
+		if i < 0 {
+			break
+		}
+		t.observeLineLocked(t.pending[:i+1], now)
+		t.pending = t.pending[i+1:]
+	}
+	if t.pending != "" {
+		t.observeLineLocked(t.pending, now)
+	}
+}
+
+func (t *blacksmithSyncTracker) observeLineLocked(line string, now time.Time) {
+	if blacksmithSyncStartPattern.MatchString(line) {
 		if t.syncingSince.IsZero() {
 			t.syncingSince = now
 		}
 		return
 	}
-	if !t.syncingSince.IsZero() && blacksmithPostSyncPattern.MatchString(text) {
+	if !t.syncingSince.IsZero() && blacksmithSyncDonePattern.MatchString(line) {
 		t.syncingSince = time.Time{}
 	}
 }

internal/providers/blacksmith/backend_test.go

@@ -34,7 +34,7 @@ type blockingSyncRunner struct{}
 
 func (blockingSyncRunner) Run(ctx context.Context, req LocalCommandRequest) (LocalCommandResult, error) {
 	if req.Stdout != nil {
-		_, _ = req.Stdout.Write([]byte("Syncing... waiting for remote workspace\n"))
+		_, _ = req.Stdout.Write([]byte("Syncing from repo root: /repo\n"))
 	}
 	<-ctx.Done()
 	return LocalCommandResult{ExitCode: 1}, ctx.Err()
@@ -319,11 +319,43 @@ func TestBlacksmithRunTerminatesSyncStall(t *testing.T) {
 	if code != 124 {
 		t.Fatalf("exit=%d want 124", code)
 	}
-	if !strings.Contains(stderr.String(), "Blacksmith Testbox sync produced no post-sync output") {
+	if !strings.Contains(stderr.String(), "Blacksmith Testbox sync did not print a completion marker") {
 		t.Fatalf("stderr=%q", stderr.String())
 	}
 }
 
+func TestBlacksmithSyncTrackerMatchesCurrentMarkers(t *testing.T) {
+	start := time.Unix(100, 0)
+	tracker := &blacksmithSyncTracker{}
+
+	tracker.observe("Syncing from repo root: /repo\n", start)
+	if !tracker.syncStalled(time.Second, start.Add(2*time.Second)) {
+		t.Fatal("sync start marker did not arm stall guard")
+	}
+
+	tracker.observe("Changes synced in 2.4s\n", start.Add(500*time.Millisecond))
+	if tracker.syncStalled(time.Second, start.Add(3*time.Second)) {
+		t.Fatal("sync completion marker did not clear stall guard")
+	}
+}
+
+func TestBlacksmithSyncTrackerHandlesSplitMarkers(t *testing.T) {
+	start := time.Unix(100, 0)
+	tracker := &blacksmithSyncTracker{}
+
+	tracker.observe("Syncing from repo", start)
+	tracker.observe(" root: /repo\n", start)
+	if !tracker.syncStalled(time.Second, start.Add(2*time.Second)) {
+		t.Fatal("split sync start marker did not arm stall guard")
+	}
+
+	tracker.observe("Changes synced", start.Add(500*time.Millisecond))
+	tracker.observe(" in 2.4s\n", start.Add(500*time.Millisecond))
+	if tracker.syncStalled(time.Second, start.Add(3*time.Second)) {
+		t.Fatal("split sync completion marker did not clear stall guard")
+	}
+}
+
 func TestBlacksmithBackendUsesInjectedCommandRunnerForListAndStatus(t *testing.T) {
 	runner := &blacksmithFuncRunner{fn: func(LocalCommandRequest) (LocalCommandResult, error) {
 		return LocalCommandResult{

internal/providers/blacksmith/helpers.go

@@ -14,11 +14,12 @@ import (
 const blacksmithTestboxProvider = "blacksmith-testbox"
 
 var (
-	blacksmithIDPattern       = regexp.MustCompile(`\btbx_[A-Za-z0-9_-]+\b`)
-	blacksmithPostSyncPattern = regexp.MustCompile(`(?i)\b(running|executing|command|pnpm|npm|yarn|bun)\b`)
-	blacksmithCleanupAttempts = 36
-	blacksmithCleanupDelay    = 5 * time.Second
-	blacksmithCleanupQuiet    = 12
+	blacksmithIDPattern        = regexp.MustCompile(`\btbx_[A-Za-z0-9_-]+\b`)
+	blacksmithSyncStartPattern = regexp.MustCompile(`(?i)^\s*Syncing(?:\.\.\.| from repo root:)`)
+	blacksmithSyncDonePattern  = regexp.MustCompile(`(?i)^\s*(Changes synced in|No changes to sync|Sync complete)\b`)
+	blacksmithCleanupAttempts  = 36
+	blacksmithCleanupDelay     = 5 * time.Second
+	blacksmithCleanupQuiet     = 12
 )
 
 type blacksmithFlagValues struct {