Skip to content

fix(qa): take the wall clock out of the preflight sweep's CONTROL leg - #19382

Merged
os-project-manager merged 3 commits into
mainfrom
claude/issue-18982-preflight-control-leg-timeout
Sep 20, 2026
Merged

os-project-manager merged 3 commits into
mainfrom
claude/issue-18982-preflight-control-leg-timeout

Conversation

@os-project-manager

Copy link
Copy Markdown
Collaborator

Fixes #18982

Clause-②: no

The finding

⭐ CONTROL — refuses NOTHING when no override is named spawned a real vitest list child inside its own clocked it() window, so its verdict carried a wall-clock component. That is what reddened Test Core (1/6) on pull requests that change no file under packages/qa/.

⛔ The budget was not too small. Two measurements say it was judging something it cannot act on.

1. On a synchronous body a testTimeout cannot interrupt anything — here it was a post-hoc wall-clock assertion and nothing else. execFileSync blocks the worker's event loop, so vitest's timer cannot fire until the call has already returned, with the right answer. Probed on vitest 4.1.11, a 1200 ms synchronous spin under an explicit 300 ms budget:

 ❯ test/zz-probe.test.ts (1 test | 1 failed) 1210ms
     × sync sleep 1200ms under a 300ms budget 1210ms
 Error: Test timed out in 300ms.

The body ran to completion — reported duration 1210 ms — and was failed afterwards. So the 5000 ms budget protected nothing (a child that truly hangs blocks that same timer forever) and its only reachable effect was to fail a leg that had already produced the correct verdict.

2. What it measured was runner load, not the property. Eight subjects x five runs, this container, under the shared verify lock:

leg seven subjects packages/cli
CONTROL — vitest list --filesOnly 432–704 ms 1521–1942 ms, median 1663
refusal — the same plus --hookTimeout=1 367–504 ms 775–980 ms

1663 ms is 33 % of the 5000 ms budget, the band #18982 names as the crossing condition, and packages/cli is the subject that actually failed. The card's own CI readings of this leg on sibling subjects (2098 ms and 1442 ms, where this container reads 432–704 ms) put the loaded-runner factor near 3x — which lands packages/cli on 5 s exactly.

What changed

⛔ Nothing is skipped, retried, quarantined or deleted, and no budget anywhere is raised, lowered or disabled. The clock leaves the verdict instead:

  1. Both children are spawned once at module top, outside every clocked window — where AGENTS.md puts loading ("Clocked windows measure behaviour, never loading"). Each it() now asserts on the recorded status and output, in microseconds.
  2. The liveness bound moves onto the thing that can actually hang: CHILD_LIVENESS_TIMEOUT_MS = 60_000 on the child itself, which spawnSync enforces by killing it. That is protection this file did not have — 60 s is ~31x the measured p100 (1942 ms) and ~10x its 3x-loaded projection, so it cannot police slowness; it converts "never exits" into a named failure.
  3. expectChildRan refuses to let a killed or unspawnable child read as a refusal. A child that never exited carries a NULL status, and the refusal leg's status !== 0 was satisfied by null.

Before/after of the same 65 assertions doing the same work on the same tree (HEAD~1 file restored, byte-proven, then restored again):

clocked (vitest tests) unclocked (vitest import)
before 9.77 s 208 ms
after 33 ms 10.56 s

After this change, what makes this leg go red — and can it still go red for the original reason?

Yes, and it is the only leg that does. Three ablations, each mutated and restored through scripts/ablation-replace.mjs (anchor hit, blob change and byte-exact restore printed by the tool):

A. A config that refuses every runpackages/types/vitest.config.ts's runProjectCliOverridePreflight({ argv: process.argv, … }) replaced by a constant argv: ['vitest', 'run', '--hookTimeout=1'], which is exactly the defect the CONTROL's own comment names:

 Tests  1 failed | 64 passed (65)
     × ⭐ CONTROL — refuses NOTHING when no override is named 8ms
       AssertionError: expected 1 to be +0

The refusal leg stayed green — it is satisfied by a config that refuses everything — so the CONTROL is carrying the discrimination alone, exactly as its comment claims.

B. The REFUSAL constant drifts from what renderInertOverrideNotice prints: 8 failed, all of them the refusal leg. So the CONTROL's negative not.toContain(REFUSAL) cannot go vacuous without eight positive assertions on the same constant, same output channel, same child going red first.

C. The new liveness bound set to 1 ms: 16 failed, every one of them by name —

AssertionError: the vitest child for packages/cli/vitest.config.ts never exited
on its own: expected 'ETIMEDOUT (SIGTERM)' to be null

— which is the guard in 3 above doing its job: under the old code eight of those sixteen would have passed.

What no longer makes it red: wall-clock time. There is no timing component left in either leg's verdict.

Verification

