TestAutoSaveOnSignalRacesTurnLoop is load-flaky, and it guards the #24 data race #36

Closed
opened 2026-08-09 17:12:41 +02:00 by clawbot · 1 comment
Collaborator

Problem

TestAutoSaveOnSignalRacesTurnLoop fails intermittently under load. It is the
test that proves the autosave path no longer gob-encodes live game state from
the signal goroutine — the data race fixed in #24. A guard test that fails
randomly is worse than useless: it either erodes trust in the suite, or gets
mentally filtered out, and then it cannot do the one job it exists for.

Evidence

Three independent observations, in order of strength:

  1. PR #35 (sticks coverage): failed 3 of 7 mutation runs. Every failure was
    inside the verbose re-run that make test performs after a failure —
    i.e. the suite running a second time while the first run's processes are
    still winding down, at roughly doubled load. It passed all 9 clean gate
    runs, including three back-to-back. It never executes a line of
    sticks.go, so the sticks work is not implicated.
  2. PR #34 (rings coverage): failed once, also in a deliberately-red build
    at host load ~99 on 48 cores. Did not recur in five clean runs.
  3. PR #34 review: could not reproduce — 20 clean uncached runs green, six
    further mutated runs at load ~60 clean.

Taken together: it is load-sensitive, not random. The common factor is
concurrent pressure, and the most reliable trigger is the conditional verbose
re-run introduced by #2, which doubles the load precisely when the suite is
already failing.

Why this is worth fixing rather than tolerating

The failure mode is self-obscuring. The re-run exists to give diagnostics on a
failure; if the re-run itself induces an unrelated failure, every genuine
red build now carries a spurious second failure that has nothing to do with
the change under test. That is exactly what happened three times in PR #35
the author had to reason past it to trust their own mutation results.

