Skip to content

Commit 601b258

Browse files
test(cli): size each case of the hook-timeout refusal pin to a measured vitest list child, past vitest's 5000 ms default (#25026)
Fixes #24927 Clause-②: no ## What changes One test file: `packages/cli/test/hook-timeout-override-refusal.test.ts` (the pin for #18788). - A named constant, `VITEST_LIST_BUDGET_MS = 27_000`, with the readings that size it written beside it. - All four cases pass it as their per-test timeout. Each case blocks on exactly one `vitest list --filesOnly` child of the package, so a case's wall time is that child's wall time. - The constant is 3x the slowest measured child (8685 ms), rounded up to the next second. This is the rule from plugin-sharing's scrypt budgets (`b9222dc70`). What stays the same: - Every case asserts exactly what it asserted before. Both controls still run a plain, unfiltered `vitest list` of the whole package. - `runVitestList()`, the vitest config and the refusal code are unchanged. No other test file changes. - Nothing is skipped, retried, quarantined or narrowed. ## Measured All local readings come from a 4-vCPU container shared with sibling agents. Every run took the verify lock. The case durations come from vitest's JSON reporter. The "file" figure is the file's start-to-end time in the same report. "Alongside" means this package's own Test Core slice ran at the same time, under the shard's flags. The flags are `OS_TEST_SHARD=1/3`, which is the slice that holds this file, plus `OS_TEST_TIERS=queue` and `VITEST_MAX_WORKERS=3` from `scripts/vitest-worker-cap.mjs`. The file's own runs used the same environment without the shard flag, because vitest refuses a shard count larger than a one-file population. "Heavy" is alongside, plus the file's runs pinned to CPU 3 (`taskset`), where they share the CPU with two busy loops. | reading | runs | refusal cases, ms | control cases, ms | file, s | failed cases | |:--|--:|:--|:--|:--|--:| | CI, merge group run `39444329582`, job `Test Core (2/6)` | 1 | 2606, 3355 | 7335, 7897 | 21.2 | 2 of 4 | | idle, before (`86d236071`) | 6 | 804 to 1244 | 1928 to 2350 | 5.9 to 6.5 | 0 of 24 | | idle, after (`7ce12e63a`) | 6 | 890 to 1193 | 1987 to 2307 | 6.2 to 6.7 | 0 of 24 | | alongside, before | 6 | 1019 to 1789 | 2560 to 3952 | 7.5 to 10.1 | 0 of 24 | | alongside, after | 6 | 1154 to 1985 | 2814 to 3501 | 9.0 to 9.6 | 0 of 24 | | alongside and pinned to CPU 3, no busy loops, before | 6 | 1106 to 1934 | 2794 to 3381 | 8.6 to 9.2 | 0 of 24 | | **heavy, before** (two sets of runs, the base tree) | 6 + 5 | 2742 to 4668 | 6982 to 8281 | 21.2 to 24.4 | **22 of 44** | | heavy, after, budget 25000 (`5d37bdbf9`) | 6 | 2821 to **5134** | 7136 to **8685** | 21.2 to 24.3 | 0 of 24 | | **heavy, after, budget 27000** (`7ce12e63a`, the head) | 5 | 2846 to 5012 | 7432 to 8676 | 22.2 to 24.8 | **0 of 20** | How to read these runs: - **The heavy load reproduces the card's red.** The CI file read 21.2 s, and the heavy runs read 21.2 to 24.4 s. In all 11 heavy runs at the default, both controls failed, and only the controls. The default reporter printed `Error: Test timed out in 5000ms.` 10 times over the 5 runs that kept its text. The other 6 runs kept only the JSON report, where both controls are `failed` at 6982 to 8160 ms. - **The budget turns the same load green.** The 11 heavy runs taken after the change passed all of their cases. - **A refusal case goes past the default under the same load.** The `--hookTimeout` refusal read 5134 ms in one run and 5012 ms in another. At the default, both runs would have timed out. This is why the budget covers all four cases, not only the two controls. - **No contention lighter than "heavy" went red.** Alongside, the slowest control read 3952 ms. The same held in place: one full slice run (`OS_TEST_SHARD=1/3`, both projects, 161 files, 674 s) read the controls at 2920 and 2395 ms. The file started 629 s into that run, near its end, when most of the slice had finished. - After the six runs with the budget at 25000 (`5d37bdbf9`), the slowest control read 8685 ms. That is above the 8160 ms the 25000 was sized on, so the head re-sizes the budget to 27000. The children alone, timed outside vitest at idle with 6 runs each and the exact argv and env the cases use: - no flag: 2139 to 2380 ms; - `--testTimeout=1`: 1993 to 2350 ms; - `--hookTimeout=1`: 854 to 994 ms; - `--teardownTimeout=1`: 846 to 1031 ms. ## Mechanism assumptions, checked 1. *"The two controls each spawn a full `vitest list` of the package; the refusals exit at config load and stay fast."* **Partly confirmed.** - A control child lists the whole package: 481 test files across both projects. With `--filesOnly`, it globs and does not import any test module. So the card's "collects the whole package" overstates the work. The cost is starting vitest, resolving both projects and globbing: about 2.2 s idle, against about 0.9 s for a refusing child. - The refusals do exit at config load. They do **not** stay fast under contention: 5134 ms is the slowest reading. 2. *"The budget belongs on the two controls, not the whole file; a child timeout in `runVitestList()` might fire first."* **The first half is falsified. There is no child timeout.** - `execFileSync` is called with no `timeout` option, and its default is none. - The case body is synchronous, so vitest cannot interrupt it. `withTimeout` in `@vitest/runner` 4.1.11 checks the elapsed time when the body returns. That is why the card's reds read 7335 and 7897 ms rather than 5000: each red is the child's full wall time, judged after the child finished. - The budget goes on all four cases (see the refusal readings above). 3. *"The contended maximum with a margin is under any CI job-level budget and inside the test-budget rules."* **Holds.** - The most the four budgets allow the file is 4 x 27 s = 108 s. The `Test Core` job's wall is 50 minutes, and its stall guard fires after 10 minutes without output. - A per-case timeout is not read by the test-budget ledger. The 10 s line in `scripts/measure-test-shard-timings.mjs` (`FILE_BUDGET_SECONDS`) grades a file's measured wall time in the hourly window, and this change does not move that wall time. See the acceptance notes. ## Why this route - **Removing the cost, as PR #24704 did, is not available here.** That file's cost was repeated scrypt work that a memo could replay. Here the cost is the subject: each control is one real config load of the whole package, and the two flags ask different questions. - Making a control cheaper means narrowing what it lists, with `--project` or a file filter. That changes the question from "a run of this package" to "a run of part of it", and the card forbids a weakened control. - Merging the two controls into one spawn is not possible either, because they pass different flags. - **One constant, not one per case kind.** Every case runs the same instrument once. A refusing child does a strict prefix of a control child's work, which is the config load. So the control's reading bounds every case, and a second constant would add a number without catching anything new. ## Tests and gates All at `7ce12e63a` (`git rev-parse --short HEAD`), the PR head, unless a row names another commit. - `pnpm --filter '@objectstack/cli^...' build` under the verify lock: `VERDICT command-exit 0`. `pnpm --filter @objectstack/cli build`: `VERDICT command-exit 0`. The package was built because the slice's integration files spawn `dist`, as CI's slice leg does. - `pnpm --filter @objectstack/cli exec vitest run --project unit` (the whole unit layer, 315 files) under the lock: `Test Files 315 passed (315)`, `Tests 4650 passed (4650)`, `VERDICT command-exit 0`. This file read 3001 and 2518 ms for its controls there. - `pnpm --filter @objectstack/cli typecheck` under the lock: `VERDICT command-exit 0`, including `check:test-typecheck: OK`. The file is in `tsconfig.test.json`'s program: `tsc --listFilesOnly` counts it once, and it has no entry in `test-typecheck-debt.json`. - The `integration` layer was not run locally on its own. This diff does not touch it, and CI's `pnpm test` runs both layers. The heavy and alongside runs above ran the slice's integration files beside the file. - `node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack` derived 53 commands at `7ce12e63a`. Each was run with its exit code captured before any pipe. - 52 exited 0. - 1 exited 3 (`PREREQUISITE NOT MET`), so it is NOT MEASURED here: `pnpm check:dual-build-cjs-loads` needs every workspace package's `dist`. CI runs it. - `--ran` reconciliation: `✓ dispatch-gates --ran: 53 derived famil(ies) accounted for — 52 run, 1 NOT-MEASURED (1 DERIVED from a recorded exit 3).` - The 11 families listed under "Declared WIDE population" were run as well, and all 11 exited 0: `check:init-service-contract`, `check:live-db-isolation`, `check:meta-type-normalized`, `check:optional-error-sink`, `check:resume-authority-declared`, `check:route-envelope`, `check:runner-env-posture`, `check:settings-bind-window`, `check:startup-registry-verdict`, `check:verify-stand-in` and `check:wildcard-fallthrough`. - `pnpm lint` (eslint over the repo, `--no-inline-config`): exit 0, no findings. - No ablation. No tested behaviour changes, only a time budget. The red-then-green readings above are the evidence that the budget is what the controls needed. - Base is `86d236071`, not merged forward. Of the 11 commits that reached `main` since, one touches `packages/cli`: `62bc129308` adds one test file and edits `src/commands/migrate/apply.ts`. That adds one file to what a control child lists, and touches nothing this file, the vitest config or the refusal reads. `git merge-tree` against `origin/main` is clean. ## No changeset (`skip-changeset`) Only a `*.test.ts` file under `packages/cli/test/` changes. `@objectstack/cli`'s `files[]` is `dist`, `README.md` and `CHANGELOG.md`, and `tsconfig.build.json` builds `src` only. `pnpm --filter @objectstack/cli build` at `7ce12e63a` (`VERDICT command-exit 0`), then a search of everything `files[]` ships: - `VITEST_LIST_BUDGET_MS` appears in 0 files under `dist`, `README.md` and `CHANGELOG.md`; - the test file's name appears in 0 files under `dist`; - control: `ValidateCommand` appears in 2 files under `dist`. ## Acceptance notes - **The file is over the 10 s line under contention, before and after this change.** It read 21.2 s in the card's merge-group run and 21.2 to 24.8 s under the heavy load, against 5.9 to 6.7 s idle. The hourly window that grades the line has not listed it: it is absent from #23181's table for this lane, which lists files down to 10.2 s. - No `// test-budget:` header is declared here, because nothing lists the file today. - If the window ever does list it, the class that describes it is `spawns the real producer once per single-cause fixture`. Each case spawns the real config load once, for one flag. - **The per-test budget is judged after the fact.** It cannot stop a child that hangs: nothing in this file bounds one, before or after this change, and the job's stall guard is what catches a hang. A `timeout` on `execFileSync` would bound it. That is not added here, because it would change `runVitestList()`'s failure shape (a killed child reports a `null` status, which the helper's own assertion rejects), and the card asks for a budget only. --- _Generated by [Claude Code](https://claude.ai/code/session_01LmjU2x1faLZ39DVTFyVca6)_ --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent ac10778 commit 601b258