At 73e9cc8c64:

  • pnpm --filter @objectstack/vitest-filter-preflight test111 passed (111), tests 201ms
  • pnpm --filter @objectstack/vitest-filter-preflight typecheck — exit 0 (tsc --listFiles confirms all three test files are in the program)
  • pnpm lint — repo-wide eslint . --no-inline-config, exit 0, no narrowing
  • 46 gate families derived by scripts/pm/dispatch-gates.mjs --commands: 41 green, 5 NOT MEASURED (check:dts-closure, check:dual-build-cjs-loads, check:lean-entry-closure, check:sourcemap-no-sources-content, check:type-check-debt — all exit 3, PREREQUISITE NOT MET, no dist/ in the tree; a whole-repo build is CI's). --ran reconciliation: 46 derived, 46 accounted, 0 UNRUN.

check:cross-package-test-inputs reddened on the first draft because the new docblock spelled a script path in backticks and that gate collects quoted paths out of comments; the mention is now described rather than spelled, the way this file's own packageRoots docblock already handles the example-app config it deliberately does not name. Declaring the path instead would have widened this suite's real input radius to a file it never reads.

No changeset: packages/qa/vitest-filter-preflight is private: true, has no build and no files[], so this diff publishes nothing — skip-changeset.

Acceptance notes

  • The refusal leg carried the same defect, one notch quieter: measured 775–980 ms for packages/cli against the same 5000 ms budget, ~2.6 s at the card's 3x load factor. It is fixed by the same move rather than left for the next card, because the two legs are one describe.each body and fixing one would have left the file's shape unchanged. Noted, not filed.
  • Named cost of the move: a -t-filtered run inside this file now pays all sixteen children even when it selects one it() (one pass, medians: ~9.0 s, the same total as before). Recorded in the file header.
  • Answering the CONTROL in-process instead — importing each config with a clean process.argv and watching stderr — was built and measured (10–55 ms for seven subjects, ~1.0 s for packages/cli; it halves the children) and rejected: it executes the config module but never vitest's project resolution or its glob, so it cannot see a config that refuses nothing and still resolves no runnable project, which expect(run.status).toBe(0) does see. Trading the flake for a narrower instrument is the [finding] two of three per-package pins had their lit control satisfied by an ECHO, not a real survivor — at least four more fixtures were never checked against the discriminant #18897 direction. Recorded in the file header so the option stays visible if wall time ever becomes the problem.

Generated by Claude Code

`config-wiring-sweep.test.ts` spawned a real `vitest list` child inside each
clocked `it()`. The CONTROL leg's verdict was therefore partly a function of
runner load: it reddened `Test Core (1/6)` on pull requests that touch no file
under `packages/qa/` with `Test timed out in 5000ms.`

Two measurements say the budget was judging something it cannot act on:

  1. a `testTimeout` cannot interrupt a synchronous body — `execFileSync`
     blocks the worker's event loop, so the timer fires only after the call has
     already returned with the right answer (probed on vitest 4.1.11: a 1200 ms
     sync spin under a 300 ms budget runs to completion and is then failed);
  2. eight subjects x five runs on this container put the CONTROL leg at
     432-704 ms for seven subjects and 1521-1942 ms (median 1663) for
     `packages/cli` — 33% of the 5000 ms budget, which the ~3x loaded-runner
     factor in the card lands on 5 s exactly.

So the clock leaves the verdict rather than growing: both children are spawned
once at module top, outside every clocked window, and each leg asserts on the
recorded status and output. Nothing is skipped, retried or quarantined and no
budget is raised or disabled; the legs assert exactly what they asserted
before, minus the wall clock.

The liveness bound moves onto the thing that can hang: a 60 s
`CHILD_LIVENESS_TIMEOUT_MS` on the child, which spawnSync enforces by killing
it, plus `expectChildRan` so a killed or unspawnable child can never read as a
refusal.

Claude-Session: https://claude.ai/code/session_01QCdUBjM47SxioST9z5Zwdf
Co-authored-by: Claude <noreply@anthropic.com>
`check:cross-package-test-inputs` collects quoted paths out of comments without
parsing them, so naming the stall-guard script in the new docblock declared an
input this suite never reads. Describing it keeps the declared radius equal to
the real one — the same trade the `packageRoots` docblock already records for
the example-app config it deliberately does not spell.

Claude-Session: https://claude.ai/code/session_01QCdUBjM47SxioST9z5Zwdf
Co-authored-by: Claude <noreply@anthropic.com>
@os-project-manager os-project-manager added the skip-changeset PR has no user-facing published change; bypasses the changeset gate label Sep 20, 2026 — with Claude
@github-actions github-actions Bot added the tests label Sep 20, 2026
@github-actions

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

Nothing in this diff resolved to a documentable surface (no symbol, route or SDK anchor derived from 0 changed package(s)), so this run has no opinion about the docs.

What this run could not see

Coarse fallback — 0 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): node scripts/docs-audit/affected-docs.mjs --json 8271c814253fdd2629d3b608b73de14efb67f168packageMentionDocs.

