Data race in internal/handlers/logbound_test.go: fx testutil.WriteSyncer calls t.Logf from a start hook after the test goroutine has finished #230

Open
opened 2026-08-20 07:16:00 +02:00 by clawbot · 0 comments
Collaborator

Found while implementing #127, at host load average 141 on 48 cores.

The race detector fires on internal/handlers/logbound_test.go: fx's testutil.WriteSyncer calls t.Logf from a start hook goroutine after the owning test goroutine has already finished. Writing to a *testing.T after its test returns is a race and, in the worst case, a panic.

Attribution: NOT introduced by that PR. A cache-defeated build of clean next passed, and the branch passed on re-run at lower load — so it is a pre-existing, load-dependent flake in next.

Distinct from #225, which is about wall-clock budgets (the fx start timeout and the 90s per-package timeout) being blown under load. This one is a genuine data race in test wiring, not a timeout, and it will red the gate at random rather than only when slow.

Why it matters: the authoritative gate runs go test -race (script/test), so an intermittent race report makes the gate untrustworthy in the same way #119 and #225 do — a reviewer then has to spend a run on next to attribute their own failure.

Definition of done:

  • no t.Logf/t.Errorf/t.Fatalf reachable from an fx hook or any goroutine that can outlive the test function
  • the fix is in the test wiring, not a -race suppression and not a reduction in what the tests assert
  • go test -race -count=2 ./internal/handlers/... is clean with the host under deliberate heavy load; state the load average it was verified at
Found while implementing https://git.eeqj.de/sneak/webhooker/issues/127, at host load average 141 on 48 cores. The race detector fires on `internal/handlers/logbound_test.go`: fx's `testutil.WriteSyncer` calls `t.Logf` from a start hook goroutine after the owning test goroutine has already finished. Writing to a `*testing.T` after its test returns is a race and, in the worst case, a panic. Attribution: NOT introduced by that PR. A cache-defeated build of clean `next` passed, and the branch passed on re-run at lower load — so it is a pre-existing, load-dependent flake in `next`. Distinct from https://git.eeqj.de/sneak/webhooker/issues/225, which is about wall-clock budgets (the fx start timeout and the 90s per-package timeout) being blown under load. This one is a genuine data race in test wiring, not a timeout, and it will red the gate at random rather than only when slow. Why it matters: the authoritative gate runs `go test -race` (`script/test`), so an intermittent race report makes the gate untrustworthy in the same way https://git.eeqj.de/sneak/webhooker/issues/119 and https://git.eeqj.de/sneak/webhooker/issues/225 do — a reviewer then has to spend a run on `next` to attribute their own failure. Definition of done: - no `t.Logf`/`t.Errorf`/`t.Fatalf` reachable from an fx hook or any goroutine that can outlive the test function - the fix is in the test wiring, not a `-race` suppression and not a reduction in what the tests assert - `go test -race -count=2 ./internal/handlers/...` is clean with the host under deliberate heavy load; state the load average it was verified at
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/webhooker#230