Skip to content

Commit 95b21b3

Browse files
ci(rerun-safety): measure the rerun property even when pass 1 is red (#18746)
Fixes #18590 Clause-②: no `Rerun Safety` (workflow `323746634`) has been red on `main` and the card's finding was that it dies in `Test suite — pass 1`, so the rerun property it exists to measure has never been measured. The card marked two premises **NOT ESTABLISHED** and asked for them to be measured first. Both were. One of them is **refuted**, and that is what decided where the fix goes. ## Premise 1 — "do all ten failures share one cause?" — REFUTED The card read only the newest run's log. Reading the whole streak back through the workflow-scoped runs API and each job's check-run annotations: **The streak is 17 nights, not 10.** Last success was `33355711750`, 2026-08-31. And the failures do not share a cause — not the failing package, not even the failing *step*: | nights | dates | step that died | failing turbo task | kind | |---|---|---|---|---| | 4 | 09-14 .. 09-17 | pass 1 | `@objectstack/cli#test` | `Test timed out in 5000ms` | | 6 | 09-08 .. 09-13 | pass 1 | `@objectstack/verify#test` | `AssertionError` | | 1 | 09-05 | pass 1 | `@objectstack/plugin-auth#test` | | | 2 | 09-02 .. 09-03 | pass 1 | `@objectstack/cli#test` | | | 4 | 09-01, 09-04, 09-06, 09-07 | **pass 2** | `@objectstack/core#test`, `@objectstack/objectql#test` | | Two consequences the card could not see from one log: 1. **Four of the seventeen nights did reach pass 2.** Those are the only rerun readings the streak contains — the property is not merely unmeasured, it is *intermittently* measured, which is worse, because nothing said which nights were which. 2. **The pass-1 killer MOVED.** `verify`'s `harness.host-resolution.test.ts` was the killer for six nights and **is green on today's `main`** (verified locally: `Test Files 1 passed (11 tests)`). It was fixed, and `cli` inherited the job. So "get pass 1 green" is not a reachable end state on a trunk that goes red like any other trunk — it was reached, repeatedly, and the instrument went dark again each time. That is why the fix is not a fix to whichever test is red tonight. ## Premise 2 — "does that file time out outside this workflow?" — the control fired Run locally on an idle box holding the shared verify lock, `--project integration`: ``` ✓ NODE_ENV=development 3300ms ✓ NODE_ENV=test 2990ms ✓ NODE_ENV=production (the never-broken leg) 3073ms × CONTROL: neutralising the declaration 5710ms Test timed out in 5000ms ✓ CONTROL: neutralised under production 3039ms ``` Green outside the workflow — but **a different leg failed**, and it failed the same way. Re-run with the budget lifted (`--testTimeout=120000`), all five pass and the true costs are `3000 / 2526 / 2742 / 3599 / 2467` ms. ⭐ This **refines** the card's lead rather than confirming it. The card read "all three legs time out regardless of `NODE_ENV`" as the signature of the spawn harness. The sharper reading: **all FIVE legs cost 2.5–3.6s against a 5000ms budget nobody chose**, so which legs redden is decided by machine load. In the workflow the three non-neutralised legs died and both CONTROL legs lived; locally the reverse happened. Same file, same commit, disjoint casualties — the casualty list is a function of the runner, not of anything under test. (The card's own reasoning that this is not about `NODE_ENV` stands, and is strengthened: `NODE_ENV` does not correlate with the casualties in either run.) ## What this changes ### 1. The instrument — `pass 2` no longer depends on `pass 1` being green `.github/workflows/rerun-safety-nightly.yml`: pass 1 now **records** its exit code instead of ending the job with it, pass 2 runs `if: always()`, and a new verdict step owns the job's exit status. `scripts/rerun-safety-verdict.mjs` compares the two passes' failing task sets and reports, in one line, **whether the rerun property was MEASURED** and what it said: | pass 1 | pass 2 | verdict | measured | job | |---|---|---|---|---| | green | green | `RERUN_SAFE` | yes | pass | | green | red | `RERUN_UNSAFE` | yes | fail | | red | green | `BASELINE_FLAKY` | yes | fail | | red | red, same set | `BASELINE_BROKEN` — rerun property CLEAN | yes | fail | | red | red, pass 2 worse | `RERUN_UNSAFE_ON_BROKEN_BASELINE` | yes | fail | | stall (75) | any | `STALL` | **no** | fail | ⛔ **Nothing is weakened and nothing is skipped.** A red pass 1 still fails the job, exactly as the workflow header intends. What changed is that a broken trunk now costs the instrument its **baseline** instead of its **reading** — and a stall is the only remaining state that reports NOT MEASURED, which is the honest answer for a stall. The task-set parser reads three spellings because no one of them is sufficient: turbo's `Failed:` footer **under-reports** (measured on the 2026-09-08 run, it named `verify` alone while `plugin-auth`, `runtime` and `client` had each printed ELIFECYCLE in the same run), so the footer, the per-task `ERROR command` line and the streaming `ELIFECYCLE` prefix are unioned. ### 2. The proximate cause — the shadow budget on the named file `packages/cli/test/published-entry-node-env-source-reroute.test.ts` now states `CHILD_BUDGET_MS = 120_000` once and hands it to both its own `spawnSync` and each of its five legs. **⛔ This is not "raise the timeout until it passes", and the card is owed the argument:** **(a) Why it cannot mask a real rerun failure.** *It raises no bound.* The `spawnSync` in this file already declared 120s — chosen, and the same number the other spawning suites in `packages/cli/test/` pin (27 of 48 integration-tier files here carry an explicit per-test timeout; this one was in the minority that does not). The child is still killed at exactly 120s. What is removed is a **second, lower, unchosen bound** — vitest's 5000ms default — that was shadowing the chosen one, and that could never have bounded a `spawnSync` anyway, because a synchronous spawn blocks the worker's event loop and vitest cannot interrupt it. The 5000ms number never bounded anything; it only relabelled a completed slow spawn as a failure after the fact. **(b) The reading that still discriminates the two.** Previously a hung child and a slow child arrived as the *same* information-free line — `Error: Test timed out in 5000ms`, attributed to the `it()` and naming nothing about the child. They are now separated: `runPublishedEntry` raises a **named** error when the child was killed by its own bound (`error.code === 'ETIMEDOUT'` / `signal === 'SIGTERM'`), carrying the env, the neutralise flag and the elapsed ms, and saying in the message that this is a hung child rather than a slow one. A slow child stays a pass whose duration vitest prints, against the five measured costs recorded in the file's header. ### 3. The job backstop — a second latent way this instrument goes dark `timeout-minutes: 120` → `170`. The last four **green** two-pass runs took 74, 89, 103 and **115** minutes, so a healthy run was within five minutes of being killed by its own backstop — and this PR makes pass 2 run on the nights pass 1 is red, which is exactly when a 115-minute run is likely. ⛔ This is not a stall budget: `run-with-stall-guard` still declares a stall after 15 minutes of frozen output on either pass, so a genuine hang is still caught in 15 minutes and never at this number. ### 4. The self-test is wired at PR time, not in the nightly `check:pm-dispatch-gates` refuses a **SCHEDULED-ONLY** gate family: every discovered family must reach a workflow declaring a PR-time event. Invoking `--self-test` from `rerun-safety-nightly.yml` (schedule + `workflow_dispatch` only) made it this tree's first — the gate caught it, by name. It is wired as `pnpm check:rerun-safety-verdict` in `lint.yml` instead. ## Reverse verification (ablation) Through `scripts/ablation-replace.mjs`, so the mutation's landing and the restore's byte-identity are the tool's own verdict: ``` anchor "matchAll(ELIFECYCLE_RE)" x1 -> x0 blob 6275d79 -> 18fce43f6bda [mutation proven on disk] FAIL parse: streaming ELIFECYCLE prefix FAIL parse: union under-reporting footer (2026-09-08 shape) -- got @objectstack/verify#test rerun-safety-verdict --self-test: 2 FAILED [exit 1] blob after restore 6275d79 == blob at HEAD 6275d79, `git diff HEAD` empty ``` Direction as predicted (turns red), and the ablated union falls back to exactly the under-report the union exists to close. ## Verification Measured at `24f5253ca`. - `pnpm lint` **repo-wide** — `eslint . --no-inline-config`, full population, no narrowing: **exit 0**. - `node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack` derived **92** commands at this HEAD; all run, exit codes recorded and reconciled with `--ran`. - `node scripts/rerun-safety-verdict.mjs --self-test` — 15 batteries, 15 registered, exit 0. - `packages/cli` suite, plus `packages/verify`'s `harness.host-resolution.test.ts` as the premise-1 control. **NOT MEASURED, declared:** - ⛔ **This workflow runs only on `main`, so no PR can make it red or green.** The change is proven by local reproduction and by the ablation above; it is **not verified by the instrument itself** and must not be read as if it were. The first real reading arrives on the first nightly after this lands. - `pnpm check:dual-build-cjs-loads` — **exit 3, PREREQUISITE NOT MET**: it reads built output and this tree has no full `pnpm build`. Not a pass and not a red. This diff adds no published bytes, so it cannot move that gate. ## Cross-face declaration The claim comment warned that touching **vitest tiering configuration** would be a repo-wide shared predicate and therefore a cross-face effect. ⛔ **It is not touched.** `packages/cli/vitest-tiers.ts` and `packages/cli/vitest.config.ts` are both unmodified. The edited test file keeps both signals that place it (`node:child_process` + the `run.js` entry basename), so it stays in the `integration` tier and no file moves between tiers. ## Changeset `skip-changeset`, **measured rather than assumed**: `@objectstack/cli` ships `["dist", "README.md", "CHANGELOG.md"]` — `test/` is not published; the root package is `private`, so `scripts/` and `.github/` are not published either. Grep of the built `packages/cli/dist` for the symbols this PR introduces (`CHILD_BUDGET_MS`, `killedByOwnBound`, `rerun-safety-verdict`) returns **zero hits**, with a positive control (`enableAutoTranspile`) hitting three files in the same grep. No published bytes move. ## Acceptance notes Noted, not filed — none of these is in this card's scope, and each is recorded here rather than acted on: - The four pass-2 deaths in the streak (`@objectstack/core#test` ×3, `@objectstack/objectql#test` ×1, on 09-01/04/06/07) are **real rerun-safety readings** that were taken and never acted on. Triage ruled explicitly that the rerun-unsafe tests are not this card's business while the instrument is mute. With the instrument repaired they will re-report themselves on the next nightly, attributed, which is the right time to pick them up. Carrier: the first nightly run after this lands. - `packages/cli/test/published-entry-stderr-error-listener.test.ts` is the other spawning file in this directory with no explicit per-test timeout, so it is the next candidate to redden the same way under load. Not measured here, and not changed — naming it so the next occurrence is recognised rather than rediscovered. Carrier: whoever picks up the next `cli#test` nightly red. --- _Generated by [Claude Code](https://claude.ai/code/session_01DvvamiacK328idtBYJBxV3)_ --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent f1c9bb3 commit 95b21b3

5 files changed

Lines changed: 721 additions & 34 deletions

File tree

‎.github/workflows/lint.yml‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4938,6 +4938,26 @@ jobs:
49384938
- name: Stall-guard budget invariant
49394939
run: pnpm check:stall-guard-budget
49404940

4941+
# The `Rerun Safety` verdict table (#18590) — self-test half only, and the
4942+
# asymmetry is the same one the step below explains: the measurement half
4943+
# takes two log paths and two exit codes that exist only inside that
4944+
# nightly job, so there is nothing here for a bare invocation to read.
4945+
#
4946+
# ⭐ It is wired HERE rather than left in the nightly deliberately.
4947+
# `rerun-safety-nightly.yml` declares `schedule` and `workflow_dispatch`
4948+
# and no PR-time event, so a gate family reachable only from it would be
4949+
# this tree's first SCHEDULED-ONLY family — which `check:pm-dispatch-gates`
4950+
# refuses by name, on the ground that a board sweep must not be routed into
4951+
# a per-PR gate list.
4952+
#
4953+
# WHAT REDDENS IT: its own script's parsing rules and verdict table. Those
4954+
# are matching rules, so their production verdict is identical before and
4955+
# after they break (see `check-self-test-wired.mjs`) — this step is the
4956+
# only instrument watching them. Reads nothing but its own fixtures; no
4957+
# build, no network, no token, sub-second.
4958+
- name: Rerun-safety verdict table self-test
4959+
run: pnpm check:rerun-safety-verdict
4960+
49414961
# The third member of the stall-guard family, and the only one that was
49424962
# never wired (#13246). `measure-stall-guard-headroom.mjs` re-derives the
49434963
# one term the budget gate above cannot read statically -- `p + s`, the

‎.github/workflows/rerun-safety-nightly.yml‎

Lines changed: 109 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,27 @@
2020
# to fail loudly like any other; what this gate is really asserting is that the
2121
# SECOND pass agrees with the first.
2222
#
23+
# ## Why pass 1 no longer ends the job (#18590)
24+
#
25+
# That last sentence was true of the design and false of the implementation. A
26+
# red `pass 1` ENDED THE JOB, which skipped `pass 2` — so on every night the
27+
# suite was red on main, the one thing this workflow exists to assert was not
28+
# asserted. The job went red anyway, and its red is indistinguishable from the
29+
# red it exists to report.
30+
#
31+
# It ran that way for a 17-night streak ending 2026-08-31: thirteen of those
32+
# nights died in pass 1, under FOUR different failing packages and two different
33+
# failure kinds, with the killer moving from `verify` to `cli` as each was
34+
# fixed. Only four of the seventeen nights ever reached pass 2. "Keep pass 1
35+
# green" is not a reachable end state on a trunk that goes red like any other,
36+
# so the measurement is no longer conditional on it: both passes always run,
37+
# and `scripts/rerun-safety-verdict.mjs` compares their failing task sets and
38+
# says, in one line, whether the rerun property was MEASURED and what it said.
39+
#
40+
# ⛔ Nothing here is weakened. A red pass 1 still fails this job. What changed
41+
# is only that a broken trunk now costs the instrument its BASELINE instead of
42+
# its READING.
43+
#
2344
# ## Why `--force`
2445
#
2546
# Turbo would replay cached results on the second pass and report green without
@@ -44,7 +65,19 @@ jobs:
4465
# while the PR read as "still running" rather than broken. Since #4314 the
4566
# primary stall detector is run-with-stall-guard on each pass (labeled red
4667
# after 15 min of frozen output); this is the pure backstop.
47-
timeout-minutes: 120
68+
#
69+
# ⚠️ Raised 120 -> 170 (#18590). 120 had stopped being a backstop and become
70+
# a second way for this instrument to go dark: the last four GREEN two-pass
71+
# runs on main took 74, 89, 103 and **115** minutes, so a healthy run was
72+
# within five minutes of being killed by its own bound — and #18590 makes
73+
# pass 2 run on the nights pass 1 is red too, which is exactly when a
74+
# 115-minute run is most likely. ⛔ This is NOT a stall budget and must never
75+
# be read as one: run-with-stall-guard still declares a stall after 15
76+
# minutes of frozen output on EITHER pass, so a genuine hang is still caught
77+
# in 15 minutes and never at this number. Raising it can therefore hide no
78+
# hang; all it stops is a slow-but-live run being reported as a failure of
79+
# the thing under test.
80+
timeout-minutes: 170
4881
steps:
4982
- name: Checkout repository
5083
uses: actions/checkout@v7
@@ -77,13 +110,35 @@ jobs:
77110
- name: Build packages
78111
run: pnpm build
79112

80-
# Deliberately NOT `continue-on-error`. If pass 1 is red the suite is
81-
# simply broken on main and that is worth failing on; this gate adds pass
82-
# 2, it does not replace the ordinary signal. The stall guard (#4250,
83-
# #4314) bounds a frozen-output hang at 15 min instead of letting a
84-
# nightly nobody watches sit until the 120-min timeout; on a stall it
85-
# exits 75 and its banner in the log names the last output line.
86-
# --log-order=stream is mandatory under the guard (see the Test Core
113+
# ⭐ Pass 1 RECORDS its exit code instead of ending the job with it
114+
# (#18590), and that change is what makes this workflow an instrument
115+
# again rather than a light that has been on for seventeen nights.
116+
#
117+
# It used to be spelled "deliberately NOT `continue-on-error`", on the
118+
# reasoning that a red pass 1 means the suite is broken on main and that
119+
# is worth failing on. The reasoning still holds and the job still fails
120+
# — see the verdict step, which owns the exit status now. What did NOT
121+
# hold is the consequence nobody wrote down: a step that ends the job also
122+
# skips `pass 2`, so on every night pass 1 was red the ONE measurement
123+
# this workflow exists to take was not taken at all. The job went red
124+
# either way, and that red is indistinguishable from the red it exists to
125+
# report — "rerun safety is failing" and "rerun safety was never measured"
126+
# printed the same colour.
127+
#
128+
# Measured over the 17-night red streak that ended 2026-08-31 (#18590):
129+
# thirteen nights died here in pass 1, and the killer MOVED — six nights
130+
# `@objectstack/verify#test` (an AssertionError, since fixed on main),
131+
# then four nights `@objectstack/cli#test` (5000ms vitest timeouts), with
132+
# `plugin-auth` and earlier `cli` nights in between. The remaining four
133+
# nights reached pass 2 and are the only rerun readings the streak
134+
# contains. So "keep pass 1 green" was never a reachable end state on a
135+
# trunk that is red from time to time like any other — and every night it
136+
# was not reached cost the reading.
137+
#
138+
# The stall guard (#4250, #4314) is unchanged: it bounds a frozen-output
139+
# hang at 15 min instead of letting a nightly nobody watches sit to the
140+
# job timeout; on a stall it exits 75 and its banner names the last output
141+
# line. --log-order=stream is mandatory under the guard (see the Test Core
87142
# comment in ci.yml): grouped log order flushes a task's output only when
88143
# the task ends, so a solo tail task longer than the budget reads as
89144
# frozen while healthy. The guard refuses a turbo run without it.
@@ -96,8 +151,16 @@ jobs:
96151
# vitest's own "use the default" signal. Needs turbo.json's
97152
# globalPassThroughEnv entry or turbo strips it — see the script header.
98153
export VITEST_MAX_WORKERS="$(node scripts/vitest-worker-cap.mjs)"
154+
status=0
99155
node scripts/run-with-stall-guard.mjs --log "$RUNNER_TEMP/rerun-pass1.log" --stall-minutes 15 -- \
100-
pnpm turbo run test --concurrency=4 --force --log-order=stream
156+
pnpm turbo run test --concurrency=4 --force --log-order=stream || status=$?
157+
echo "PASS1_EXIT=$status" >> "$GITHUB_ENV"
158+
if [ "$status" -ne 0 ]; then
159+
echo "::warning::Pass 1 exited $status — the suite is red on main. Recorded as the"
160+
echo "::warning::BASELINE and NOT failed here: pass 2 runs anyway so the rerun"
161+
echo "::warning::property still gets measured tonight. The verdict step owns the"
162+
echo "::warning::job's exit status and will still fail this job."
163+
fi
101164
102165
# Informational only. A stray `.objectstack/` is how the #4065 class shows
103166
# up on disk, so printing what pass 1 left behind turns a pass-2 failure
@@ -113,11 +176,19 @@ jobs:
113176
echo "Files inside them:"
114177
find . -path ./node_modules -prune -o -type d -name '.objectstack' -exec find {} -type f \; || true
115178
116-
# A pass-2 red normally means rerun-UNSAFE — but a stall (guard exit 75)
117-
# says nothing about working-tree pollution, and the #4065 error text
118-
# would send whoever triages it hunting for state leaks that aren't
119-
# there. Keep the two verdicts apart.
179+
# ⭐ `if: always()` is the other half of #18590 — pass 2 is the assertion,
180+
# so it runs whatever pass 1 did. A red pass 1 now costs this instrument
181+
# its BASELINE, not its reading.
182+
#
183+
# This step no longer renders the verdict either. It cannot: with a red
184+
# baseline allowed, "pass 2 failed" is no longer the same fact as
185+
# "rerun-unsafe" — a task that was already failing in pass 1 and fails
186+
# again in pass 2 is ordinary breakage on main, and printing the #4065
187+
# text over it would send whoever triages it hunting for state leaks that
188+
# are not there. That comparison needs both passes' failing task sets, so
189+
# it belongs one step down, in the verdict.
120190
- name: Test suite — pass 2 (same working tree)
191+
if: always()
121192
run: |
122193
# Bound vitest's INNER worker pool (#11958). A no-op on a runner with
123194
# <= 5 cores (it only ever LOWERS vitest's own `cores - 1` default);
@@ -129,18 +200,28 @@ jobs:
129200
status=0
130201
node scripts/run-with-stall-guard.mjs --log "$RUNNER_TEMP/rerun-pass2.log" --stall-minutes 15 -- \
131202
pnpm turbo run test --concurrency=4 --force --log-order=stream || status=$?
132-
if [ "$status" -eq 0 ]; then
133-
exit 0
134-
elif [ "$status" -eq 75 ]; then
135-
echo "::error::Pass 2 STALLED — frozen output, killed by run-with-stall-guard"
136-
echo "::error::(see #4250). This is NOT a rerun-safety verdict: a stall says"
137-
echo "::error::nothing about working-tree pollution. Rerun the workflow; if it"
138-
echo "::error::stalls again at the same file, note the occurrence on #4250."
139-
else
140-
echo "::error::The suite passes once and fails on a second run in the same"
141-
echo "::error::working tree. Something under test writes state into the tree and"
142-
echo "::error::reads it back on the next run. Ordinary CI cannot see this — every"
143-
echo "::error::other job is a fresh clone, so every other job is always run #1."
144-
echo "::error::See the on-disk state reported above, and #4065 for the pattern."
145-
fi
146-
exit "$status"
203+
echo "PASS2_EXIT=$status" >> "$GITHUB_ENV"
204+
205+
# ⭐ THE VERDICT, and the job's exit status (#18590).
206+
#
207+
# It answers the question the exit code alone has never been able to
208+
# express — was the rerun property MEASURED tonight — and only then what
209+
# it measured. `scripts/rerun-safety-verdict.mjs` carries the table and a
210+
# `--self-test`; its header is the authority on detail.
211+
#
212+
# ⛔ This step does not make the job green. A red pass 1 still fails it,
213+
# exactly as before; what is new is that the failure now SAYS which of
214+
# "broken on main" and "rerun-unsafe" it is, and a broken-on-main night no
215+
# longer swallows the reading.
216+
# ⛔ The self-test is NOT invoked here. It runs at PR time as
217+
# `pnpm check:rerun-safety-verdict` in lint.yml, because this workflow
218+
# declares only `schedule` and `workflow_dispatch`: a gate family reachable
219+
# from here alone would be the tree's first SCHEDULED-ONLY family, which
220+
# `check:pm-dispatch-gates` refuses by name. That step's comment carries
221+
# the reasoning.
222+
- name: Rerun-safety verdict
223+
if: always()
224+
run: |
225+
node scripts/rerun-safety-verdict.mjs \
226+
--pass1-log "$RUNNER_TEMP/rerun-pass1.log" --pass1-exit "${PASS1_EXIT:-1}" \
227+
--pass2-log "$RUNNER_TEMP/rerun-pass2.log" --pass2-exit "${PASS2_EXIT:-1}"

‎package.json‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -158,6 +158,7 @@
158158
"check:select-gate-families": "bash scripts/ci/select-gate-families.selftest.sh",
159159
"check:shard-attestation": "node scripts/check-shard-attestation.mjs --self-test && node scripts/check-shard-attestation.mjs",
160160
"check:required-contexts": "node scripts/check-required-contexts.mjs --self-test && node scripts/check-required-contexts.mjs",
161+
"check:rerun-safety-verdict": "node scripts/rerun-safety-verdict.mjs --self-test",
161162
"check:cross-package-test-inputs": "node scripts/check-cross-package-test-inputs.mjs --self-test && node scripts/check-cross-package-test-inputs.mjs",
162163
"check:live-db-isolation": "node scripts/check-live-db-isolation.mjs --self-test && node scripts/check-live-db-isolation.mjs",
163164
"check:tier-file-adoption": "node scripts/check-tier-file-adoption.mjs --self-test && node scripts/check-tier-file-adoption.mjs",

‎packages/cli/test/published-entry-node-env-source-reroute.test.ts‎

Lines changed: 80 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -88,6 +88,49 @@ const PUBLISHED_ENTRY = resolve(HERE, '../bin/run.js');
8888
/** The control preload. See its own header for why it is an accessor pair. */
8989
const NEUTRALISER = resolve(HERE, 'fixtures/published-entry-auto-transpile-neutraliser.mjs');
9090

91+
/**
92+
* The ONE bound on a leg of this file, and the reason it is stated once (#18590).
93+
*
94+
* ## The defect this closes
95+
*
96+
* Every leg here boots a real, cold Node process running the published oclif
97+
* entry and waits for it synchronously. Measured on an idle box, lock held,
98+
* with the budget lifted so the numbers are costs and not verdicts:
99+
*
100+
* NODE_ENV=development 3000ms
101+
* NODE_ENV=test 2526ms
102+
* NODE_ENV=production 2742ms
103+
* CONTROL neutralised (dev) 3599ms
104+
* CONTROL neutralised (prod) 2467ms
105+
*
106+
* The `spawnSync` below already declares this file's real bound — 120s, chosen,
107+
* and the same number the other spawning suites in this directory pin. But no
108+
* leg named a vitest budget, so every one of them was ALSO measured against
109+
* vitest's 5000ms DEFAULT, which nobody here chose. Against costs of 2.5-3.6s
110+
* that is a margin thinner than the run-to-run variance on an idle machine, so
111+
* WHICH leg reddens is decided by how busy the box is and by nothing this file
112+
* tests. Both halves of that were measured: in `Rerun Safety` (the workflow
113+
* that deliberately runs the whole suite twice on one runner) the three
114+
* non-neutralised legs timed out while both CONTROL legs passed; locally, on a
115+
* quiet box, the opposite happened — the neutralised CONTROL leg took 5710ms
116+
* and was the only one to fail. Same file, same commit, disjoint casualties.
117+
*
118+
* ## ⛔ Why this is not "raise the timeout until it passes"
119+
*
120+
* That move hides a real failure, and this one cannot, because it raises no
121+
* bound at all. The child is still killed by `spawnSync` at exactly the same
122+
* 120s it was before; what is removed is a SECOND, lower, unchosen bound that
123+
* was shadowing the chosen one. A leg that genuinely hangs still dies at 120s —
124+
* and now says so, see `runPublishedEntry`. Nor can a slow leg pass silently:
125+
* vitest prints each leg's duration, and the numbers above are the record to
126+
* compare against.
127+
*
128+
* ⛔ And it must not be tuned DOWN to "catch a slowdown". The 5000ms budget
129+
* proved exactly what a too-tight budget proves: nothing about the code, and a
130+
* red whose casualty list is a function of the runner's load.
131+
*/
132+
const CHILD_BUDGET_MS = 120_000;
133+
91134
/**
92135
* The card's verbatim signature. Asserted as text rather than as an exit code
93136
* alone because an exit code says only THAT the run failed — this says the run
@@ -136,21 +179,52 @@ afterAll(() => {
136179
* sets to pin tsx away from the CWD's tsconfig, and a developer running the
137180
* suite under that shim would otherwise inherit the very mitigation this file
138181
* is measuring the absence of.
182+
*
183+
* ## The reading that tells a HUNG child from a SLOW one (#18590)
184+
*
185+
* Under the 5000ms default both arrived as the same line — `Error: Test timed
186+
* out in 5000ms`, attributed to the `it()` and naming nothing about the child,
187+
* its environment or how long it actually ran. That is why ten nights of this
188+
* file's red could be read as anything at all.
189+
*
190+
* `spawnSync` distinguishes them and always did: a child killed by its own
191+
* `timeout` comes back with `error.code === 'ETIMEDOUT'` and `signal ===
192+
* 'SIGTERM'`, where a slow-but-correct child comes back with a status. So the
193+
* hung case is now raised BY NAME, with the env and the elapsed time in the
194+
* message, and the slow case stays a pass whose duration vitest prints. ⛔ Do
195+
* not fold this back into a bare timeout: the two outcomes needing to be told
196+
* apart is the whole reason this file went unread for seventeen nights.
139197
*/
140198
function runPublishedEntry(
141199
env: Record<string, string | undefined>,
142200
options: { neutralise?: boolean } = {},
143201
) {
202+
const startedAt = Date.now();
144203
const result = spawnSync(
145204
process.execPath,
146205
[...(options.neutralise ? [`--import=${NEUTRALISER}`] : []), PUBLISHED_ENTRY, '--version'],
147206
{
148207
cwd: fixtureCwd,
149208
encoding: 'utf8',
150-
timeout: 120_000,
209+
timeout: CHILD_BUDGET_MS,
151210
env: childEnv({ TSX_TSCONFIG_PATH: undefined, ...env }),
152211
},
153212
);
213+
const elapsedMs = Date.now() - startedAt;
214+
215+
const killedByOwnBound =
216+
(result.error as NodeJS.ErrnoException | undefined)?.code === 'ETIMEDOUT' ||
217+
result.signal === 'SIGTERM';
218+
if (killedByOwnBound) {
219+
throw new Error(
220+
`The published entry did not exit within its own ${CHILD_BUDGET_MS}ms bound and was killed ` +
221+
`(signal=${result.signal ?? 'none'}, code=${(result.error as NodeJS.ErrnoException | undefined)?.code ?? 'none'}, ` +
222+
`elapsed=${elapsedMs}ms, neutralised=${options.neutralise === true}, env=${JSON.stringify(env)}). ` +
223+
'This is a HUNG child, not a slow one — a slow child passes and vitest prints its duration. ' +
224+
'Do not respond by raising a budget: read what the entry is waiting on.',
225+
);
226+
}
227+
154228
return { status: result.status, output: `${result.stdout ?? ''}${result.stderr ?? ''}` };
155229
}
156230

@@ -160,20 +234,20 @@ describe('#12271 - the published entry does not reroute to src/ on an ambient NO
160234
expect(output).not.toContain(CARD_SIGNATURE);
161235
expect(output).not.toContain(SOURCE_COMMANDS);
162236
expect(status).toBe(0);
163-
});
237+
}, CHILD_BUDGET_MS);
164238

