Repository navigation
Conversation
…timeout-honesty test
`run-executor-timeout-honesty.test.ts` was the last load-sensitive test in the
suite: it set `maxRunWallClockMs` to 150 ms and expected a real connector
subprocess to spawn, complete the START handshake, durably ingest 5 records and
emit a PROGRESS `phase_boundary` inside that one window.
`maxRunWallClockMs` is a resettable no-progress allowance, not a total-run
budget — `markProgress` re-arms the timer on every PROGRESS message — but the
watchdog is armed at construction, before the subprocess is spawned. With no
PROGRESS before the phase boundary, the first allowance had to cover `node`
startup, the handshake and the ingest round-trip together.
Measured via the run-executor's own `elapsed_ms` at the phase-boundary latch
(24-core host): 84-124 ms idle, up to 148 ms under load, against a 150 ms
allowance. A 2 ms margin. That metric spans the whole attempt from `startedAt`,
so it is the right diagnostic for what the old allowance had to cover in one
stretch — but it is NOT a measure of this change's effect.
This raises the no-progress allowance to 400 ms and resets it on connector
readiness; the completion case stays at three allowances and the secondary
ceiling at four. Startup remains subject to the initial allowance.
- Both generated connectors emit a plain `PROGRESS` "ready" message immediately
after START, so the ingest round-trip no longer shares one allowance with
process startup. This does not make startup unbounded and does not remove
timing sensitivity. Verified by counting `markProgress` calls across the 8
tests: 39 re-arms with the message versus 31 without — exactly 8 more, one per
connector spawn. (`elapsed_ms` cannot show this: `startedAt` is stamped before
the watchdog exists, so the re-arm does not move it.)
- The allowance and the post-boundary sleep become named constants
(`WALL_CLOCK_BUDGET_MS`, `POST_BOUNDARY_SLEEP_MS = 3x`), so the invariant
("the sleep must out-run the allowance") is stated rather than encoded in two
unrelated literals.
Timeout honesty is unweakened. Every "must time out" test still hangs forever
with no further progress, so only the watchdog can end those runs. The
phase-boundary test's sleep is still a multiple of the allowance, so a re-armed
(rather than disarmed) watchdog would still fail it. The control test that
asserts a plain PROGRESS does not disarm the watchdog now exercises that
distinction instead of assuming it, because its connector emits one.
No headroom multiplier or reduction in flake frequency is claimed; passing runs
do not establish a causal rate change, and reliability under contention is
unproved. Production code is untouched.
Assisted-by: AI
Signed-off-by: Tim Nunamaker <tnunamak@gmail.com>
Contributor
Author
|
Already on main; closing as landed. Assisted-by: AI |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Why
A test that fails at random under load sends whoever investigates it hunting a bug in the run executor that is not there.
reference-implementation/test/run-executor-timeout-honesty.test.tswas the last such test in the suite: across six controlled full-suite arms it failed once, and the failure landed on the least loaded arm — so it was load-sensitive, but not determined by the concurrency cap and not a leak of an unowned background task.The test set
maxRunWallClockMsto 150 ms and required a real connector subprocess to spawn, complete theSTARThandshake (the first message the executor exchanges with the subprocess to confirm it is alive), durably ingest 5 records through a real in-memory ingest server, and emit aPROGRESSmessage of typephase_boundary— the connector's signal that it has finished one declared stage of work — all inside that window.A watchdog is the timer that kills a run if no progress arrives before it fires. 150 ms was never enough, because
maxRunWallClockMsis a resettable no-progress budget rather than a total-run budget: the watchdog re-arms on everyPROGRESSmessage, viacreateAttemptWatchdog'smarkProgress(run-executor.ts,arm()). But that watchdog is constructed during run setup (run-executor.ts:1045) before the connector subprocess is spawned. Until the connector's first PROGRESS message arrives there is nothing to re-arm it, so the budget also coversnodeprocess startup — a cost the test does not control and cannot bound.Measured with the run-executor's own
elapsed_msat the phase-boundary latch, on a 24-core host:elapsed_msThe sibling test's own comment claimed 150 ms was "comfortably longer than the ingest round-trip". Idle, it already consumed 83% of the budget; under load, 98.7%.
What changed
This is deliberately not "raise 150 ms to 5 s".
The test generates two throwaway connectors on the fly, one per scenario shape. Both now emit a plain
PROGRESS"connector ready"message immediately after START, which re-arms the watchdog once the process is up — so the ingest round-trip no longer shares a single allowance with process startup. The watchdog is armed at construction, before the spawn, so startup remains subject to the initial allowance: this does not make startup unbounded or remove timing sensitivity. Verified by countingmarkProgresscalls across the file's 8 tests: 39 re-arms with the message versus 31 without, exactly 8 more, one per connector spawn.Two claims from earlier revisions are retracted. One framed this as "removing the spawn race", which overclaims — startup is still bounded by the initial allowance. The other credited a drop in
elapsed_ms; that was wrong, becausestartedAtis stamped atrun-executor.ts:1122, before the watchdog exists, soelapsed_msspans the spawn and is blind to the re-arm. ThemarkProgresscounts above come from instrumentation added for this change and were not independently reproduced.The invariant is also named rather than implied:
WALL_CLOCK_BUDGET_MS = 400andPOST_BOUNDARY_SLEEP_MS = WALL_CLOCK_BUDGET_MS * 3— the latter being how long a connector keeps working locally after announcing a phase boundary, which must exceed the budget for the test to mean anything — replace scattered150/500/2_000literals, so "the post-boundary sleep must out-run the budget" is stated in one place instead of being an accident of two unrelated numbers.The allowance rises from 150 ms to 400 ms and resets on readiness. No headroom multiplier or reduction in flake frequency is claimed: passing runs do not establish a causal rate change, and the earlier "~14×" figure was derived from the retracted
elapsed_msmeasurement.What did not change
Production code is untouched — the diff is one test file.
Timeout honesty is not weakened. The property under test is that the executor reports a timeout as a timeout, and that a declared local-only phase boundary is not truncated. Every "must time out" test still uses a connector that hangs forever with no further progress, so only the watchdog can end those runs; a larger budget delays the kill, it cannot prevent it. The phase-boundary test's post-boundary sleep is still 3× the budget, so a re-armed rather than disarmed watchdog would still kill the run and fail the test. The test covering the secondary ceiling still relies on the real one: a run doing only local work is allowed four times the no-progress budget before it is killed, and that multiplier is unchanged. The control test asserting that a plain PROGRESS does not disarm the watchdog is now stronger, because its connector emits one, so the "phase_boundary, not merely PROGRESS" distinction is exercised rather than assumed.
The disarm logic itself remains separately covered, without any subprocess, by
test/run-executor-watchdog.test.ts(2 of 2 pass, unchanged). That file uses real short timers rather than an injected or fake clock; no fake-clock proof exists here or is added by this change.Verification
Node v22.23.1, branched on
origin/main(bac55262f). 40 runs of the file in total:The before arms passing is expected and is the point: this is a narrow-margin race, not a deterministic failure. The 2 ms measured margin, not a pass/fail count, is the evidence that the defect was real.
Retained logs cover 30 of the 40 runs; the fourth arm was run inline and its output was not kept, so that row is UNVERIFIED and establishes nothing. An independent review reproduced 10/10 on a different Node major version, but under idle conditions, which does not substantiate the loaded arm. Behavior under contention is unproved.
File runtime rises from about 4.8 s to about 7.7 s, because the five timeout tests now wait 400 ms instead of 150 ms before the watchdog fires. That is the honest cost of the larger budget.
ultracite, this repository's formatter and linter, reports one pre-existing formatting error on this file; it is present on unmodifiedorigin/mainand is not introduced here.Assisted-by: AI