test(plugin-dev): pay the plugin-security transform at module load, out of every clocked window - #10120
Conversation
…ent-warning test bodies bail #1 of dev-plugin-security-enforcement-warning.test.ts paid the cold vite transform of the deliberately-unmocked real `@objectstack/plugin-security` chain inside its own measured window, via `DevPlugin.start()`'s dynamic import. On an idle 4-vCPU container that cost 3110/3351/3360 ms — ~70% of vitest's 5000ms default testTimeout — while the file's other three tests cost 3-5 ms each. Under four concurrent tsup DTS builds of plugin-dev dependents it crossed the budget on every run (5006/5007/5006 ms, "Test timed out in 5000ms"), and bail #2 inherited the still-cold import (2203-2931 ms) and went red with it on the busier CI shard. Pay the import once in a `beforeAll` instead, so it lands on vitest's separate hookTimeout (default 10000ms) and each `it` measures only the behaviour it is about. After, same machine and same load: bail #1 is 22-26 ms idle and 29-54 ms under the four-build load, all four tests green. No assertion is skipped, weakened or mocked, and no timeout is raised — the four tests remain the pins for the "nothing is enforced" warning. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01PnJHU45vPJj5UQrxe946Bx
📓 Docs Drift CheckNothing 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. |
|
Coordination note from the spec seat (session
If this seat can help expedite (review corroboration is above), say so on this PR; otherwise ignore this note. Generated by Claude Code |
⛔ merge queue 构建失败 — 先分诊,再决定要不要重排队列构建 32334616926 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集), 失败的 job(日志抽取,best effort):
历史信号:
分诊清单:
Generated by Claude Code · merge-queue-triage workflow (#4859) |
⛔ merge queue 构建失败 — 先分诊,再决定要不要重排队列构建 32334745861 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集), 失败的 job(日志抽取,best effort):
历史信号:
分诊清单:
Generated by Claude Code · merge-queue-triage workflow (#4859) |
⛔ merge queue 构建失败 — 先分诊,再决定要不要重排队列构建 32334642055 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集), 失败的 job(日志抽取,best effort):
历史信号:
分诊清单:
Generated by Claude Code · merge-queue-triage workflow (#4859) |
⛔ merge queue 构建失败 — 先分诊,再决定要不要重排队列构建 32335141663 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集), 失败的 job(日志抽取,best effort):
历史信号:
分诊清单:
Generated by Claude Code · merge-queue-triage workflow (#4859) |
…ot in a clocked window The `beforeAll` warm-up only moved the one-off `@objectstack/plugin-security` transform from the 5000ms `testTimeout` onto the 10000ms `hookTimeout`. The merge queue runs the FULL suite where PR-side CI runs only the affected subset, and on that heavier shard the hook itself blew its budget — ejecting the PR four times with `Error: Hook timed out in 10000ms.` at this file's `beforeAll`. Replace the hook with a top-level side-effect import. Collection is the one phase vitest 4.1.10 clocks against nothing: `@vitest/runner` wraps only hooks and test bodies in `withTimeout(...)`, `collectTests()` awaits `runner.importFile(filepath, 'collect')` bare and merely records `collectDuration`, and the runner exposes exactly three timeout knobs (`testTimeout`, `hookTimeout`, `teardownTimeout`), none covering module load. Under an identical single-core load the file's `tests` phase drops from 7.22s to 67ms and the suite stays green even with `--hookTimeout=1`. All four #10036 assertions are untouched, and the real plugin is still imported for real. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01PnJHU45vPJj5UQrxe946Bx
Fixes #10115
Follow-up round: the
beforeAllfix was insufficient, and this is whyThe first commit moved the one-off
@objectstack/plugin-securitytransform off each test's5000ms
testTimeoutand onto vitest's 10000mshookTimeout. That was accepted with arecorded residual — "if a heavier shard ever makes the hook itself time out". The residual
materialised immediately: the merge queue runs the full suite where PR-side CI runs only
the affected subset, and on that heavier shard the hook blew its own budget, ejecting this
PR four times and jamming the queue for everyone.
The failing signature, verbatim
Extracted from queue run
32335141663, job96323172298, shardTest Core (3/3)(the threesibling ejections
32334616926/32334642055/32334745861carry the same block):It is the hook, not a test body, not an assertion, not an OOM. The
beforeAllat:97:1consumed 10024ms of its 10000ms budget and the four bodies never ran (
4 skipped).The fix: move the cost out of every clocked window, not into a bigger one
Any budget the cost is moved into can be exhausted by a heavier shard — that is the class,
and both previous shapes were instances of it. A top-level side-effect import is paid during
collection, and in vitest 4.1.10 collection is clocked against nothing.
Verified against the installed runner rather than recalled:
@vitest/runner@4.1.10wraps exactly hooks and test bodies inwithTimeout(...). Everycall site is a
beforeAll/afterAll/beforeEach/afterEach/onTestFailed/onTestFinishedhandler or a testresult.collectTests()awaitsrunner.importFile(filepath, "collect")bare — no wrapper — andmerely records
file.collectDuration = now() - collectStart. That value is only ever summedfor reporters; it is never compared against a budget anywhere in the runner or in vitest.
vitest --helpon 4.1.10 offers exactly three timeout knobs:--testTimeout(test bodies),--hookTimeout(hooks),--teardownTimeout(teardown). None covers module loading.vi.mockis hoisted above every import in the file, this one included, so the ten mocks stillregister before the new import is evaluated — the same mechanism that already lets the
existing static
./dev-pluginimport see them.No assertion is skipped, weakened, quarantined or mocked; no timeout is raised; the real
plugin is still imported for real. The four #10036 pins are untouched.
Numbers, with margin
4-vCPU container. Load = the run confined to one core (
taskset -c 0) with a spinner on thatsame core, which reproduces the share a vitest process gets on a loaded shard. Each run is
cold (
node_modules/.viteremoved first).testsphaseThe margin after this change is not a bigger number in the same budget — it is the absence of
the budget. The
testsphase drops 7.22s to 67ms (108x), the cost reappearing in theunclocked
importphase (5.3s to 12.8s). Against the 5000mstestTimeoutthe worst body nowsits at 41ms, a 122x headroom. And the file has no hook at all, so it passes even under
--hookTimeout=1, which is the sharpest statement of the margin available: there is no hooktime left to clock.
Reproduction honesty
I could not push the hook past 10000ms on this container. It plateaus hard at 7.2-7.4s
across 1, 2, 6 and 12 competing spinners, and adding a forced uncached full-repo test run
alongside did not move it either — past that point the residual is IO-bound, not CPU-bound.
So the local reproduction relocates the cliff with a CLI flag (
--hookTimeout=5000)rather than manufacturing the load, touching neither the file nor any committed config. That
yields the identical failure shape at the identical call site:
Ablation
Predicted before running: reverting the file to its
e0ac7ef34content under the same loadwith
--hookTimeout=5000goes red withHook timed out in 5000msat:97:1, with 4skipped and 0 failed bodies, because a failing suite-level hook skips them rather than
running them. Observed exactly that; the restored leg is green at
tests 66ms.Rebuild statement. The mutated artifact is the test file itself, which vitest loads from
src/with no packageexportsordistindirection, so no build step can sit between theedit and the run. The one dependency this file consumes through an
exportsmap is@objectstack/plugin-security(todist/); it is untouched by both legs and its dist treehashes identically across them, so the two legs differ only in the test file.
Gates
Union derived by
node scripts/pm/dispatch-gates.mjswith no paths passed (it takes its ownchange set from the merge base), run after the final commit, at
7ef8159b7, on a cleanworktree. Exit codes captured before any pipe; each gate printed its own verdict line.
One narrowing, declared:
check:type-check-debt --re-measurewas not run locally. It requiresa full workspace build and re-runs tsc per ledger entry;
plugin-devdeclares its owntypecheckscript and carries no DEBT or TEST_DEBT entry, so this diff cannot move any countit measures. The structural half,
check:type-check-coverage, is green above. CI runs itregardless.
A first pass reported
plugin-dev typecheckEXIT=2 on@objectstack/spec/security. That wasdamage from my own load harness, which killed
@objectstack/spec#buildmid-DTS and leftdist/security/with.jsbut no.d.ts. Rebuilding spec restored EXIT=0. Recorded becausea truncated
distreading lies in both directions and this one read as a real defect in afile this PR never touches.
Changeset
None, deliberately: test-only, publishes nothing. The
skip-changesetlabel was alreadyapplied to this PR and is still present, so the changeset gate is satisfied by the repo
mechanism rather than by an empty changeset (which
scripts/check-empty-changeset.mjsrejects).
Queue note
#10003 and #10008 were ejected by this same timeout and are on repeat queue attempts; nothing
had merged to
mainrepo-wide for about 2.5h. Those cards are not addressed here — this PRonly removes the jam they were caught in. I have deliberately not re-queued this PR, since
each ejection forces every PR behind it to rebuild; re-queueing is the reviewer's call now
that the fix is on the branch.
Generated by Claude Code