Skip to content

Commit e50bff8

Browse files
Merge pull request #361 from AgentWorkforce/fix/bootstrap-empty-revision-360
fix(mount): stop repeated stalled bootstrap checkpoints
2 parents a030c75 + d8a23d8 commit e50bff8

6 files changed

Lines changed: 516 additions & 8 deletions

File tree

cmd/relayfile-mount/main.go

Lines changed: 18 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -432,7 +432,7 @@ func runSinglePollingMount(rootCtx context.Context, cfg mountConfig) error {
432432
log.Printf("%s", mountStartupLogLine(cfg))
433433
log.Printf("Mirror started at %s. Sync interval %s +/- %.0f%%. Public state: %s", cfg.localDir, cfg.interval.Round(time.Second), cfg.intervalJitter*100, filepath.Join(cfg.localDir, ".relay", "state.json"))
434434

435-
run := func(reconcile bool) {
435+
run := func(reconcile bool) error {
436436
ctx, cancel := context.WithTimeout(rootCtx, cfg.timeout)
437437
defer cancel()
438438
var err error
@@ -442,19 +442,30 @@ func runSinglePollingMount(rootCtx context.Context, cfg mountConfig) error {
442442
err = syncer.SyncOnce(ctx)
443443
}
444444
if err != nil {
445+
var stalled *mountsync.BootstrapStalledError
446+
if errors.As(err, &stalled) {
447+
// This is an operator-actionable hard stop, not a transient
448+
// cycle failure. Returning it terminates this runner (and, for
449+
// scoped layouts, cancels sibling runners) instead of letting
450+
// the polling ticker retry the same persisted checkpoint forever.
451+
return err
452+
}
445453
if errors.Is(err, context.DeadlineExceeded) {
446454
if synced, total, ok := readBootstrapProgress(cfg.localDir); ok {
447455
log.Printf("mount bootstrapping: %d/%d files (in progress)", synced, total)
448-
return
456+
return nil
449457
}
450458
}
451459
log.Printf("mount sync cycle failed: %v", err)
452-
return
460+
return nil
453461
}
454462
log.Printf("mount sync cycle completed")
463+
return nil
455464
}
456465

457-
run(true)
466+
if err := run(true); err != nil {
467+
return err
468+
}
458469
if cfg.once {
459470
return nil
460471
}
@@ -503,7 +514,9 @@ func runSinglePollingMount(rootCtx context.Context, cfg mountConfig) error {
503514
cycle,
504515
)
505516
if reconcile {
506-
run(true)
517+
if err := run(true); err != nil {
518+
return err
519+
}
507520
}
508521
timer.Reset(jitteredIntervalWithSample(cfg.interval, cfg.intervalJitter, rng.Float64()))
509522
}

cmd/relayfile-mount/main_test.go

Lines changed: 138 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,9 @@ package main
22

33
import (
44
"context"
5+
"encoding/json"
56
"errors"
7+
"fmt"
68
"net/http"
79
"net/http/httptest"
810
"os"
@@ -415,6 +417,142 @@ func TestInstallCredsFileRefreshToleratesParseFailureWithoutRetry(t *testing.T)
415417
}
416418
}
417419

