From 88cf40bc0343d870b5dc31bb413d5c958895fb39 Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Sun, 25 Oct 2026 15:07:09 -0300 Subject: [PATCH 1/2] testquality: a test that sleeps a second or more is flagged A wait on the clock passes on a quiet machine and fails on a loaded one, which is what a flake is: of 45 failed fleet gates in two days of spin, the real flakes were each a bound the machine's load outran. A time.Sleep of a constant second or more in a test's body - a subtest's or a goroutine's included - is reported with its length; under a second paces a loop, a computed duration is not a number to judge, and a helper's sleep is the helper's. The allowlist carries the ones whose only signal is the clock, each with its why. Co-Authored-By: Claude Fable 5.1 --- README.md | 2 +- .../testdata/src/waits/waits_test.go | 61 +++++++++++++++++++ internal/testquality/testquality.go | 47 ++++++++++++++ internal/testquality/testquality_test.go | 6 ++ site/src/content/docs/testquality.md | 23 +++++-- 5 files changed, 134 insertions(+), 5 deletions(-) create mode 100644 internal/testquality/testdata/src/waits/waits_test.go diff --git a/README.md b/README.md index 504cf2e..f2fdc51 100644 --- a/README.md +++ b/README.md @@ -10,7 +10,7 @@ their `go.mod`; each fails CI with a specific finding and says how to resolve it | tool | what it catches | |---|---| | [`mutate`](https://spin-stack.github.io/go-tools/mutate/) | code your change touched that no test checks, even at 100% coverage: it breaks the code one small edit at a time and fails when the tests still pass | -| [`testquality`](https://spin-stack.github.io/go-tools/testquality/) | tests that cannot fail, and tests skipped unconditionally | +| [`testquality`](https://spin-stack.github.io/go-tools/testquality/) | tests that cannot fail, tests skipped unconditionally, and tests that sleep a second or more where a condition should be waited for | | [`ctxlife`](https://spin-stack.github.io/go-tools/ctxlife/) | goroutines that use their caller's context and outlive the call | | [`refs`](https://spin-stack.github.io/go-tools/refs/) | paths, tasks and packages that AGENTS.md or CLAUDE.md names and the tree no longer has | | [`vulngate`](https://spin-stack.github.io/go-tools/vulngate/) | vulnerabilities the code calls and that have a fix | diff --git a/internal/testquality/testdata/src/waits/waits_test.go b/internal/testquality/testdata/src/waits/waits_test.go new file mode 100644 index 0000000..35919d8 --- /dev/null +++ b/internal/testquality/testdata/src/waits/waits_test.go @@ -0,0 +1,61 @@ +// Package waits holds tests that sleep for a second or more where a condition should be waited +// for, and the sleeps that are not that. +package waits + +import ( + "testing" + "time" +) + +const settle = 3 * time.Second + +func TestSleepsASecond(t *testing.T) { + time.Sleep(time.Second) // want `TestSleepsASecond sleeps 1s` + if t.Name() == "" { + t.Fatal("named") + } +} + +func TestSleepsInASubtestAndAGoroutine(t *testing.T) { + t.Run("sub", func(t *testing.T) { + time.Sleep(2 * time.Second) // want `TestSleepsInASubtestAndAGoroutine sleeps 2s` + if t.Name() == "" { + t.Fatal("named") + } + }) + go func() { + time.Sleep(settle) // want `TestSleepsInASubtestAndAGoroutine sleeps 3s` + }() + time.Sleep(time.Minute + 500*time.Millisecond) // want `TestSleepsInASubtestAndAGoroutine sleeps 1m0.5s` + if t.Name() == "" { + t.Fatal("named") + } +} + +// Under a second paces a loop, and a duration the test computes is not a number to judge here. +func TestPacesAndComputes(t *testing.T) { + time.Sleep(20 * time.Millisecond) + time.Sleep(999 * time.Millisecond) + d := time.Duration(t.Name()[0]) * time.Second + time.Sleep(d) + time.Sleep(backoff(3)) + waitABit(t) + // Not time.Sleep: another package's Sleep, and a duration handed to something else. + clock{}.Sleep(5 * time.Second) + <-time.After(2 * time.Second) + if t.Name() == "" { + t.Fatal("named") + } +} + +// A helper's sleep is the helper's: a helper named by many tests is one line to fix. +func waitABit(t *testing.T) { + t.Helper() + time.Sleep(5 * time.Second) +} + +func backoff(n int) time.Duration { return time.Duration(n) * time.Second } + +type clock struct{} + +func (clock) Sleep(time.Duration) {} diff --git a/internal/testquality/testquality.go b/internal/testquality/testquality.go index bfd90de..489e988 100644 --- a/internal/testquality/testquality.go +++ b/internal/testquality/testquality.go @@ -5,8 +5,10 @@ package testquality import ( "errors" "go/ast" + "go/constant" "go/types" "strings" + "time" "golang.org/x/tools/go/analysis" "golang.org/x/tools/go/analysis/passes/inspect" @@ -62,6 +64,13 @@ func run(pass *analysis.Pass) (any, error) { "t.Skip or an assertion, and no helper is handed the test. A test that asserts "+ "nothing passes forever and reports this package as covered", fn.Name.Name) } + + for _, sleep := range longSleeps(pass, fn) { + pass.Reportf(sleep.call.Pos(), "%s sleeps %s for nothing it can see: a wait on the clock "+ + "passes on a quiet machine and fails on a loaded one, which is what a flake is. Wait for "+ + "the condition - a channel, a log line, Eventually - or say in the allowlist why the "+ + "clock is the only signal there is", fn.Name.Name, sleep.d) + } }) return nil, nil @@ -196,3 +205,41 @@ func isFromPackage(pass *analysis.Pass, call *ast.CallExpr, pkgs map[string]bool } return pkgs[fn.Pkg().Path()] } + +// longSleep is one time.Sleep in a test's body, closures included, of a second or more. +type longSleep struct { + call *ast.CallExpr + d time.Duration +} + +// longSleeps is every time.Sleep in fn whose duration is a constant of a second or more: under a +// second paces a loop, and a duration the test computes is not a number to judge here. A helper's +// sleep is the helper's, not every caller's. +func longSleeps(pass *analysis.Pass, fn *ast.FuncDecl) []longSleep { + var found []longSleep + ast.Inspect(fn.Body, func(n ast.Node) bool { + call, ok := n.(*ast.CallExpr) + if !ok || len(call.Args) != 1 { + return true + } + sel, ok := call.Fun.(*ast.SelectorExpr) + if !ok || sel.Sel.Name != "Sleep" || !isFromPackage(pass, call, map[string]bool{"time": true}) { + return true + } + // A duration that is not a constant has no value here (the zero TypeAndValue's is nil). + value := pass.TypesInfo.Types[call.Args[0]].Value + if value == nil { + return true + } + ns, exact := constant.Int64Val(constant.ToInt(value)) + if !exact { + return true + } + if ns < int64(time.Second) { + return true + } + found = append(found, longSleep{call: call, d: time.Duration(ns)}) + return true + }) + return found +} diff --git a/internal/testquality/testquality_test.go b/internal/testquality/testquality_test.go index 54f2325..1693850 100644 --- a/internal/testquality/testquality_test.go +++ b/internal/testquality/testquality_test.go @@ -19,6 +19,12 @@ func TestTestsThatCanFailAreNotFlagged(t *testing.T) { analysistest.Run(t, analysistest.TestData(), testquality.Analyzer, "canfail") } +// A sleep of a second or more in a test's body, closures included, is a wait on the clock; under a +// second, a computed duration and a helper's sleep are not flagged. +func TestLongSleepsInATestAreFlagged(t *testing.T) { + analysistest.Run(t, analysistest.TestData(), testquality.Analyzer, "waits") +} + func TestTestsThatNeverRunAreFlagged(t *testing.T) { analysistest.Run(t, analysistest.TestData(), testquality.Analyzer, "skipped") } diff --git a/site/src/content/docs/testquality.md b/site/src/content/docs/testquality.md index b18df39..4b0bb9e 100644 --- a/site/src/content/docs/testquality.md +++ b/site/src/content/docs/testquality.md @@ -1,6 +1,6 @@ --- title: testquality -description: Fails on a test that cannot fail, or one skipped unconditionally. Such a test counts as covered, passes forever, and proves nothing. +description: Fails on a test that cannot fail, one skipped unconditionally, or one that sleeps a second or more where a condition should be waited for. The first two count as covered, pass forever and prove nothing; the third passes on a quiet machine and fails on a loaded one. --- A test that cannot fail is worse than no test: it shows up green, it counts toward coverage, and @@ -33,11 +33,26 @@ func TestSkippedOutright(t *testing.T) { t.Skip("comes back when the feature is written") t.Fatal("never reached") } + +func TestWaitsOnTheClock(t *testing.T) { + start(t) + time.Sleep(5 * time.Second) // for the server to be up, presumably + assertUp(t) +} ``` -The first two are reported as `cannot fail` and the third as `is skipped unconditionally`. A test -that hands `t` to a helper counts as one that can fail, and so does one where a closure captures -`t` and calls an assertion package. Subtests are inspected with the rest of the body. +The first two are reported as `cannot fail`, the third as `is skipped unconditionally`, and the +fourth as `sleeps 5s for nothing it can see`. A test that hands `t` to a helper counts as one that +can fail, and so does one where a closure captures `t` and calls an assertion package. Subtests +are inspected with the rest of the body. + +A sleep of a second or more in a test's body - a subtest's or a goroutine's included - is a wait +on the clock: it passes on a quiet machine and fails on a loaded one, which is what a flake is. +Of 45 failed fleet gates in two days of one repository, the real flakes were each a wait with a +bound that the machine's load outran. Wait for the condition - a channel, a log line, an +`Eventually` - or say in the allowlist why the clock is the only signal there is. Under a second +paces a loop and is not flagged; a duration the test computes is not a number to judge; a helper's +sleep is the helper's, one line to fix however many tests call it. Tests behind the `integration` and `e2e` build tags are analyzed too: a test in another lane is held like any other. From 47402569a6d8cc8953661e373349efa9f534b2ec Mon Sep 17 00:00:00 2001 From: Manuel de Brito Fontes Date: Sun, 25 Oct 2026 15:10:15 -0300 Subject: [PATCH 2/2] testquality: a sleep inside a loop looks again, and is not a wait on the clock Nine of spin's 43 were a loop's pacing: for deadline...; time.Sleep(2s). Co-Authored-By: Claude Fable 5.1 --- .../testdata/src/waits/waits_test.go | 27 ++++++++++++++++++- internal/testquality/testquality.go | 26 +++++++++++++++--- site/src/content/docs/testquality.md | 7 ++--- 3 files changed, 52 insertions(+), 8 deletions(-) diff --git a/internal/testquality/testdata/src/waits/waits_test.go b/internal/testquality/testdata/src/waits/waits_test.go index 35919d8..619561a 100644 --- a/internal/testquality/testdata/src/waits/waits_test.go +++ b/internal/testquality/testdata/src/waits/waits_test.go @@ -32,10 +32,22 @@ func TestSleepsInASubtestAndAGoroutine(t *testing.T) { } } -// Under a second paces a loop, and a duration the test computes is not a number to judge here. +// Under a second paces a loop, and a duration the test computes is not a number to judge here. A +// loop that sleeps looks again, which is a wait for a condition with the loop's own bound. func TestPacesAndComputes(t *testing.T) { time.Sleep(20 * time.Millisecond) time.Sleep(999 * time.Millisecond) + for deadline := time.Now().Add(time.Minute); time.Now().Before(deadline); time.Sleep(2 * time.Second) { + if t.Name() != "" { + break + } + } + for !ready() { + time.Sleep(5 * time.Second) + } + for range 3 { + func() { time.Sleep(time.Second) }() + } d := time.Duration(t.Name()[0]) * time.Second time.Sleep(d) time.Sleep(backoff(3)) @@ -48,6 +60,17 @@ func TestPacesAndComputes(t *testing.T) { } } +// A sleep after a loop is not the loop's. +func TestSleepsAfterALoop(t *testing.T) { + for !ready() { + time.Sleep(time.Second) + } + time.Sleep(4 * time.Second) // want `TestSleepsAfterALoop sleeps 4s` + if t.Name() == "" { + t.Fatal("named") + } +} + // A helper's sleep is the helper's: a helper named by many tests is one line to fix. func waitABit(t *testing.T) { t.Helper() @@ -56,6 +79,8 @@ func waitABit(t *testing.T) { func backoff(n int) time.Duration { return time.Duration(n) * time.Second } +func ready() bool { return true } + type clock struct{} func (clock) Sleep(time.Duration) {} diff --git a/internal/testquality/testquality.go b/internal/testquality/testquality.go index 489e988..c9281a2 100644 --- a/internal/testquality/testquality.go +++ b/internal/testquality/testquality.go @@ -6,6 +6,7 @@ import ( "errors" "go/ast" "go/constant" + "go/token" "go/types" "strings" "time" @@ -212,14 +213,31 @@ type longSleep struct { d time.Duration } -// longSleeps is every time.Sleep in fn whose duration is a constant of a second or more: under a -// second paces a loop, and a duration the test computes is not a number to judge here. A helper's -// sleep is the helper's, not every caller's. +// longSleeps is every time.Sleep in fn whose duration is a constant of a second or more and that +// is not inside a loop: a loop that sleeps looks again, which is a wait for a condition, with the +// loop's own bound. Under a second paces anything, and a duration the test computes is not a +// number to judge here. A helper's sleep is the helper's, not every caller's. func longSleeps(pass *analysis.Pass, fn *ast.FuncDecl) []longSleep { + var loops []ast.Node + ast.Inspect(fn.Body, func(n ast.Node) bool { + switch n.(type) { + case *ast.ForStmt, *ast.RangeStmt: + loops = append(loops, n) + } + return true + }) + inLoop := func(pos token.Pos) bool { + for _, l := range loops { + if l.Pos() <= pos && pos < l.End() { + return true + } + } + return false + } var found []longSleep ast.Inspect(fn.Body, func(n ast.Node) bool { call, ok := n.(*ast.CallExpr) - if !ok || len(call.Args) != 1 { + if !ok || len(call.Args) != 1 || inLoop(call.Pos()) { return true } sel, ok := call.Fun.(*ast.SelectorExpr) diff --git a/site/src/content/docs/testquality.md b/site/src/content/docs/testquality.md index 4b0bb9e..9315139 100644 --- a/site/src/content/docs/testquality.md +++ b/site/src/content/docs/testquality.md @@ -50,9 +50,10 @@ A sleep of a second or more in a test's body - a subtest's or a goroutine's incl on the clock: it passes on a quiet machine and fails on a loaded one, which is what a flake is. Of 45 failed fleet gates in two days of one repository, the real flakes were each a wait with a bound that the machine's load outran. Wait for the condition - a channel, a log line, an -`Eventually` - or say in the allowlist why the clock is the only signal there is. Under a second -paces a loop and is not flagged; a duration the test computes is not a number to judge; a helper's -sleep is the helper's, one line to fix however many tests call it. +`Eventually` - or say in the allowlist why the clock is the only signal there is. A sleep inside a +loop looks again, which is a wait for a condition with the loop's own bound, and is not flagged; +nor is one under a second, which paces; nor a duration the test computes, which is not a number to +judge; a helper's sleep is the helper's, one line to fix however many tests call it. Tests behind the `integration` and `e2e` build tags are analyzed too: a test in another lane is held like any other.