1 file changed

Lines changed: 43 additions & 4 deletions

File tree

‎packages/cli/test/hook-timeout-override-refusal.test.ts‎

Lines changed: 43 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -93,6 +93,45 @@ const VITEST_ENTRY = resolve(dirname(require.resolve('vitest/package.json')), 'v
9393
/** The refusal's own headline, as `renderInertOverrideNotice` prints it. */
9494
const REFUSAL = 'TIMEOUT OVERRIDE CANNOT REACH THIS PACKAGE';
9595

96+
/**
97+
* The time budget of every case here: one `vitest list` child of this package
98+
* (#24927).
99+
*
100+
* Each case blocks on exactly one child (`runVitestList`, a synchronous
101+
* `execFileSync`), so a case's wall time is that child's wall time, and
102+
* vitest's 5000 ms default is a number nobody chose for that work. A control
103+
* child passes the config load and then resolves both projects and globs the
104+
* whole package; a refusing child stops at the config load. So the control
105+
* child is the larger one, and its reading sizes the budget for all four.
106+
*
107+
* Readings in ms, slowest case of each kind (refusal / control):
108+
*
109+
* - CI, merge group run 39444329582, job `Test Core (2/6)`, a contended
110+
* shard: 3355 / 7897. Both controls failed, `Test timed out in 5000ms.`
111+
* - Local, idle, 6 runs of this file alone: 1244 / 2350.
112+
* - Local, 12 runs beside this package's own Test Core slice
113+
* (`OS_TEST_SHARD` 1/3, `OS_TEST_TIERS=queue`, `VITEST_MAX_WORKERS=3`),
114+
* with this file pinned to one CPU that it shares with 2 busy loops:
115+
* 5134 / 8685. In the 6 runs at the default, both controls failed every
116+
* time. This load reproduces the CI reading: the file read 21.2 to 24.4 s
117+
* here and 21.2 s in CI.
118+
*
119+
* The rule follows plugin-sharing's scrypt budgets
120+
* (`share-link-password-webcontainer.test.ts`): take 3x the slowest reading
121+
* and round up to the next second. 3 x 8685 = 26055, so the budget is 27000.
122+
* The refusals are budgeted too: the same load took one of them to 5134 ms,
123+
* past the default.
124+
*
125+
* The case body blocks the event loop, so vitest cannot interrupt it. vitest
126+
* judges the budget after the child returns: its elapsed-time check fails a
127+
* synchronous case that ran past its timeout. `execFileSync` here is given no
128+
* `timeout`, so no child limit fires before this one. If a case's child count
129+
* or the package's test population changes, re-measure and re-size. Do not
130+
* make a control cheaper by narrowing what it lists (a `--project`, a file
131+
* filter): it asks about a run of the whole package.
132+
*/
133+
const VITEST_LIST_BUDGET_MS = 27_000;
134+
96135
interface ChildRun {
97136
readonly status: number;
98137
readonly output: string;
@@ -141,15 +180,15 @@ describe('#18788 a CLI timeout override that cannot reach a project is refused,
141180
// ownership §3). Both spellings named here are measured in this package.
142181
expect(run.output).toContain('extends: true');
143182
expect(run.output).toContain('beforeAll(fn, 1)');
144-
});
183+
}, VITEST_LIST_BUDGET_MS);
145184

