sneak/rgoue
1
0
Fork 0
Code Issues 10 Pull Requests Actions Packages Projects Releases Wiki Activity

test: drive the autosave race test to a condition, not a turn count (closes #36)

Browse Source 
TestAutoSaveOnSignalRacesTurnLoop failed intermittently under load. The
captured failure text settles what it was: driveUntilDone's

    t.Fatal("the turn loop ran out of turns before the saves were taken")

with no WARNING: DATA RACE anywhere in the log. The handoff is fine; the
test's own drive loop ran out of its fixed 1000-turn budget first.

Confirmed by instrumenting the loop to report the turns it actually
used. The count tracks scheduling pressure and nothing else: about
60-120 turns at host load ~57 with the whole machine to spread over, 418
at GOMAXPROCS=4, 539 and 655 at 2 and 1, and past 1000 under the doubled
load of the verbose rerun the test target performs after a failure. The
turns spent between one save being answered and the next request
arriving are not work, they are the saving goroutine's wake-up latency,
so a fixed turn count is a wall-clock assumption in disguise. Raising it
would hide the flake, not fix it.

So the budget is gone rather than larger. driveUntilDone drives until
the saving goroutine finishes and nothing else. Termination still holds,
it just belongs to the code under test: every AutoSaveOnSignal returns
within the timeout it is handed, and g.sigSave is one deep, so an
unserviced request stays in the channel and every later call finds it
full and fails at once. A dead handoff therefore releases the saving
goroutine after one autoSaveWait however many saves were asked for, and
what fails is the real assertion - "saves taken = 0, want 25" - rather
than "out of turns".

Removing the cap exposed a second assumption underneath it. testTerm
answers space and newline for ever once its script is exhausted, and
neither key takes a turn, so command(), which loops until the player
consumes one, never returns; the old cap was silently sized to the
script. An uncapped drive wedged inside a single command() call. The two
drive tests now use driveTerm, a headless terminal whose script repeats,
so every key it hands out takes a turn.

The guard is undiminished, shown by mutation and reverted afterwards.
Reverting the fix from the earlier signal-autosave work - AutoSaveOnSignal
replaced by a direct g.autoSave(), encoding on the calling goroutine -
still fails the test with 139 DATA RACE reports, snapshotHeader reading
what executeCommand writes. Removing serviceAutoSaveRequest from
command() still fails it too, now in 10s with "saves taken = 0, want 25"
instead of by hanging.

Under load: at GOMAXPROCS=2 on a 48-core host at load ~150, with an
unrelated deliberate failure in the tree so every run took the verbose
rerun, the old code failed 8 of 8 runs and the new code 0 of 8. Also
green across 24 concurrent unconstrained runs at load ~120, 10 runs
alongside a spinner load, and 5 runs each at GOMAXPROCS 1, 2 and 4.

No non-test code changed. make check green, lint 0 issues, .golangci.yml
byte-identical.
This commit is contained in:
clawbot
2026-08-09 16:45:34 +00:00
parent 13caec4298
commit cb7ddfdb67
2 changed files with 129 additions and 17 deletions
Download Patch File Download Diff File Expand all files Collapse all files

57
TODO.md
View File

@@ -35,6 +35,63 @@ is finished.
# Completed Steps
- 2026-08-09 `TestAutoSaveOnSignalRacesTurnLoop` de-flaked at the cause
(`fix/autosave-turn-budget-36`, closes #36). The failure text was captured
before anything was changed and it is **not** a data race: the assertion was
`driveUntilDone`'s
`t.Fatal("the turn loop ran out of turns before the saves were taken")`, with
no `WARNING: DATA RACE` anywhere in the log. The handoff fixed in #24 was
working; the test's own drive loop was running out of its fixed 1000-turn
budget first.
Confirmed rather than taken on trust. Instrumenting the loop to report the
turns it actually used showed the count tracking scheduling pressure and
nothing else: about 60-120 turns at host load ~57 with the whole machine to
spread over, 418 at `GOMAXPROCS=4`, 539 and 655 at 2 and 1, and past 1000 —
the recorded failure — under the doubled load of the verbose rerun that the
test target performs after a failure. The turns between one save being
answered and the next request arriving are not work; they are the saving
goroutine's wake-up latency, so a fixed turn count is a wall-clock
assumption in disguise, which is why raising it would have hidden the flake
rather than fixed it.
So the budget is gone rather than larger. `driveUntilDone` now drives until
the saving goroutine finishes and nothing else. Termination is not lost, it
just belongs to the code under test instead of to the test: every
`AutoSaveOnSignal` returns within the timeout it is handed, and `g.sigSave`
is one deep, so an unserviced request stays in the channel and every later
call finds it full and fails at once — a dead handoff releases the saving
goroutine after one `autoSaveWait` however many saves were asked for, and
the failure is then the real assertion (`saves taken = 0, want 25`) instead
of "out of turns".
Removing the cap exposed a second assumption underneath it, which is the
reason this is not a one-line diff. `testTerm` answers space and newline for
ever once its script is exhausted, and neither key takes a turn, so
`command()` — which loops until the player consumes one — never returns; the
old cap was silently sized to the script (4000 characters, two per turn,
against 1000 turns). An uncapped drive wedged inside a single `command()`
call. The two drive tests therefore use a new `driveTerm`, a headless
terminal whose script repeats, so every key it hands out takes a turn.
Both halves of the definition of done were demonstrated by mutation, with
the deliberately-broken tree reverted afterwards and `.golangci.yml` left
byte-identical (sha256 `021cc83f...46bcb`). Reverting #24 —
`AutoSaveOnSignal` replaced by a direct `g.autoSave()`, encoding on the
calling goroutine — still fails the test with 139 `WARNING: DATA RACE`
reports naming `snapshotHeader` reading what `executeCommand` writes, so the
guard is undiminished. Removing the `serviceAutoSaveRequest` call from
`command()` still fails it too, now in 10s with `saves taken = 0, want 25`
rather than by hanging.
Under load, an A/B at `GOMAXPROCS=2` on a 48-core host at load ~150, with an
unrelated deliberate failure in the tree so that every run took the verbose
rerun: the old code failed 8 of 8 runs with "ran out of turns"; the new code
failed 0 of 8, the only failure being the planted one. Also green across 24
concurrent unconstrained runs at load ~120, 10 runs alongside a spinner
load, and 5 runs each at `GOMAXPROCS` 1, 2 and 4. `make check` green, lint 0
issues.
- 2026-08-09 Wizard commands under test (`test/wizard-coverage`, closes #7): the
last of the three thin spots, so the coverage step is now closed rather than
narrowed. `game/wizard.go`'s eight functions had no tests of their own, and

89
game/autosave_test.go
View File

@@ -9,7 +9,6 @@ import (
"io"
"os"
"path/filepath"
"strings"
"testing"
"time"
)
@@ -17,7 +16,8 @@ import (
// autoSaveWait is the deadline the tests hand AutoSaveOnSignal when they
// expect the save to be taken. It is long enough that a loaded machine
// cannot turn a working handoff into a spurious failure, and it is never
// actually waited out on a passing run.
// actually waited out on a passing run. It is also what bounds
// driveUntilDone, by way of the saving goroutine it waits for.
const autoSaveWait = 10 * time.Second
// TestAutoSaveOnSignalRacesTurnLoop is the test issue #24 exists for: it
@@ -34,12 +34,12 @@ const autoSaveWait = 10 * time.Second
func TestAutoSaveOnSignalRacesTurnLoop(t *testing.T) {
t.Parallel()
// Same mix as TestTurnLoopCrashSweep: the spaces answer any --More--
// prompt, and the script is long enough that the drive never runs it
// out.
script := []byte(strings.Repeat("h j k l y u b n s . ", 400))
// Same mix as TestTurnLoopCrashSweep — the spaces answer any --More--
// prompt — on a driveTerm, so the drive can run for as long as the
// saves take rather than for as long as a script lasts.
term := &driveTerm{script: []byte("h j k l y u b n s . ")}
g := New(Params{Seed: 20260809, Term: &testTerm{input: script}})
g := New(Params{Seed: 20260809, Term: term})
g.FileName = filepath.Join(t.TempDir(), "rogue.save")
g.startLevel()
g.prePlay()
@@ -74,14 +74,38 @@ func TestAutoSaveOnSignalRacesTurnLoop(t *testing.T) {
// driveUntilDone runs turns until the saving goroutine is finished,
// fortifying the hero each turn so no death exits the test binary. The
// turn cap keeps a broken handoff from hanging the suite instead of
// failing it.
// condition it waits on is that goroutine finishing — nothing else.
//
// It used to stop after a fixed 1000 turns and fail, and that cap was a
// load-sensitive assumption wearing a counter's clothes (issue #36). The
// turns this loop spends between one save request being answered and the
// next arriving are not work; they are the saving goroutine's scheduling
// latency, so the turn count 25 saves costs is a function of how
// contended the machine is rather than of anything the code under test
// does. Measured here on a 48-core host at load ~57: about 60-120 turns
// with a whole machine to spread over, 418 to 655 as GOMAXPROCS was cut
// from 4 to 1, and past 1000 under the doubled load of the verbose
// rerun, which is the flake this replaces. A budget that has to be
// guessed cannot be guessed right, so there is no budget.
//
// Dropping it costs no termination guarantee, because the bound belongs
// to the code under test and not to this loop. Each AutoSaveOnSignal
// call returns within the timeout the caller hands it, and g.sigSave is
// one deep: once a request goes unserviced it stays in the channel, so
// every later call finds it full and reports failure immediately. A
// handoff that has stopped answering therefore releases the saving
// goroutine after one autoSaveWait however many saves were asked for,
// done closes, and the caller's own assertion — the count of saves
// actually taken — is what fails, which says far more than "out of
// turns" ever did. `go test -timeout 30s` remains the backstop under
// that.
//
// The one thing the caller does have to supply is a terminal that can
// feed an unbounded drive: see driveTerm.
func driveUntilDone(t *testing.T, g *RogueGame, done <-chan struct{}) {
t.Helper()
const maxTurns = 1000
for range maxTurns {
for {
select {
case <-done:
return
@@ -91,8 +115,6 @@ func driveUntilDone(t *testing.T, g *RogueGame, done <-chan struct{}) {
fortify(g)
g.command()
}
t.Fatal("the turn loop ran out of turns before the saves were taken")
}
// TestAutoSaveOnSignalWhileBlockedOnInput is the case the fix is really
@@ -266,9 +288,7 @@ func TestAutoSaveOnSignalTimesOutLeavingTheOldSave(t *testing.T) {
func TestAutoSaveOnSignalWithoutASaveFile(t *testing.T) {
t.Parallel()
g := New(Params{Seed: 5, Term: &testTerm{
input: []byte(strings.Repeat("s . ", 200)),
}})
g := New(Params{Seed: 5, Term: &driveTerm{script: []byte("s . ")}})
g.FileName = ""
g.startLevel()
g.prePlay()
@@ -437,6 +457,41 @@ func mkBlockedGame(t *testing.T, term Terminal) *RogueGame {
return g
}
// driveTerm is a headless Terminal whose script repeats instead of
// running out, for the tests that drive the turn loop until something
// else finishes rather than for a set number of turns.
//
// testTerm cannot do that job. Once its script is exhausted it answers
// space and newline for ever, and neither takes a turn, so command() —
// which loops until the player does something that consumes one, the
// `if !g.After { ntimes++ }` in command.c — never returns. A drive with
// a turn cap sized to its script never notices; a drive that runs until
// the saves are taken wedges inside a single command() call, which is
// what a first attempt at issue #36 did. Cycling a script of commands
// that all take a turn removes the failure mode instead of sizing
// around it.
type driveTerm struct {
script []byte
pos int
}
func (t *driveTerm) Render(*Window) {}
func (t *driveTerm) Repaint() {}
func (t *driveTerm) Fini() {}
// Interrupt has nothing to wake: this terminal's ReadChar never blocks.
func (t *driveTerm) Interrupt() {}
// ReadChar hands out the next scripted key, wrapping at the end.
func (t *driveTerm) ReadChar() (byte, bool) {
ch := t.script[t.pos]
t.pos = (t.pos + 1) % len(t.script)
return ch, true
}
// blockingTerm is a Terminal that genuinely blocks in ReadChar until a
// key is pushed or Interrupt wakes it — which testTerm, whose reads never
// block, cannot reproduce.