420+
// TestRunSinglePollingMountStopsOnBootstrapStall proves the typed hard failure
421+
// leaves the polling runner immediately. main turns this returned error into a
422+
// nonzero process exit, so the ticker cannot retry the same checkpoint.
423+
func TestRunSinglePollingMountStopsOnBootstrapStall(t *testing.T) {
424+
t.Setenv("RELAYFILE_BOOTSTRAP_STALL_CYCLES", "1")
425+
var calls atomic.Int32
426+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
427+
calls.Add(1)
428+
http.Error(w, "stuck", http.StatusBadGateway)
429+
}))
430+
defer server.Close()
431+
432+
err := runSinglePollingMount(context.Background(), mountConfig{
433+
baseURL: server.URL,
434+
token: "test-token",
435+
workspaceID: "ws_bootstrap_stall",
436+
remotePath: "/",
437+
localDir: t.TempDir(),
438+
stateDir: t.TempDir(),
439+
mountKind: mountsync.MountKindDaemon,
440+
syncMode: syncModeMirror,
441+
interval: time.Hour,
442+
timeout: time.Second,
443+
websocketEnabled: false,
444+
})
445+
var stalled *mountsync.BootstrapStalledError
446+
if !errors.As(err, &stalled) {
447+
t.Fatalf("expected bootstrap stall to escape polling runner, got %v", err)
448+
}
449+
if got := calls.Load(); got == 0 {
450+
t.Fatal("expected initial full-tree request before runner exited")
451+
}
452+
}
453+
454+
// TestRunSinglePollingMountKeepsNormalCycleFailuresNonFatal verifies that a
455+
// normal cloud error keeps its historical per-cycle retry behavior rather
456+
// than terminating the mount runner.
457+
func TestRunSinglePollingMountKeepsNormalCycleFailuresNonFatal(t *testing.T) {
458+
t.Setenv("RELAYFILE_BOOTSTRAP_STALL_CYCLES", "2")
459+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
460+
http.Error(w, "transient", http.StatusBadGateway)
461+
}))
462+
defer server.Close()
463+
464+
err := runSinglePollingMount(context.Background(), mountConfig{
465+
baseURL: server.URL,
466+
token: "test-token",
467+
workspaceID: "ws_normal_retry",
468+
remotePath: "/",
469+
localDir: t.TempDir(),
470+
stateDir: t.TempDir(),
471+
mountKind: mountsync.MountKindDaemon,
472+
syncMode: syncModeMirror,
473+
interval: time.Hour,
474+
timeout: time.Second,
475+
websocketEnabled: false,
476+
once: true,
477+
})
478+
if err != nil {
479+
t.Fatalf("normal cycle failure must remain nonfatal to the runner, got %v", err)
480+
}
481+
}
482+
483+
// TestRunSinglePollingMountStopsOnTimerBootstrapStall exercises the polling
484+
// timer path, not just the initial cycle. The first page commits a partial
485+
// checkpoint and its next-page error remains nonfatal; the following timer
486+
// reconcile fails at that unchanged cursor and terminates the runner.
487+
func TestRunSinglePollingMountStopsOnTimerBootstrapStall(t *testing.T) {
488+
t.Setenv("RELAYFILE_BOOTSTRAP_STALL_CYCLES", "1")
489+
var rootTreeCalls atomic.Int32
490+
var cursorTreeCalls atomic.Int32
491+
var readCalls atomic.Int32
492+
entries := make([]mountsync.TreeEntry, 0, 10)
493+
for i := 0; i < 10; i++ {
494+
entries = append(entries, mountsync.TreeEntry{Path: fmt.Sprintf("/f/%05d.txt", i), Type: "file"})
495+
}
496+
nextCursor := entries[len(entries)-1].Path
497+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
498+
switch {
499+
case strings.Contains(r.URL.Path, "/fs/tree"):
500+
if r.URL.Query().Get("cursor") != "" {
501+
cursorTreeCalls.Add(1)
502+
// A 400 is intentionally not retried by HTTPClient, so exactly
503+
// two calls prove the initial nonfatal cycle plus one timer cycle.
504+
http.Error(w, "stuck cursor", http.StatusBadRequest)
505+
return
506+
}
507+
rootTreeCalls.Add(1)
508+
w.Header().Set("Content-Type", "application/json")
509+
_ = json.NewEncoder(w).Encode(mountsync.TreeResponse{Entries: entries, NextCursor: &nextCursor})
510+
case strings.Contains(r.URL.Path, "/fs/file"):
511+
readCalls.Add(1)
512+
w.Header().Set("Content-Type", "application/json")
513+
_ = json.NewEncoder(w).Encode(mountsync.RemoteFile{
514+
Path: r.URL.Query().Get("path"),
515+
ContentType: "text/plain",
516+
Content: "content",
517+
})
518+
default:
519+
http.NotFound(w, r)
520+
}
521+
}))
522+
defer server.Close()
523+
524+
started := time.Now()
525+
err := runSinglePollingMount(context.Background(), mountConfig{
526+
baseURL: server.URL,
527+
token: "test-token",
528+
workspaceID: "ws_timer_bootstrap_stall",
529+
remotePath: "/",
530+
localDir: t.TempDir(),
531+
stateDir: t.TempDir(),
532+
mountKind: mountsync.MountKindDaemon,
533+
syncMode: syncModeMirror,
534+
interval: time.Millisecond, // enforced to the 5s poll floor
535+
timeout: time.Second,
536+
websocketEnabled: false,
537+
})
538+
var stalled *mountsync.BootstrapStalledError
539+
if !errors.As(err, &stalled) {
540+
t.Fatalf("expected timer-path bootstrap stall to escape runner, got %v", err)
541+
}
542+
if got := rootTreeCalls.Load(); got != 1 {
543+
t.Fatalf("root tree calls = %d, want one initial partial traversal", got)
544+
}
545+
if got := readCalls.Load(); got != int32(len(entries)) {
546+
t.Fatalf("ReadFile calls = %d, want %d first-page files", got, len(entries))
547+
}
548+
if got := cursorTreeCalls.Load(); got != 2 {
549+
t.Fatalf("cursor tree calls = %d, want initial nonfatal + timer hard-stop", got)
550+
}
551+
if elapsed := time.Since(started); elapsed < minMountPollInterval {
552+
t.Fatalf("runner returned before a timer cycle (%s < %s)", elapsed, minMountPollInterval)
553+
}
554+
}
555+
418556
func TestNormalizeRemotePathsDedupesRepeatedFlagValues(t *testing.T) {
419557
got := normalizeRemotePaths(
420558
[]string{"/github/repos/acme/cloud", "github/repos/acme/cloud/", "/slack/channels/proj-cloud"},

internal/mountsync/bootstrap_test.go

Lines changed: 168 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ package mountsync
33
import (
44
"context"
55
"encoding/json"
6+
"errors"
67
"fmt"
78
"os"
89
"path/filepath"
@@ -365,6 +366,173 @@ func TestBootstrapResumesFromPersistedCursor(t *testing.T) {
365366
}
366367
}
367368

369+
// TestBootstrapStallCycleGuardPersistsAndFailsHard reproduces the
370+
// non-converging unversioned partial-bootstrap shape: the first page is
371+
// persisted, then every resumed cycle fails at the same next-page cursor.
372+
// The empty revision is non-destructive and not the reason completion fails;
373+
// the unchanged checkpoint is. The guard turns the otherwise infinite
374+
// "non-empty state without completed bootstrap" loop into a hard failure,
375+
// even when every attempt is a fresh Syncer process.
376+
func TestBootstrapStallCycleGuardPersistsAndFailsHard(t *testing.T) {
377+
client := newBootstrapClient(30, 10)
378+
for path, file := range client.files {
379+
file.Revision = ""
380+
client.files[path] = file
381+
}
382+
client.listTreeFailAt = 2
383+
client.listTreeFailErr = &HTTPError{StatusCode: 502, Code: "bad_gateway", Message: "stuck"}
384+
localDir := t.TempDir()
385+
opts := SyncerOptions{RootCtx: context.Background(), BootstrapStallCycles: 2}
386+
387+
s := newBootstrapSyncer(t, client, localDir, opts)
388+
err := s.Reconcile(context.Background())
389+
if err == nil {
390+
t.Fatalf("expected partial bootstrap cycle to return its cloud error")
391+
}
392+
var stalled *BootstrapStalledError
393+
if errors.As(err, &stalled) {
394+
t.Fatalf("checkpoint-advancing cycle must stay below the hard limit: %v", err)
395+
}
396+
st := loadPersistedState(t, localDir)
397+
if st.BootstrapStallCycles != 0 || st.BootstrapCursor == "" || st.BootstrapFilesSynced == 0 {
398+
t.Fatalf("expected persisted partial checkpoint with reset stall count, state=%#v", st)
399+
}
400+
if got := countLocalFiles(t, localDir); got != 10 {
401+
t.Fatalf("expected first page to stay materialized, got %d files", got)
402+
}
403+
404+
// A fresh Syncer resumes at the same failing cursor. This is the first
405+
// checkpoint-stable stalled cycle, so it increments but stays retryable.
406+
s = newBootstrapSyncer(t, client, localDir, opts)
407+
err = s.Reconcile(context.Background())
408+
if err == nil || errors.As(err, &stalled) {
409+
t.Fatalf("first checkpoint-stable cycle must return the cloud error, got %v", err)
410+
}
411+
st = loadPersistedState(t, localDir)
412+
if st.BootstrapStallCycles != 1 {
413+
t.Fatalf("BootstrapStallCycles after first unchanged cycle = %d, want 1", st.BootstrapStallCycles)
414+
}
415+
416+
// The next fresh Syncer sees the same persisted partial checkpoint and
417+
// reaches the configured limit, returning a typed, status-visible failure.
418+
s = newBootstrapSyncer(t, client, localDir, opts)
419+
err = s.Reconcile(context.Background())
420+
if !errors.As(err, &stalled) {
421+
t.Fatalf("expected BootstrapStalledError at the hard limit, got %v", err)
422+
}
423+
if stalled.Cycles != 2 || stalled.Limit != 2 {
424+
t.Fatalf("BootstrapStalledError = %#v, want cycles=2 limit=2", stalled)
425+
}
426+
st = loadPersistedState(t, localDir)
427+
if st.BootstrapComplete {
428+
t.Fatalf("hard stall must not force BootstrapComplete")
429+
}
430+
if st.BootstrapStallCycles != 2 {
431+
t.Fatalf("persisted BootstrapStallCycles = %d, want 2", st.BootstrapStallCycles)
432+
}
433+
if st.LastError == nil || st.LastError.Kind != "bootstrap_stalled" || st.LastError.Code != "bootstrap_stall_cycle_limit" {
434+
t.Fatalf("expected structured persisted bootstrap stall error, got %#v", st.LastError)
435+
}
436+
}
437+
438+
func TestBootstrapStallCycleGuardIgnoresCanceledContext(t *testing.T) {
439+
s := newBootstrapSyncer(t, newBootstrapClient(1, 1), t.TempDir(), SyncerOptions{
440+
RootCtx: context.Background(),
441+
BootstrapStallCycles: 2,
442+
})
443+
s.state.BootstrapCursor = "resume-cursor"
444+
s.state.BootstrapStallCycles = 1
445+
446+
wrappedCanceled := fmt.Errorf("mount shutting down: %w", context.Canceled)
447+
if err := s.recordBootstrapCycle("resume-cursor", nil, wrappedCanceled); err != nil {
448+
t.Fatalf("canceled context must not trip the stall guard: %v", err)
449+
}
450+
if got := s.state.BootstrapStallCycles; got != 1 {
451+
t.Fatalf("canceled context changed stall count to %d, want 1", got)
452+
}
453+
454+
// DeadlineExceeded is a failed retry at the same checkpoint, so it still
455+
// consumes the remaining attempt and produces the typed hard stop.
456+
err := s.recordBootstrapCycle("resume-cursor", nil, context.DeadlineExceeded)
457+
var stalled *BootstrapStalledError
458+
if !errors.As(err, &stalled) {
459+
t.Fatalf("deadline exceeded must count toward the stall limit, got %v", err)
460+
}
461+
if stalled.Cycles != 2 || stalled.Limit != 2 {
462+
t.Fatalf("BootstrapStalledError = %#v, want cycles=2 limit=2", stalled)
463+
}
464+
}
465+
466+
// TestBootstrapStallCycleGuardResetsOnCheckpointAdvanceAndCompletion proves
467+
// that the counter reflects lack of traversal progress, not merely errors.
468+
func TestBootstrapStallCycleGuardResetsOnCheckpointAdvanceAndCompletion(t *testing.T) {
469+
client := newBootstrapClient(30, 10)
470+
client.listTreeFailAt = 2
471+
client.listTreeFailErr = &HTTPError{StatusCode: 502, Code: "bad_gateway", Message: "page failure"}
472+
localDir := t.TempDir()
473+
s := newBootstrapSyncer(t, client, localDir, SyncerOptions{
474+
RootCtx: context.Background(),
475+
BootstrapStallCycles: 3,
476+
})
477+
478+
// Page one advances the cursor before page two fails, so the count resets.
479+
if err := s.Reconcile(context.Background()); err == nil {
480+
t.Fatalf("expected first bootstrap attempt to fail on page 2")
481+
}
482+
if st := loadPersistedState(t, localDir); st.BootstrapStallCycles != 0 || st.BootstrapCursor == "" {
483+
t.Fatalf("cursor advance must reset stall count; state=%#v", st)
484+
}
485+
486+
// Fail at the same persisted cursor once: count increments.
487+
if err := s.Reconcile(context.Background()); err == nil {
488+
t.Fatalf("expected unchanged checkpoint attempt to fail")
489+
}
490+
if st := loadPersistedState(t, localDir); st.BootstrapStallCycles != 1 {
491+
t.Fatalf("unchanged checkpoint count = %d, want 1", st.BootstrapStallCycles)
492+
}
493+
494+
// Let page two advance, then fail on page three. The new cursor resets the
495+
// persisted count despite the returned cloud error.
496+
client.mu.Lock()
497+
client.listTreeFailAt = 3
498+
client.mu.Unlock()
499+
if err := s.Reconcile(context.Background()); err == nil {
500+
t.Fatalf("expected bootstrap attempt to fail on page 3")
501+
}
502+
if st := loadPersistedState(t, localDir); st.BootstrapStallCycles != 0 {
503+
t.Fatalf("advanced checkpoint must reset stall count, got %d", st.BootstrapStallCycles)
504+
}
505+
506+
client.mu.Lock()
507+
client.listTreeFailAt = 0
508+
client.mu.Unlock()
509+
if err := s.Reconcile(context.Background()); err != nil {
510+
t.Fatalf("completion after checkpoint advances: %v", err)
511+
}
512+
st := loadPersistedState(t, localDir)
513+
if !st.BootstrapComplete || st.BootstrapStallCycles != 0 {
514+
t.Fatalf("completion must clear checkpoint and stall count, state=%#v", st)
515+
}
516+
}
517+
518+
func TestBootstrapStallCycleLimitUsesOptionThenEnvThenDefault(t *testing.T) {
519+
newSyncer := func(t *testing.T, opts SyncerOptions) *Syncer {
520+
t.Helper()
521+
return newBootstrapSyncer(t, newBootstrapClient(1, 1), t.TempDir(), opts)
522+
}
523+
t.Setenv("RELAYFILE_BOOTSTRAP_STALL_CYCLES", "7")
524+
if got := newSyncer(t, SyncerOptions{}).bootstrapStallCycles; got != 7 {
525+
t.Fatalf("env bootstrap stall limit = %d, want 7", got)
526+
}
527+
if got := newSyncer(t, SyncerOptions{BootstrapStallCycles: 3}).bootstrapStallCycles; got != 3 {
528+
t.Fatalf("explicit bootstrap stall limit = %d, want 3", got)
529+
}
530+
t.Setenv("RELAYFILE_BOOTSTRAP_STALL_CYCLES", "not-a-number")
531+
if got := newSyncer(t, SyncerOptions{}).bootstrapStallCycles; got != defaultBootstrapStallCycles {
532+
t.Fatalf("invalid env bootstrap stall limit = %d, want default %d", got, defaultBootstrapStallCycles)
533+
}
534+
}
535+
368536
// TestBootstrapCompleteGatesFastPath: a hand-seeded state with Files +
369537
// LastEventAt but BootstrapComplete=false MUST NOT short-circuit; the
370538
// full pull runs and the mirror converges (the rw_517d60b6 repro).

0 commit comments

Comments
 (0)