Skip to content

test: end the quiesce crash child on its exit, not on the clock - #800

Merged
nissa-seru merged 1 commit into
anima-research:mainfrom
nissa-seru:imogen/f474-crash-child-exit
Oct 25, 2026
Merged

nissa-seru merged 1 commit into
anima-research:mainfrom
nissa-seru:imogen/f474-crash-child-exit

Conversation

@nissa-seru

Copy link
Copy Markdown
Contributor

test/host-quiesce.test.ts's crash tests ran their child with spawnSync(..., { timeout: 60_000 }), and the child carried a 30 s timer of its own. On a loaded host the 2,101-message test's child needed longer than 60 s to finish correctly, and the parent killed it. Each crash test now waits for its child's exit, and pass or fail rests on the child's exit code. Test-only.

Problem

"a REAL process exit after a 2,101-message resume batch was synced but before it was acked loses no deferred write and duplicates none" failed after 60.7 s in one of our full-suite runs, on a host whose load average was over 100 when that run ended, and in @antra-tess's full run on main at 3b9c7dd0, as #799 reports. It passes alone.

By run at main e2623b9457, with the predictions written before the runs:

  • Where the child's time goes: nearly all of it is one synchronous stretch in the resume flush, between the hand-off's persist and the ack's persist: readdDrained of the 2,101 entries, then ackDeferredWrites' store.sync(). It takes 1.1 s on a quiet host, with about 2 s of CPU for the whole child.
  • Under contention it stretches: pinned to one core with 11 busy loops there, 14.2 s; with 15, 17.0 s; with 60, 78.4 s. The CPU stays about the same.
  • The child's own 30 s timer can't end it: no timer runs inside that stretch. A 100 ms timer set in the child never ran in any of these runs, and the real child pinned with 15 busy loops ran 31.9 s and exited 0.
  • So only the parent's 60 s timeout bounds it: the test pinned with 60 busy loops failed after 61.1 s at "child staged the crash", null !== 0, the child killed. A copy of the child with no deadline, pinned the same way, exited 0 after 80.8 s.
  • The work is right: pinned with 7 and 11 busy loops, the test passed in 19 s and 29 s, every message present exactly once.

Changes

  • The parent spawns the child asynchronously and waits for its close, passing the test's signal, so a cancelled or timed-out test ends the child. It sets no deadline of its own, so a hang is the runner's test timeout to bound. The assertion shows the child's status, the signal that ended it if any, and the end of its stderr. An abort, or another error once the child has spawned, rejects at close with the error and the end of the child's stderr. A child that never spawned rejects at once.
  • The child's 30 s timer goes. Pass or fail rests on its exit code: 0 at the exit point, 3 when the staged queue isn't as staged, 4 when the staging ran to its end without reaching the exit point.
  • turn-start-ack waited forever after its nudge. It now exits 4 once runUntilIdle() returns, since its exit point is inside the nudged turn and the nudge is queued before runUntilIdle() looks.
  • redefer still waits for its exit point with no answer of its own. That exit comes from the abandon's teardown, and by reading, quiesce({ abandon }) can resolve after the framework's 10 s grace while the teardown still runs, so a 4 after it could come early on a starved host. If its exit point is missing, the runner's timeout ends it. Or, if nothing else keeps the child's event loop alive, Node ends it at once with exit 13, for a top-level await that never settles.
  • All five crash scenarios share the change. The 2,101 stays: it was chosen to exceed the 2,000-message window boot recovery used to scan for landed writes.

Tests

On Node v24.22.1, over main e2623b9457, each at a clean commit of this branch before it was squashed into this one.

At this commit's tree:

  • Checks: the typecheck and build are clean.
  • The full suite: 7,542 tests, 7,498 pass, 0 fail, 44 skipped.
  • The five crash tests pass together in 10 of 10 runs.
  • The 2,101 test pinned to one core with 60 busy loops there passes, taking 145 s. That's the condition that reproduced the failure above.
  • The same, under a 20 s runner timeout: the runner reports the test timed out after 20.0 s, and no crash child is left when the run ends.

At an earlier commit, which differs from this one only in how runCrashChild settles (on error as well as close), what its assertion message shows, and the name of the test's parameter:

  • host-quiesce.test.ts passes 50 of 50, and the five crash tests pass together in 20 of 20 runs.
  • The 2,101 test pinned with 60 busy loops passes 2 of 2.
  • Removals, each failing its test:
    • boot recovery's dedup scan limited to the last 2,000 messages: the 2,101 test fails at "present exactly once, in order";
    • 2,100 of the 2,101 messages staged: the child exits 3, 3 !== 0;
    • the big batch's exit moved past the resume's last persist: resume() returns, and the child exits 4;
    • turn-start-ack's exit hook not armed: its turn runs, runUntilIdle() returns, and the child exits 4.

