test(cli): stop asserting the winner of a 1ms race in the Vale timeout test - #320
test(cli): stop asserting the winner of a 1ms race in the Vale timeout test#320thecodedrift wants to merge 1 commit into
Conversation
…t test The test gave a 1ms budget to a one-line document and demanded a timeout. That asserts the winner of a race: the timer has to fire before a child running in its OWN process, which does not care whether our event loop is free. Measured, that document takes Vale about 46ms, so 1ms normally wins — and it was seen losing once, across four concurrent full-suite runs, reporting a clean "ok" where the test demanded a "timeout". Captured assertion, which issue #262 had never managed to record for its own two tests: FAIL test/vale-run.test.ts > marks a timeout blocking expected { status: 'ok', blocking: false } to match { status: 'timeout', blocking: true } The production timeout is correct and is not changed: a settled guard, a cleared timer, and an unref so it never holds the loop open. Only the test's budget was wrong. The race is removed by making the work outlast the budget by a margin nothing plausible closes. Vale is QUADRATIC in the size of one file, measured on the pinned binary: 80KB 0.3s | 160KB 0.9s | 320KB 3.5s | 640KB 14s | 1MB 48s So ~320KB of prose against a 100ms budget is a 33x margin the right way round, confirmed by the mutation check: disabling the timer lets the same run finish in 3290ms and report "ok". Eight concurrent copies of the test now pass, which is the contention that broke the old one. The run is killed at 100ms, so the test costs about that rather than 3.5s. This is not either of the two tests #262 names — those passed 9 of 9 runs here. It is a separate flake that entered with 54cd0c0, inside the 0.11.2 range. Refs #262
fde584c to
e1ed936
Compare
|
@claude /review |
|
Claude finished @thecodedrift's task in 2m 8s —— View job Review completeReview mode: incremental — read 0 prior review thread(s) before reviewing.
SummaryThe diff is a single test file change (+20/-2), replacing the racy 1ms-timeout / one-line-document setup in I verified the underlying mechanics in
This is a solid fix for the race: instead of asserting a 1ms timer beats a ~46ms child process (a race the timer can lose under load), it now asserts a 100ms timer beats a ~3.5s child process — a race that's essentially decided before it starts, and one that fails safe if the timer itself gets delayed. I didn't find any correctness bug, removed test coverage, or convention violation in the diff. One inline note (informational, not blocking): left on the No other findings. Nothing from the prior review to carry forward since there wasn't one. |
![claude[bot]](https://avatars.githubusercontent.com/in/1236702?s=60&v=4){kind=small}
|
|
||
| expect( | ||
| await runVale({ cwd, paths: ["doc.md"], timeoutMs: 1 }) | ||
| await runVale({ cwd, paths: ["doc.md"], timeoutMs: 100 }) |
There was a problem hiding this comment.
[New] Minor, not blocking: the fix's margin (100ms budget vs. ~3.5s measured real runtime) is what makes this deterministic, but that margin is measured on one pinned binary/host. It only has to survive down to roughly 3x for the timeout to still win reliably; anything that shrinks the ~35x margin toward that — a materially faster CI runner, a future Vale binary bump that improves the quadratic constant, or running this in a lower-resource sandbox where process startup itself eats a chunk of the 100ms — narrows the safety margin rather than eliminating the race outright. Given the PR's own verification (mutation check + 8 concurrent copies) already stress-tested this, I'd treat this as informational rather than something to act on now — just flagging it as the one axis that could reintroduce flakiness later if the constants drift.
1 participant
Stack (root → tip):
Found while investigating #262. This is not either of the two tests that issue names — those passed 9 of 9 full-suite runs here. It is a separate flake, and it entered with
54cd0c0(the #300 fix), inside the 0.11.2 range.The captured failure
#262's main gap is that the assertion output was never recorded. This one now is:
Reproduced once across four concurrent full-suite runs. Idle it passes 15/15, and under light contention 6/6 — it needs real load.
Why it raced
The test gave a 1ms budget to a one-line document. That asserts the winner of a race: the timer must fire before a child that runs in its own process and does not care whether our event loop is free. Measured, that document takes Vale ~46ms, so 1ms normally wins. Under load the timer's callback is delayed while the child keeps going, and it loses.
The production timeout is correct and is unchanged — a
settledguard, a cleared timer, and anunrefso it never holds the loop open. Only the test's budget was wrong.The fix
Make the work outlast the budget by a margin nothing plausible closes. Vale is quadratic in the size of a single file, measured on the pinned binary:
So ~320KB of prose against a 100ms budget is a 33x margin the right way round, where the old test had 46x the wrong way. The run is killed at 100ms, so the test costs about that, not 3.5s.
Verified
ok, failing the test — which both proves the test exercises the timeout path and independently confirms the 320KB sizing.Related, and worse — filed separately
That quadratic has a product consequence beyond this test.
VALE_TIMEOUT_MSis 60s, and a timeout returnsblocking: trueimmediately rather than being excluded-and-retried the way an unparseable file now is. So one markdown file over roughly 1.1MB blocks the wholecheckrun and every other file's findings are lost — the exact shape #300 fixed, on a path #300 did not cover.Refs #262