165239
it('resolves commands from dist/ under an ambient NODE_ENV=test', () => {
166240
const { status, output } = runPublishedEntry({ NODE_ENV: 'test' });
167241
expect(output).not.toContain(CARD_SIGNATURE);
168242
expect(output).not.toContain(SOURCE_COMMANDS);
169243
expect(status).toBe(0);
170-
});
244+
}, CHILD_BUDGET_MS);
171245

172246
it('NODE_ENV=production stays green, the leg that was never broken', () => {
173247
const { status, output } = runPublishedEntry({ NODE_ENV: 'production' });
174248
expect(output).not.toContain(CARD_SIGNATURE);
175249
expect(status).toBe(0);
176-
});
250+
}, CHILD_BUDGET_MS);
177251

178252
/**
179253
* THE CONTROL. If this ever goes green the three assertions above have
@@ -185,7 +259,7 @@ describe('#12271 - the published entry does not reroute to src/ on an ambient NO
185259
expect(output).toContain(CARD_SIGNATURE);
186260
expect(output).toContain(SOURCE_COMMANDS);
187261
expect(status).not.toBe(0);
188-
});
262+
}, CHILD_BUDGET_MS);
189263

190264
/**
191265
* The second half of the control: with the declaration neutralised, the only
@@ -197,5 +271,5 @@ describe('#12271 - the published entry does not reroute to src/ on an ambient NO
197271
const { status, output } = runPublishedEntry({ NODE_ENV: 'production' }, { neutralise: true });
198272
expect(output).not.toContain(CARD_SIGNATURE);
199273
expect(status).toBe(0);
200-
});
274+
}, CHILD_BUDGET_MS);
201275
});

0 commit comments

Comments
 (0)