Not verified

  • The full runs' failures by their text. Neither kept the assertion's message. That ours was this bound rests on its duration, 60.7 s, and on the run above that reproduces it. Her run gave no duration or platform.
  • Other tests that run a child under a timeout of their own. Several do. None of them has been seen to fail, and none is changed here.

What each part is for, and what we cut

  • The asynchronous spawn: spawnSync blocks the parent's event loop while the child runs, so without a timeout of its own neither the runner's timeout nor the test's signal could act on a hang.
  • The test's signal: without it, a test the runner times out or cancels would leave its child running.
  • Settling on close: the abort's error comes as the child is killed, before it has exited, so settling there would let the test remove the store under a live child.
  • Removing the child's 30 s timer: it couldn't cut the flush, which is where the time goes, and anywhere else it could only turn a slow, correct run into a false 4. Without it, a child stuck before its exit point is the runner's to end.
  • turn-start-ack's 4: a missing exit point there now fails by event once the nudged turn has ended, rather than waiting for the runner.
  • Cut: a longer timeout. A deadline sized to this child's work fails a correct run whenever a host is slow enough. The runner's timeout is a wall clock too, but it bounds every test's hang the same way and isn't sized to this work.
  • Cut: a 4 for redefer after its quiesce. It rests on the framework's own 10 s grace, so it would move the same false failure, not remove it.

  • No changelog fragment: the PR changes only tests (no-changelog).

Written by Imogen-2490 (Claude Opus 5.5). Ada-1017 (Claude Opus 5.5) chose its shape, and Abigail-2676 (Claude Opus 5.5) read it. Internal reviews read it.

Description checked and posted by Fiona-2757 (Claude Opus 5.5).

🤖 Written using Anthropic's Claude Opus 5.5 through the Rookery's tooling, and posted from the shared nissa-seru account.

host-quiesce.test.ts's "a REAL process exit after a 2,101-message
resume batch was synced but before it was acked loses no deferred write
and duplicates none" failed after 60.7 s in one of our full-suite runs,
on a host whose load average was over 100 when the run ended, and in a
maintainer's full run on main. It passes alone.

The test ran its crash child with spawnSync(..., { timeout: 60_000 }).
Nearly all of the child's time is one synchronous stretch in the resume
flush: readdDrained of the 2,101 entries, then the ack's store.sync().
It takes about 1.1 s on a quiet host and stretches with contention:
pinned to one core with 11 busy loops, 14.2 s; with 60, 78.4 s. The
child's own 30 s "exit point never reached" timer can't fire inside it,
since no timer runs until the stretch ends. So on a starved host the
parent's 60 s timeout killed a child that would have finished correctly:
pinned with 60 busy loops, the test failed after 61.1 s with the child's
status null, while a copy of the child with no deadline exited 0 after
80.8 s. Pinned with 7 and 11 busy loops the test passed, every message
present exactly once.

- The parent now spawns the child asynchronously and waits for its
  close, with the test's signal, so a cancelled or timed-out test ends
  the child. spawnSync blocked the parent's event loop while the child
  ran, so without its timeout neither the runner's timeout nor the
  signal could act. There is no deadline of the test's own; a hang is
  the runner's test timeout to bound. The helper settles on close only:
  an abort's error comes as the child is killed, before it exits, so
  settling there would let the test remove the store under a live
  child. An abort, or another error once the child has spawned, rejects
  at close with the error and the end of the child's stderr; a child
  that never spawned rejects at once. The assertion shows the child's
  status, the signal that ended it, and the end of its stderr.
- The child's 30 s timer goes. Pass or fail rests on its exit code: 0 at
  the exit point, 3 when the staged queue isn't as staged, 4 when the
  staging ran to its end without reaching the exit point.
- turn-start-ack, which waited forever after its nudge, now exits 4 once
  runUntilIdle() returns: its exit point is inside the nudged turn, and
  the nudge is queued before runUntilIdle() looks.
- redefer still waits for its exit point with no answer of its own: it
  comes from the abandon's teardown, and quiesce({ abandon }) can resolve
  after the framework's 10 s grace, before that teardown is done, so a 4
  after it could come early on a starved host. A missing exit point
  there is left to the runner's timeout, or ends at once with Node's
  exit 13 if nothing else keeps the child's event loop alive.

All five crash scenarios share the change. The 2,101 stays: it was
chosen to exceed the 2,000-message dedup window boot recovery used to
scan.

Test only; no behaviour changes.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@nissa-seru nissa-seru added the no-changelog Exempts this PR from the changelog check (internal-only change) label Oct 25, 2026

@github-actions github-actions Bot left a comment •

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Automated review

Recommendation: merge and fast-follow. 2 medium severity findings can be fixed after the merge.

Reviewed commit a90d2a7 with claude-opus-5-5, by reading the code. It did not run the code or look at the checks.

Does this change belong in the project?

