fix(#566): guard the file-scoped test timeout instead of splitting by size - #666
Merged
Conversation
… size #566 asks to split the two heaviest test files. Re-measured on 3c86f1c first, and the premise no longer holds: slotTypecheckPipeline 18394 ms (issue) -> 2032 ms cliBackendDetector 16506 ms (issue) -> 3772 ms slowest file today: devplatform/dockerBackend.test.ts, 5163 ms Neither named file is the slowest any more, and cliBackendDetector is 175 lines — splitting it into 4-6 files would be churn with nothing behind it. So this ships what the issue is actually about: nothing detects a file approaching the ceiling, which is why the margin went unwatched since #550 sized it. `--test-timeout` kills the FILE, not the leaf, and blames whichever leaf was running. The per-file total was not even observable: spec and tap flatten a glob to suite names, so the filename is gone. `test:summary` is the one event carrying both `file` and `duration_ms` — a second reporter on `npm test` records it at no extra cost, and check-test-file-durations.mjs turns it into a gate. The gate is a FRACTION of the ceiling (warn 25%, fail 50%), not a committed ms baseline. Durations vary by machine — this suite is ~36 s locally on 16 cores and ~172 s on a 4-vCPU runner — so an absolute number would be either permanently red or permanently asleep, and would need re-committing as the suite grows. That stale-baseline failure has bitten this repo before. The ceiling is parsed out of the `test` script rather than duplicated, so lowering --test-timeout tightens the guard automatically. Today: 572 files, slowest 5163 ms, 23.2x headroom. Mutation-checked rather than assumed — the guard exits 1 at 60000 ms (50%), exits 0 at 59999 ms with a WARN, and also exits 1 on an empty file list or a missing input, so it cannot pass while checking nothing.
…st-files # Conflicts: # middleware/package.json
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.
Closes #566
The issue's premise no longer holds
#566 asks to split
slotTypecheckPipelineandcliBackendDetector, sized on measurements taken back at PR #550. Re-measured on3c86f1c8, node 22.22.3, each file run on its own:test/builder/slotTypecheckPipeline.test.tstest/cliBackendDetector.test.tstest/devplatform/dockerBackend.test.tsNeither named file is the slowest any more, and
cliBackendDetectoris 175 lines — splitting that into 4–6 files would be churn with nothing behind it.So this PR ships what the issue is actually about.
What was really missing
--test-timeoutis applied to the file, not the leaf. A file whose leaves are each fast but whose total crosses the ceiling is killed as a unit, and the failure is reported against whichever leaf happened to be running — it does not look like "this file grew too big".The margin went unwatched since #550 sized it, and there is a concrete reason why: the per-file total was not observable at all. Run a glob through the
specortapreporter and both flatten to suite names — the filename is gone. (Confirmed while building this: the tap output for the full suite contains no file paths.)test:summaryis the one event that carries bothfileandduration_ms, emitted once per file. A second reporter on the existingnpm testrecords it at no extra cost — the guard must not double the CI time it guards — andscripts/check-test-file-durations.mjsturns the JSON into a gate.Why a fraction of the ceiling, not a committed baseline
The repo's other ratchets commit an absolute number because they count things that do not vary by machine.
Corrected after seeing the guard run on CI. I first argued durations vary 4.7× by machine, citing ~36 s locally vs ~172 s on the runner. That conflated two different numbers. The aggregate varies 4.7× — but that is parallelism (16-way local vs ~4-way CI), not speed. Per FILE the two environments agree closely: slowest file 5147 ms locally vs 5358 ms on CI, a 4 % difference.
So a committed ms baseline would have been more viable than I claimed. The fraction is still the better fit, for reasons that survive the correction: it needs no re-committing as the suite grows, it cannot go stale, and it states the risk directly — how close the slowest file is to being killed — rather than encoding it indirectly as a number someone must maintain. But the "machines differ too much" argument was wrong, and a reviewer weighing this tradeoff should have the real figures.
testscript, not duplicated, so lowering--test-timeouttightens the guard automatically instead of silently widening the gap between two numbers.Confirmed running on CI (job
middleware (lint + typecheck + test), step Test file durations): 572 files, slowestdockerBackend.test.tsat 5358 ms = 22.4x headroom. The step is instantaneous — it reads the JSON the test step already wrote.Mutation check
The guard is proven to fail, not assumed to:
The last two matter most: a guard that passes while checking nothing is worse than no guard.
Something the measurement turned up that you should see
While building this I hit a real 120 000 ms file timeout on
test/devplatform/devPlatformRoutes.test.ts— the exact failure mode #566 describes. It is not file size. In isolation that file runs in 1.77 s, 29/29 green; it only hangs under full-suite concurrency.I then ran a controlled A/B on this branch, same commit, 3 rounds each at
--test-concurrency=4:Identical — the reporter is not the cause. But it also means
--test-concurrency=4does not make this suite deterministic on a 16-core machine: 4 of 6 full runs failed, each with a different victim (builderIssueReporting,devPlatformGates,devWebhooks,devPlatformRoutes), the errors beingECONNREFUSED/fetch failed. That is the localhost socket contention #605 suspects, and it is worse than #605's single green run suggested. CI's 4-vCPU runner is consistently green today, so it does not bite there.This does not affect the change in this PR — the guard is independent, and CI is green — but it means the concurrency pin in #664 should be read as reducing the flake, not fixing it. I have corrected that PR's description accordingly.
Verification
middleware: build OK · 6174 tests, 0 fail, 4 skipped · lint 0 errors · typecheck clean · typecheck:test ratchet unchanged at 406test-file-durations.jsonis gitignored — it is a measurement of the machine that ran it, not a repo factmain(3c86f1c8)