From 67a6532deccf03cfead09038bc3057e9ed3a1fe7 Mon Sep 17 00:00:00 2001 From: Feng Ruohang Date: Thu, 5 Nov 2026 11:34:34 +0800 Subject: [PATCH] test(restore): give native-restore liveness waits one minute The native-restore tests waited 10 seconds for steps that do real drive work: metadata writes with synchronous persistence and renames on every drive. A full suite run on a machine whose SSD was busy with another decommission run failed TestRestoreUploadStagingFailsClosed/staged once with "background restore did not finish"; about 430 reruns, under CPU and fsync stress as well, passed. The test uses local locks, and after its release the completion takes no new namespace lock, so the bound is a liveness bound, not a latency contract. All eight such waits in the native-restore tests now use one restoreTestWait of one minute, and the background-restore helper prints the goroutine stacks when it times out. Assertions that something must not happen keep their own bounds. Co-Authored-By: Claude Opus 5.5 Signed-off-by: Feng Ruohang --- cmd/restore-native-generation_test.go | 10 +++++----- cmd/restore-native-isolation_test.go | 16 ++++++++++++---- 2 files changed, 17 insertions(+), 9 deletions(-) diff --git a/cmd/restore-native-generation_test.go b/cmd/restore-native-generation_test.go index d79bc1030..48b5d19ea 100644 --- a/cmd/restore-native-generation_test.go +++ b/cmd/restore-native-generation_test.go @@ -369,7 +369,7 @@ func TestRestoreUploadUnreadableFailsClosed(t *testing.T) { if mode == "stale" { select { case <-gate.entered: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("restore never reached completion") } } else { @@ -701,7 +701,7 @@ func testRestoreUploadStaging(t *testing.T, mode string) { } select { case <-entered: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("completion never staged its commit") } stored := restoreIsolationUploads(t, r, 0) @@ -784,7 +784,7 @@ func TestRestoreSplitKeepsRunningUpload(t *testing.T) { } select { case <-gate.entered: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("restore never reached completion") } stored := restoreIsolationUploads(t, r, 0) @@ -1277,7 +1277,7 @@ func TestCleanupStaleUploadsSkipsRunningCommit(t *testing.T) { readOnce.Do(func() { close(readRelease) }) select { case <-cleanupDone: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("stale cleanup never returned") } stageOnce.Do(func() { close(stageRelease) }) @@ -1403,7 +1403,7 @@ func TestCleanupStaleUploadsHoldsLockThroughRename(t *testing.T) { paused.Do(func() { close(pause.release) }) select { case <-stageEntered: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("completion never staged after the rename ended") } stageOnce.Do(func() { close(stageRelease) }) diff --git a/cmd/restore-native-isolation_test.go b/cmd/restore-native-isolation_test.go index 232eb4323..6e5e412da 100644 --- a/cmd/restore-native-isolation_test.go +++ b/cmd/restore-native-isolation_test.go @@ -28,6 +28,7 @@ import ( "net/http/httptest" "net/url" "reflect" + "runtime" "strings" "sync" "sync/atomic" @@ -82,14 +83,21 @@ func (l *restoreIsolationLayer) RestoreTransitionedObject(ctx context.Context, b return err } +// restoreTestWait bounds how long a restore test waits for a step that does +// real drive work: metadata writes with synchronous persistence and renames +// on every drive. It is a liveness bound, not a latency contract; a loaded +// machine has stalled such a step past ten seconds. +const restoreTestWait = time.Minute + // wait returns the result of the next background restore. func (l *restoreIsolationLayer) wait(t *testing.T) error { t.Helper() select { case err := <-l.done: return err - case <-time.After(10 * time.Second): - t.Fatal("background restore did not finish") + case <-time.After(restoreTestWait): + buf := make([]byte, 1<<20) + t.Fatalf("background restore did not finish in %v; goroutines:\n%s", restoreTestWait, buf[:runtime.Stack(buf, true)]) return nil } } @@ -255,7 +263,7 @@ func restoreIsolationEntered(t *testing.T, tier *restoreIsolationGateTier) { t.Helper() select { case <-tier.entered: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("restore never reached its download gate") } } @@ -1062,7 +1070,7 @@ func TestRestoreUploadOutlivesStaleAge(t *testing.T) { if gated { select { case <-gate.entered: - case <-time.After(10 * time.Second): + case <-time.After(restoreTestWait): t.Fatal("restore never reached completion") } } else {