146185
it('refuses `--teardownTimeout` — the other knob the same allowlist drops', () => {
147186
const run = runVitestList('--teardownTimeout=1');
148187

149188
expect(run.status).not.toBe(0);
150189
expect(run.output).toContain(REFUSAL);
151190
expect(run.output).toContain('--teardownTimeout');
152-
});
191+
}, VITEST_LIST_BUDGET_MS);
153192

154193
it('⭐ CONTROL — a run naming no override passes and says nothing', () => {
155194
// Without this leg the three above are satisfied by a config that refuses
@@ -160,7 +199,7 @@ describe('#18788 a CLI timeout override that cannot reach a project is refused,
160199
expect(run.output).not.toContain(REFUSAL);
161200
// It really listed something, so the zero is a reading and not an empty run.
162201
expect(run.output).toMatch(/\.test\.ts/);
163-
});
202+
}, VITEST_LIST_BUDGET_MS);
164203

165204
it('⭐ CONTROL — `--testTimeout` is on vitest’s allowlist, reaches the projects, and is NOT refused', () => {
166205
// The discriminator. `--testTimeout=1` bounds test bodies here for real
@@ -172,5 +211,5 @@ describe('#18788 a CLI timeout override that cannot reach a project is refused,
172211

173212
expect(run.status).toBe(0);
174213
expect(run.output).not.toContain(REFUSAL);
175-
});
214+
}, VITEST_LIST_BUDGET_MS);
176215
});

0 commit comments

Comments
 (0)