1 Commits

Author SHA1 Message Date
clawbot
3061931291 test: drive the autosave race test to a condition, not a turn count (closes #36)
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. Each old-code failure took 0.12
seconds - 1000 turns burned in a tenth of a second - which is why every
attempt to reproduce this by loading the host failed: the cap was never
a wall-clock allowance at all.

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, so the saving goroutine always
finishes. A handoff that has stopped answering costs one autoSaveWait in
total, because g.sigSave is one deep and an unserviced request stays in
the channel for every later call to find full and fail on at once; what
fails is then the real assertion, "saves taken = 0, want 25", rather
than "out of turns". That is not the worst case, and the comment states
the bound that actually holds: a handoff that drains each request but
slower than autoSaveWait costs one timeout per save, wantSaves *
autoSaveWait = 250s, which would run past the 30s package timeout. It
needs about ten seconds of scheduler starvation per save against the
0.12s-per-1000-turns regime above, so it is remote, and a turn cap did
not bound it either.

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.
Repeating is necessary and not sufficient, and the comment on driveTerm
says which property is load-bearing: ' ' clears After outright and all
eight movement keys clear it on a refused step, so a script of only
those keys wedges exactly as testTerm's tail did - with the script set
to " " the drive hits the 30s timeout inside command(). What makes the
wedge impossible is that the cycle always contains an unconditional
turn-taker, and these scripts contain two, '.' and 's', neither of which
can be refused by being blocked in all directions, Held, in a bear trap,
or under NoCommand > 0. Trimming both out would bring the wedge back.

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 a flood of DATA RACE reports (139 here, 62-110
on another machine; the property is what is pinned, not the number),
the encoder reading what the turn loop 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.
2026-08-09 17:06:45 +00:00
2 changed files with 75 additions and 22 deletions

27
TODO.md
View File

@@ -58,12 +58,18 @@ is finished.
So the budget is gone rather than larger. `driveUntilDone` now drives until So the budget is gone rather than larger. `driveUntilDone` now drives until
the saving goroutine finishes and nothing else. Termination is not lost, it 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 just belongs to the code under test instead of to the test: every
`AutoSaveOnSignal` returns within the timeout it is handed, and `g.sigSave` `AutoSaveOnSignal` returns within the timeout it is handed, so the saving
is one deep, so an unserviced request stays in the channel and every later goroutine always finishes. A handoff that has stopped answering costs one
call finds it full and fails at once — a dead handoff releases the saving `autoSaveWait` in total — `g.sigSave` is one deep, so an unserviced request
goroutine after one `autoSaveWait` however many saves were asked for, and stays in the channel and every later call finds it full and fails at once —
the failure is then the real assertion (`saves taken = 0, want 25`) instead and the failure is then the real assertion (`saves taken = 0, want 25`)
of "out of turns". instead of "out of turns". The worst case is not that one: a handoff that
drains each request but slower than `autoSaveWait` costs one timeout per
save, `wantSaves × autoSaveWait` = 250s, which would run past the 30s
package timeout instead of reaching the assertion. It takes ~10s of
scheduler starvation per save against a measured 0.12s per 1000 turns, so it
is remote, and the turn cap did not bound it either. The comment in the test
states that bound rather than the optimistic one.
Removing the cap exposed a second assumption underneath it, which is the 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 reason this is not a one-line diff. `testTerm` answers space and newline for
@@ -72,7 +78,14 @@ is finished.
old cap was silently sized to the script (4000 characters, two per turn, old cap was silently sized to the script (4000 characters, two per turn,
against 1000 turns). An uncapped drive wedged inside a single `command()` against 1000 turns). An uncapped drive wedged inside a single `command()`
call. The two drive tests therefore use a new `driveTerm`, a headless 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. terminal whose script repeats. Repeating is necessary but not sufficient,
and the test says so: `' '` clears `After` outright and all eight movement
keys clear it on a refused step, so a script of only those keys wedges just
as `testTerm`'s tail did. What makes the wedge impossible is that the cycle
always holds an _unconditional_ turn-taker, and these scripts hold two —
`'.'` (empty handler) and `'s'` (`search`, which writes `After` on no path),
neither refusable by blocked-in-all-directions, `Held`, a bear trap, or
`NoCommand > 0`. Removing both would bring the wedge back.
Both halves of the definition of done were demonstrated by mutation, with Both halves of the definition of done were demonstrated by mutation, with
the deliberately-broken tree reverted afterwards and `.golangci.yml` left the deliberately-broken tree reverted afterwards and `.golangci.yml` left

View File

@@ -17,7 +17,8 @@ import (
// expect the save to be taken. It is long enough that a loaded machine // 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 // cannot turn a working handoff into a spurious failure, and it is never
// actually waited out on a passing run. It is also what bounds // actually waited out on a passing run. It is also what bounds
// driveUntilDone, by way of the saving goroutine it waits for. // driveUntilDone, by way of the saving goroutine it waits for — see
// there for what that bound comes to.
const autoSaveWait = 10 * time.Second const autoSaveWait = 10 * time.Second
// TestAutoSaveOnSignalRacesTurnLoop is the test issue #24 exists for: it // TestAutoSaveOnSignalRacesTurnLoop is the test issue #24 exists for: it
@@ -36,7 +37,9 @@ func TestAutoSaveOnSignalRacesTurnLoop(t *testing.T) {
// Same mix as TestTurnLoopCrashSweep — the spaces answer any --More-- // Same mix as TestTurnLoopCrashSweep — the spaces answer any --More--
// prompt — on a driveTerm, so the drive can run for as long as the // 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. // saves take rather than for as long as a script lasts. The '.' and
// the 's' are what make an unbounded drive safe, and at least one of
// the two has to stay in the cycle: see driveTerm.
term := &driveTerm{script: []byte("h j k l y u b n s . ")} term := &driveTerm{script: []byte("h j k l y u b n s . ")}
g := New(Params{Seed: 20260809, Term: term}) g := New(Params{Seed: 20260809, Term: term})
@@ -89,16 +92,28 @@ func TestAutoSaveOnSignalRacesTurnLoop(t *testing.T) {
// guessed cannot be guessed right, so there is no budget. // guessed cannot be guessed right, so there is no budget.
// //
// Dropping it costs no termination guarantee, because the bound belongs // Dropping it costs no termination guarantee, because the bound belongs
// to the code under test and not to this loop. Each AutoSaveOnSignal // 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 // call returns within the timeout the caller hands it, so the saving
// one deep: once a request goes unserviced it stays in the channel, so // goroutine always finishes and done always closes. That bound is worth
// every later call finds it full and reports failure immediately. A // stating exactly, because it is not one autoSaveWait.
// handoff that has stopped answering therefore releases the saving //
// goroutine after one autoSaveWait however many saves were asked for, // A handoff that has stopped answering altogether costs one, in total,
// done closes, and the caller's own assertion — the count of saves // however many saves were asked for. g.sigSave
// actually taken — is what fails, which says far more than "out of // is one deep, so the unserviced request stays in the channel and every
// turns" ever did. `go test -timeout 30s` remains the backstop under // later call finds it full and reports failure immediately — measured
// that. // at 10.0s for 25 saves with the service point deleted from command().
// What fails is then the caller's own assertion, the count of saves
// actually taken, which says far more than "out of turns" ever did.
//
// A handoff that still drains every request but takes longer than
// autoSaveWait to do it is the worst case, and costs one timeout per
// save: wantSaves * autoSaveWait, 250s at these constants, which would
// run past the package timeout rather than reach the assertion. It
// takes about ten seconds of scheduler starvation per save to get
// there, against a regime measured at 0.12s per 1000 turns, so it is
// remote — and the 1000-turn cap did not bound it either, a turn count
// being no kind of time bound. `go test -timeout 30s` is the backstop
// under all of it.
// //
// The one thing the caller does have to supply is a terminal that can // The one thing the caller does have to supply is a terminal that can
// feed an unbounded drive: see driveTerm. // feed an unbounded drive: see driveTerm.
@@ -467,9 +482,34 @@ func mkBlockedGame(t *testing.T, term Terminal) *RogueGame {
// `if !g.After { ntimes++ }` in command.c — never returns. A drive with // `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 // 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 // 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 // what a first attempt at issue #36 did.
// that all take a turn removes the failure mode instead of sizing //
// around it. // Repeating the script is necessary but nowhere near sufficient, and
// the difference is what anyone editing one of these scripts has to
// know. Most keys take a turn only conditionally. ' ' is the "legal
// illegal command" and clears After outright (tables.go). All eight
// movement keys clear it whenever the step is refused: a wall or the
// map edge (move.go moveResolve), an illegal diagonal (moveTarget), or
// a confused step that lands back in place (moveHero). A script of
// nothing but those keys wedges exactly the way testTerm's tail does,
// repetition or no repetition — with the script set to just " " this
// drive hits the 30s package timeout inside command().
//
// What actually makes the wedge impossible is that the cycle always
// contains at least one *unconditional* turn-taker, and the scripts
// here carry two: '.', the rest command, whose handler is empty, and
// 's', search, which writes After on no path. Nothing refuses either
// one — not being blocked in all eight directions, not Held, not stuck
// in a bear trap, and not NoCommand > 0, where playTurn skips
// executeCommand altogether and After is simply left true. Trim both
// out and the wedge this test exists to remove comes straight back.
//
// One further precondition, from what this fake does not supply:
// testTerm's tail answered a newline every other read and this does
// not. Nothing reachable from these scripts asks for one — waitFor('\n')
// sits on the death and score paths (rip.go, score.go), which fortify
// prevents from ever being reached — but a script that could reach them
// would park in waitFor for ever.
type driveTerm struct { type driveTerm struct {
script []byte script []byte
pos int pos int