Definition of done

  1. Determine why it is load-sensitive. Likely candidates, to be confirmed
    rather than assumed: a real timing assumption in the test (a deadline, a
    sleep, a bounded number of loop iterations before the signal is expected to
    land), or a genuine residual race the detector only wins the scheduling
    lottery on under pressure.
  2. If it is a test-side timing assumption, remove the assumption rather
    than widening the timeout — a test that passes because a constant got
    bigger has not been fixed. Make it wait on a condition, not a duration.
  3. If it is a real race, that is a defect in the #24 fix and must be
    reported as such before any test change. Say so and stop; do not paper over
    it by relaxing the test.
  4. Capture the actual failure output — all three observations so far are
    "it failed", and nobody has recorded the assertion text or a race
    report
    . Get that first; it likely settles item 1 immediately.
  5. The test still fails when the #24 fix is reverted (i.e. it remains a real
    guard). Prove it by mutation, as PR #26 originally did — reverting
    AutoSaveOnSignal to encode on the calling goroutine produced 73-113
    DATA RACE reports.
  6. Run the suite repeatedly under deliberate load (the condition that
    triggers it) to demonstrate the fix, not just once on an idle box.
  7. make check green; TODO.md Completed Steps entry; do not rotate
    "Next Step"; commit title ends (closes #N).

Implementation requirements

  • Do NOT weaken or delete the test to make it pass. It guards a bug that can
    destroy a player's save file.
  • Do NOT change the signal-handling, pendingSaver, service-point, or
    atomic-write logic settled in #23/#26 unless item 3 applies — and if it
    does, report before changing anything.
  • Lint: golangci-lint on this host shares one cache and one lock across
    concurrent agent sessions. Export GOLANGCI_LINT_CACHE to a fresh empty
    private directory AND retry on parallel golangci-lint is running; a
    private cache does not prevent the lock collision. Treat any result naming
    paths outside your worktree as void.
  • make targets only. Do NOT modify .golangci.yml. No Dockerfile/CI/script/.
  • Never mention Claude or Anthropic anywhere.

Priority

Medium-high. No user-facing defect — but it degrades the signal quality of
every future red build in this repo, and it sits on top of the most
consequential bug fixed so far.

## Problem `TestAutoSaveOnSignalRacesTurnLoop` fails intermittently under load. It is the test that proves the autosave path no longer gob-encodes live game state from the signal goroutine — the data race fixed in #24. A guard test that fails randomly is worse than useless: it either erodes trust in the suite, or gets mentally filtered out, and then it cannot do the one job it exists for. ## Evidence Three independent observations, in order of strength: 1. **PR #35 (sticks coverage): failed 3 of 7 mutation runs.** Every failure was inside the **verbose re-run** that `make test` performs after a failure — i.e. the suite running a second time while the first run's processes are still winding down, at roughly doubled load. It passed all 9 clean gate runs, including three back-to-back. It never executes a line of `sticks.go`, so the sticks work is not implicated. 2. **PR #34 (rings coverage): failed once**, also in a deliberately-red build at host load ~99 on 48 cores. Did not recur in five clean runs. 3. **PR #34 review: could not reproduce** — 20 clean uncached runs green, six further mutated runs at load ~60 clean. Taken together: it is **load-sensitive, not random**. The common factor is concurrent pressure, and the most reliable trigger is the conditional verbose re-run introduced by #2, which doubles the load precisely when the suite is already failing. ## Why this is worth fixing rather than tolerating The failure mode is self-obscuring. The re-run exists to give diagnostics on a failure; if the re-run itself induces an unrelated failure, every genuine red build now carries a spurious second failure that has nothing to do with the change under test. That is exactly what happened three times in PR #35 — the author had to reason past it to trust their own mutation results. ## Definition of done 1. Determine **why** it is load-sensitive. Likely candidates, to be confirmed rather than assumed: a real timing assumption in the test (a deadline, a sleep, a bounded number of loop iterations before the signal is expected to land), or a genuine residual race the detector only wins the scheduling lottery on under pressure. 2. **If it is a test-side timing assumption**, remove the assumption rather than widening the timeout — a test that passes because a constant got bigger has not been fixed. Make it wait on a condition, not a duration. 3. **If it is a real race**, that is a defect in the #24 fix and must be reported as such before any test change. Say so and stop; do not paper over it by relaxing the test. 4. Capture the actual failure output — all three observations so far are "it failed", and **nobody has recorded the assertion text or a race report**. Get that first; it likely settles item 1 immediately. 5. The test still fails when the #24 fix is reverted (i.e. it remains a real guard). Prove it by mutation, as PR #26 originally did — reverting `AutoSaveOnSignal` to encode on the calling goroutine produced 73-113 `DATA RACE` reports. 6. Run the suite repeatedly **under deliberate load** (the condition that triggers it) to demonstrate the fix, not just once on an idle box. 7. `make check` green; `TODO.md` Completed Steps entry; do not rotate "Next Step"; commit title ends ` (closes #N)`. ## Implementation requirements - Do NOT weaken or delete the test to make it pass. It guards a bug that can destroy a player's save file. - Do NOT change the signal-handling, `pendingSaver`, service-point, or atomic-write logic settled in #23/#26 unless item 3 applies — and if it does, report before changing anything. - **Lint:** golangci-lint on this host shares one cache and one lock across concurrent agent sessions. Export `GOLANGCI_LINT_CACHE` to a fresh empty private directory AND retry on `parallel golangci-lint is running`; a private cache does not prevent the lock collision. Treat any result naming paths outside your worktree as void. - `make` targets only. Do NOT modify `.golangci.yml`. No Dockerfile/CI/`script/`. - Never mention Claude or Anthropic anywhere. ## Priority Medium-high. No user-facing defect — but it degrades the signal quality of every future red build in this repo, and it sits on top of the most consequential bug fixed so far.
Author
Collaborator

Failure text captured at last — it is not a data race

Fired during review of #38 (head 6f409bd),
on the verbose rerun make test does after a failure, under heavy parallel load
(a mutation to showMap was in the tree at the time — unrelated to this test,
and it is what triggered the rerun). Full output was written to a file and read
whole, not filtered.

The assertion, from the === NAME block:

=== NAME  TestAutoSaveOnSignalRacesTurnLoop
    autosave_test.go:63: the turn loop ran out of turns before the saves were taken

and the summary line:

--- FAIL: TestAutoSaveOnSignalRacesTurnLoop (0.55s)

There is no WARNING: DATA RACE anywhere in the output. The 1400-line log
contains exactly two --- FAIL lines: this one and the deliberate showMap
mutation. So this flake is not the race the test exists to catch.

What it actually is. autosave_test.go:63 is the t.Fatal at the bottom of
driveUntilDone:

const maxTurns = 1000
for range maxTurns {
    select {
    case <-done:
        return
    default:
    }
    fortify(g)
    g.command()
}
t.Fatal("the turn loop ran out of turns before the saves were taken")

TestAutoSaveOnSignalRacesTurnLoop asks for wantSaves = 25 saves while the
turn loop runs, capped at 1000 turns. The cap was hit before the saving
goroutine finished its 25 requests. That is a turn-budget exhaustion, i.e.
the handoff was working but too slowly under load, not a broken handoff and not
a race — each AutoSaveOnSignal costs the game goroutine a full state encode
plus a file write, all under -race, and 18 concurrent agent sessions on this
host is exactly the load that makes 1000 turns insufficient.

Note the deadline knob that exists (autoSaveWait = 10 * time.Second, commented
"long enough that a loaded machine cannot turn a working handoff into a spurious
failure") guards the waiting side only. The driving side is a fixed turn
count with no such headroom, which is the asymmetry.

Suggested direction, not filed as a fix here: bound driveUntilDone by wall
time (or raise/derive maxTurns from wantSaves) rather than by a fixed turn
count, so a slow machine cannot convert a working handoff into a failure — the
same reasoning autoSaveWait already documents.

Not a finding against #38: the test is
pre-existing, that PR touches no non-test code, and four other full
GOFLAGS=-count=1 make test runs on the same head were clean.

## Failure text captured at last — it is not a data race Fired during review of https://git.eeqj.de/sneak/rgoue/pulls/38 (head `6f409bd`), on the verbose rerun `make test` does after a failure, under heavy parallel load (a mutation to `showMap` was in the tree at the time — unrelated to this test, and it is what triggered the rerun). Full output was written to a file and read whole, not filtered. The assertion, from the `=== NAME` block: === NAME TestAutoSaveOnSignalRacesTurnLoop autosave_test.go:63: the turn loop ran out of turns before the saves were taken and the summary line: --- FAIL: TestAutoSaveOnSignalRacesTurnLoop (0.55s) **There is no `WARNING: DATA RACE` anywhere in the output.** The 1400-line log contains exactly two `--- FAIL` lines: this one and the deliberate `showMap` mutation. So this flake is *not* the race the test exists to catch. **What it actually is.** `autosave_test.go:63` is the `t.Fatal` at the bottom of `driveUntilDone`: const maxTurns = 1000 for range maxTurns { select { case <-done: return default: } fortify(g) g.command() } t.Fatal("the turn loop ran out of turns before the saves were taken") `TestAutoSaveOnSignalRacesTurnLoop` asks for `wantSaves = 25` saves while the turn loop runs, capped at 1000 turns. The cap was hit before the saving goroutine finished its 25 requests. That is a **turn-budget exhaustion**, i.e. the handoff was working but too slowly under load, not a broken handoff and not a race — each `AutoSaveOnSignal` costs the game goroutine a full state encode plus a file write, all under `-race`, and 18 concurrent agent sessions on this host is exactly the load that makes 1000 turns insufficient. Note the deadline knob that exists (`autoSaveWait = 10 * time.Second`, commented "long enough that a loaded machine cannot turn a working handoff into a spurious failure") guards the *waiting* side only. The *driving* side is a fixed turn count with no such headroom, which is the asymmetry. Suggested direction, not filed as a fix here: bound `driveUntilDone` by wall time (or raise/derive `maxTurns` from `wantSaves`) rather than by a fixed turn count, so a slow machine cannot convert a working handoff into a failure — the same reasoning `autoSaveWait` already documents. Not a finding against https://git.eeqj.de/sneak/rgoue/pulls/38: the test is pre-existing, that PR touches no non-test code, and four other full `GOFLAGS=-count=1 make test` runs on the same head were clean.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/rgoue#36