It fits the project. This is a test-only fix for a flaky existing test (#799). The crash tests now wait for the child to exit, and the child's exit code decides pass or fail.

4 reasons with sources

It adds no new feature, dependency or interface, and all the changes stay inside the existing test files.

  • It fixes the reliability of a test for behaviour the project already has, so it belongs. The five REAL-process-exit crash scenarios already exist. The change swaps spawnSync with a 60 s timeout for an async spawn bound to the test's signal, and drops the child's 30 s timer. It does not change what the tests check. (test/host-quiesce.test.ts (crash scenarios))
  • The changes stay where crash tests already live: in the test and its child helper. No src/ files are touched. No changelog fragment is needed, because CONTRIBUTING.md asks for one only for behaviour-affecting changes, and its CI check is triggered by edits to src/. (test/helpers/quiesce-crash-child.ts)
  • The PR body follows the house format and the evidence standards. It has Problem, Changes, Tests and Not verified sections, gives numeric suite counts (7,542 tests, 7,498 pass, 0 fail, 44 skipped), and lists removals that make each test fail. (CONTRIBUTING.md, "What a PR should contain")
  • It is one coherent change, and its title uses the conventional-commit style the project defaults to. All of it serves one goal: ending the crash child when it exits, not when a clock runs out. That includes the turn-start-ack exit-4 path, which replaces a wait that never ended. (CONTRIBUTING.md, "What a PR should contain")

Findings

1 finding of medium or high severity, see the inline comment:

1 finding about lines the diff does not show:

  • Medium severity. The redefer child still waits forever when its exit point is missed, and it no longer has a timer to end it. test/helpers/quiesce-crash-child.ts:159-160
Details of this finding
  • Medium severity, test/helpers/quiesce-crash-child.ts:159-160. The redefer child still waits forever when its exit point is missed, and it no longer has a timer to end it. Once the 30 s timer is gone, redefer ends with await quiescing; await new Promise(() => {}) and nothing else ever exits. If a regression stops the split re-deferral write from happening, how the test fails depends on what keeps the child's event loop alive. If something does (for example the periodic sync interval that framework.start() installs when syncIntervalMs > 0), the child runs until the runner's 600 s timeout and leaves no diagnostic. If nothing does, Node exits with code 13 for an unsettled top-level await. Either way the failure is slow or unclear, where it used to be a clear exit 4 within 30 s. A long but finite timer after quiescing settles, well past the 10 s grace, would keep this scenario deterministic.
1 more finding, less severe
  • Low severity, documentation, test/helpers/quiesce-crash-child.ts:1-27. The child's header leaves out its exit codes and its new no-timeout contract. The header says only that 0 means the exit point was hit and anything else means staging failed. The change gives exit codes their meaning: 3 when the staged queue doesn't match, 4 when staging ran to its end without reaching the exit point, and 13 or a hang for redefer. It also deleted the comment that explained the child's own deadline. None of this is written down in the file, so the next maintainer has to rebuild from the PR description why the child has no timer and what 3 and 4 mean.

Comment thread test/host-quiesce.test.ts
Comment on lines +1890 to +1910
function runCrashChild(
storePath: string,
mode: string,
abort: AbortSignal,
): Promise<{ status: number | null; signal: NodeJS.Signals | null; stderr: string }> {
return new Promise((resolve, reject) => {
const child = spawn(process.execPath, [CRASH_CHILD, storePath, mode], { signal: abort, stdio: ['ignore', 'ignore', 'pipe'] });
let stderr = '';
let failure: Error | undefined;
child.stderr.setEncoding('utf8');
child.stderr.on('data', (chunk: string) => { stderr += chunk; });
child.on('error', (error) => {
failure = error;
if (child.pid === undefined) reject(error);
});
child.on('close', (status, signal) => {
if (failure) reject(new Error(`${failure.message} (stderr: ${stderr.slice(-800)})`, { cause: failure }));
else resolve({ status, signal, stderr });
});
});
}

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Medium severity. A stuck crash child is now bounded only by the 10-minute runner timeout, and its stderr is lost when that timeout fires.

runCrashChild sets no deadline. The only bound is --test-timeout=600000 in package.json's test script, so a child that never reaches its exit point now holds the test, and its concurrency slot, for 10 minutes. Before this change the bound was 30 s. If someone runs the file directly with node --test dist/test/host-quiesce.test.js and no --test-timeout, nothing ends it. When the runner times the test out, it reports the timeout right away. The later rejection that carries stderr.slice(-800) lands after the test has been reported, so a hang shows no child output for diagnosis. A generous bound that scales with load (several minutes) would fix the false failure without the unbounded hang, and it would keep the stderr in the failure message.

@nissa-seru
nissa-seru merged commit 371923e into anima-research:main Oct 25, 2026
16 checks passed
@nissa-seru
nissa-seru deleted the imogen/f474-crash-child-exit branch October 25, 2026 21:32
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

no-changelog Exempts this PR from the changelog check (internal-only change)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant