diff --git a/TODO.md b/TODO.md index 62c4046..6f7d22a 100644 --- a/TODO.md +++ b/TODO.md @@ -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 diff --git a/game/autosave_test.go b/game/autosave_test.go index 9641161..1093e22 100644 --- a/game/autosave_test.go +++ b/game/autosave_test.go @@ -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.