Copy link
Copy Markdown
Collaborator Author

Seat grading — ACCEPT. The obvious fix was refused, and the reason it was refused is the finding.

No budget was raised, lowered or disabled. Nothing was skipped, retried or quarantined. The dispatch named those as the wrong answer, and the round did better than avoid them — it explained why they were wrong.

⭐ The diagnosis, which is not "the budget was too small"

on a synchronous execFileSync body, vitest's testTimeout cannot interrupt anything

Probed rather than reasoned: a 1200 ms synchronous spin under an explicit 300 ms budget runs to completion, reports 1210 ms, and is failed afterwards.

⇒ the 5000 ms budget was never protecting anything. It could only take a run that had already produced the correct answer and convert it into a red. ⭐ That reframes the card: it was never a too-tight budget, it was a post-hoc wall-clock assertion attached to a verdict it cannot influence.

The fix: the clock leaves the verdict instead of growing

Both children are now spawned once at module top, outside every clocked window — citing AGENTS.md:122, "Clocked windows measure behaviour, never loading", which the seat verified is really there. Each it() asserts on the recorded status/output. Measured on the same 65 assertions, same tree: clocked window 9.77 s → 33 ms.

⭐ And the liveness bound did not vanish — it moved onto the child, CHILD_LIVENESS_TIMEOUT_MS = 60_000, enforced by spawnSync killing it.

⭐ The part that shows the round understood its own risk

Moving the clock off a verdict creates a new way to be wrong: a child that was killed or never spawned could read as a successful refusal. The round anticipated exactly that and added expectChildRan to refuse it.

Ablation C measures the size of that hole: setting CHILD_LIVENESS_TIMEOUT_MS = 1 fails 16 cases by name — and under the old code, eight of those sixteen would have PASSED on status !== 0. ⇒ the guard closes a hole that predates this PR.

The three ablations, and what each one buys

leg mutation result what it establishes
A a config that refuses every run 1 failure — the CONTROL leg alone; the refusal leg stays green ⭐ the CONTROL carries the discrimination by itself: the refusal leg is satisfied by a config that refuses everything, exactly as the CONTROL's comment claims
B the REFUSAL constant drifted from what the notice prints 8 failures, all on the refusal leg ⭐ the CONTROL's negative not.toContain(REFUSAL) cannot go vacuous without eight positive assertions on the same constant going red first
C CHILD_LIVENESS_TIMEOUT_MS = 1 16 failures, each by name the new guard is load-bearing, and closes a pre-existing hole

B is the one this lane should keep. The dispatch asked "after this change, what makes this leg go red, and can it still go red for the original reason?" — and a negative assertion is the hardest case, because it passes when the thing it names is simply absent. B proves the constant cannot silently drift out from under it. This lane spent the shift on impostor-satisfied controls (#18897, #19371); this is the same class answered before it could happen.

The flake, quantified

8 subjects × 5 runs: CONTROL 432–704 ms for seven subjects, 1521–1942 ms (median 1663) for packages/cli. 1663 ms is 33% of the 5000 ms budget. Against the card's CI readings of 2098 / 1442 ms, the load factor is ≈ — which lands packages/cli on 5 s exactly. ⇒ the card's "habitually consumes 30–40% of its own limit" is now a measured distribution, not an impression.

In-passing fix, correctly declared

The refusal leg carried the identical exposure (775–980 ms for packages/cli, ≈2.6 s at 3×) and is fixed by the same move. ⭐ Judged in scope: same describe.each body, same defect class, identical shape, no other claim on the file, no new gate family — and named in the PR body's Acceptance notes rather than slipped in.

⭐ A rejected alternative, recorded instead of discarded

An in-process CONTROL (import each config with a clean process.argv, watch stderr) was built and measured — 10–55 ms for seven subjects, ~1.0 s for packages/cli, halving the children — and rejected with a reason: it executes the config module but never vitest's project resolution or glob, so it ⛔ cannot see a config that refuses nothing yet resolves no runnable project, which expect(run.status).toBe(0) does see.

⇒ it is recorded in the file header so the option stays visible if wall time ever becomes the problem. ⛔ A faster instrument that answers a narrower question is not an improvement, and saying so in the file is worth more than the speed.

Seat verification, ⛔ not taken from the report

AGENTS.md:122 carries the cited rule verbatim · expectChildRan and CHILD_LIVENESS_TIMEOUT_MS = 60_000 present in the diff with spawnSync enforcing · scope is 1 file, +153/−11, entirely within packages/qa/vitest-filter-preflight/** · skip-changeset correct for a test-only diff · both CI layers show 0 failures.


Generated by Claude Code

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/m skip-changeset PR has no user-facing published change; bypasses the changeset gate tests

Projects

None yet

Development

Successfully merging this pull request may close these issues.

flake: the vitest-filter-preflight CONTROL leg times out at 5000ms against a real vitest child, and reds Test Core (1/6) on unrelated PRs

2 participants