Merge fix/autosave-turn-budget-36 (drive on a condition, not a turn budget)
This commit was merged in pull request #40.
This commit is contained in:
70
TODO.md
70
TODO.md
@@ -35,6 +35,76 @@ 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, so the saving
|
||||
goroutine always finishes. A handoff that has stopped answering costs one
|
||||
`autoSaveWait` in total — `g.sigSave` is one deep, so an unserviced request
|
||||
stays in the channel and every later call finds it full and fails at once —
|
||||
and the failure is then the real assertion (`saves taken = 0, want 25`)
|
||||
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
|
||||
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. 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
|
||||
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
|
||||
|
||||
@@ -9,7 +9,6 @@ import (
|
||||
"io"
|
||||
"os"
|
||||
"path/filepath"
|
||||
"strings"
|
||||
"testing"
|
||||
"time"
|
||||
)
|
||||
@@ -17,7 +16,9 @@ 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 — see
|
||||
// there for what that bound comes to.
|
||||
const autoSaveWait = 10 * time.Second
|
||||
|
||||
// TestAutoSaveOnSignalRacesTurnLoop is the test issue #24 exists for: it
|
||||
@@ -34,12 +35,14 @@ 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. 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 . ")}
|
||||
|
||||
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 +77,50 @@ 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, so the saving
|
||||
// goroutine always finishes and done always closes. That bound is worth
|
||||
// stating exactly, because it is not one autoSaveWait.
|
||||
//
|
||||
// A handoff that has stopped answering altogether costs one, in total,
|
||||
// however many saves were asked for. g.sigSave
|
||||
// is one deep, so the unserviced request stays in the channel and every
|
||||
// later call finds it full and reports failure immediately — measured
|
||||
// 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
|
||||
// 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 +130,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 +303,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 +472,66 @@ 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.
|
||||
//
|
||||
// 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 {
|
||||
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.
|
||||
|
||||
Reference in New Issue
Block a user