Skip to content

test(plugin-dev): pay the plugin-security transform at module load, out of every clocked window - #10120

Merged
os-zhuang merged 2 commits into
mainfrom
claude/issue-10115-plugin-dev-enforcement-warning-timeout
Aug 20, 2026
Merged

test(plugin-dev): pay the plugin-security transform at module load, out of every clocked window#10120
os-zhuang merged 2 commits into
mainfrom
claude/issue-10115-plugin-dev-enforcement-warning-timeout

Conversation

@os-warren

@os-warrenos-warren commented Aug 20, 2026

Copy link
Copy Markdown
Collaborator

Fixes#10115

Follow-up round: the beforeAll fix was insufficient, and this is why

The first commit moved the one-off @objectstack/plugin-security transform off each test's
5000ms testTimeout and onto vitest's 10000ms hookTimeout. That was accepted with a
recorded 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, job 96323172298, shard Test Core (3/3) (the three
sibling ejections 32334616926 / 32334642055 / 32334745861 carry the same block):

 ❯ src/dev-plugin-security-enforcement-warning.test.ts (4 tests | 4 skipped) 10024ms
⎯⎯⎯⎯⎯⎯ Failed Suites 1 ⎯⎯⎯⎯⎯⎯⎯
FAIL src/dev-plugin-security-enforcement-warning.test.ts [ src/dev-plugin-security-enforcement-warning.test.ts ]
Error: Hook timed out in 10000ms.
If this is a long-running hook, pass a timeout value as the last argument or configure it globally with "hookTimeout".
❯ src/dev-plugin-security-enforcement-warning.test.ts:97:1
97| beforeAll(async () => {
| ^
98| await import('@objectstack/plugin-security');
Test Files 1 failed | 5 passed (6)
Tests 54 passed | 4 skipped (58)
Duration 21.78s (transform 24.44s, setup 0ms, import 29.92s, ...)

It is the hook, not a test body, not an assertion, not an OOM. The beforeAll at :97:1
consumed 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.10 wraps exactly hooks and test bodies in withTimeout(...). Every
    call site is a beforeAll / afterAll / beforeEach / afterEach / onTestFailed /
    onTestFinished handler or a test result.
  • collectTests() awaits runner.importFile(filepath, "collect")bare — no wrapper — and
    merely records file.collectDuration = now() - collectStart. That value is only ever summed
    for reporters; it is never compared against a budget anywhere in the runner or in vitest.
  • vitest --help on 4.1.10 offers exactly three timeout knobs: --testTimeout (test bodies),
    --hookTimeout (hooks), --teardownTimeout (teardown). None covers module loading.

vi.mock is hoisted above every import in the file, this one included, so the ten mocks still
register before the new import is evaluated — the same mechanism that already lets the
existing static ./dev-plugin import 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 that
same core, which reproduces the share a vitest process gets on a loaded shard. Each run is
cold (node_modules/.vite removed first).

conditiontests phasemax test bodyoutcome
before, idle3.32s26 mspass
before, loaded7.22s (72% of the 10000ms hookTimeout)69 mspass, 1.38x margin
before, queue (GitHub)10024ms❌ ejected 4x
after, loaded67 ms41 mspass

The margin after this change is not a bigger number in the same budget — it is the absence of
the budget. The tests phase drops 7.22s to 67ms (108x), the cost reappearing in the
unclocked import phase (5.3s to 12.8s). Against the 5000ms testTimeout the worst body now
sits 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 hook
time 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:

 FAIL src/dev-plugin-security-enforcement-warning.test.ts [ src/dev-plugin-security-enforcement-warning.test.ts ]
Error: Hook timed out in 5000ms.
❯ src/dev-plugin-security-enforcement-warning.test.ts:97:1
Test Files 1 failed (1)
Tests 4 skipped (4)

Ablation

Predicted before running: reverting the file to its e0ac7ef34 content under the same load
with --hookTimeout=5000 goes red with Hook timed out in 5000ms at :97:1, with 4
skipped 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.

fixed / HEAD blob = b6668b86bb66d1909d5a6edbf54f9be906083e93
mutated blob = 02952e11a4852b0d4189d393113c1841ac25fa98 (== e0ac7ef34 blob for this path) ✓
restored blob = b6668b86bb66d1909d5a6edbf54f9be906083e93 ✓ byte-identical
plugin-security dist, both legs = eb0a6d768db316932680cbc181a46c63ab0d55bc ✓ identical

Rebuild statement. The mutated artifact is the test file itself, which vitest loads from
src/ with no package exports or dist indirection, so no build step can sit between the
edit and the run. The one dependency this file consumes through an exports map is
@objectstack/plugin-security (to dist/); it is untouched by both legs and its dist tree
hashes identically across them, so the two legs differ only in the test file.

Gates

Union derived by node scripts/pm/dispatch-gates.mjs with no paths passed (it takes its own
change set from the merge base), run after the final commit, at 7ef8159b7, on a clean
worktree. Exit codes captured before any pipe; each gate printed its own verdict line.

nul-bytes 0 · slot-lookup 0 · test-source-alias 0 · type-source-resolution 0
affected-docs 0 · query-options-erasure 0 · type-check-coverage 0
engine-double-contract 0 · where-matcher 0
plugin-dev typecheck 0 · plugin-dev test 0 (6 files, 58 tests, 58 passed)

One narrowing, declared: check:type-check-debt --re-measure was not run locally. It requires
a full workspace build and re-runs tsc per ledger entry; plugin-dev declares its own
typecheck script and carries no DEBT or TEST_DEBT entry, so this diff cannot move any count
it measures. The structural half, check:type-check-coverage, is green above. CI runs it
regardless.

A first pass reported plugin-dev typecheck EXIT=2 on @objectstack/spec/security. That was
damage from my own load harness, which killed @objectstack/spec#build mid-DTS and left
dist/security/ with .js but no .d.ts. Rebuilding spec restored EXIT=0. Recorded because
a truncated dist reading lies in both directions and this one read as a real defect in a
file this PR never touches.

Changeset

None, deliberately: test-only, publishes nothing. The skip-changeset label was already
applied 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.mjs
rejects).

Queue note

#10003 and #10008 were ejected by this same timeout and are on repeat queue attempts; nothing
had merged to main repo-wide for about 2.5h. Those cards are not addressed here — this PR
only 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

…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
@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.

@os-zhuangClaude

Copy link
Copy Markdown
Contributor

Coordination note from the spec seat (session session_01URCaKuNTuK3BKJvwqM74QU), for the owning seat's review — no action taken on this PR, it stays yours to drive:

  1. Independent corroboration: a finding: #10036 的告警测试依赖兄弟包 dist 却未声明构建边 —— merge queue 全量 shard 随缓存状态非确定性红,已弹出一个无辜 PR(#10105) #10112 dispatch re-measured this defect blind to your numbers and landed on the same mechanism and the same fix shape — idle before bail Add metamodel interfaces for ObjectQL/ObjectUI contract #1 = 3402ms (yours 3110/3351/3360), beforeAll warm-up after = 22ms (yours 22/23/24/26), assertion-shape absent from all three ejection logs, plugin-security:build present on all three red shards. Full readings on finding: #10036 的告警测试依赖兄弟包 dist 却未声明构建边 —— merge queue 全量 shard 随缓存状态非确定性红,已弹出一个无辜 PR(#10105) #10112 (report comment 5351652455). finding: #10036 的告警测试依赖兄弟包 dist 却未声明构建边 —— merge queue 全量 shard 随缓存状态非确定性红,已弹出一个无辜 PR(#10105) #10112 is re-scoped to its surviving local-DX half and no longer competes with this PR.
  2. Two queue victims wait on this landing: docs(os-dev): an ablation must prove its mutation landed on disk #10003 and feat(docs-gate): close the runtime-services stability label vocabulary #10008 (maintainer-authorized merges) were both ejected by this exact timeout and are on their second queue attempt now, un-protected — if they eject again, their final re-queue waits for this PR. Queue health generally: three ejections in one night from this one test.

If this seat can help expedite (review corroboration is above), say so on this PR; otherwise ignore this note.


Generated by Claude Code

@github-actions

Copy link
Copy Markdown
Contributor

⛔ merge queue 构建失败 — 先分诊,再决定要不要重排

队列构建 32334616926 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集),
所以失败的测试可能在本 PR 没碰过的包里 —— 那不是重排能修的。每次盲目重排都会让排在后面的所有 PR 重建一轮。

失败的 job(日志抽取,best effort):

  • Test Core (3/3) — 失败步骤: Run this shard's tests

    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[41m�[1m FAIL �[22m�[49m src/dev-plugin-security-enforcement-warning.test.ts�[2m [ src/dev-plugin-security-enforcement-warning.test.ts ]�[22m
    

历史信号:

  • 本 PR 过去 24h 无队列失败记录(首次)。
  • 过去 24h 队列共有 26 个失败构建(不含本次)。

分诊清单:

  1. 失败测试在本 PR 改动的包里 → 真回归,修 PR。
  2. 失败测试与本 PR 无关 → 在其他 PR 的同类评论里搜同名测试;出现过 ⇒ flaky 实锤,开 issue 修/隔离那条测试。修好前重排只会再烧一轮全队列。
  3. 两者都不是 → 可能与同组 PR 语义冲突;等前面的 PR 落地或失败出队后再重排一次即可,不要连续重排。

Generated by Claude Code · merge-queue-triage workflow (#4859)

@github-merge-queue
github-merge-queueBot removed this pull request from the merge queue due to failed status checks Aug 20, 2026
@github-actions

Copy link
Copy Markdown
Contributor

⛔ merge queue 构建失败 — 先分诊,再决定要不要重排

队列构建 32334745861 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集),
所以失败的测试可能在本 PR 没碰过的包里 —— 那不是重排能修的。每次盲目重排都会让排在后面的所有 PR 重建一轮。

失败的 job(日志抽取,best effort):

  • Test Core (3/3) — 失败步骤: Run this shard's tests

    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[41m�[1m FAIL �[22m�[49m src/dev-plugin-security-enforcement-warning.test.ts�[2m [ src/dev-plugin-security-enforcement-warning.test.ts ]�[22m
    

历史信号:

  • ⚠️本 PR 过去 24h 已在队列失败 1 次(不含本次)。 内容未变而反复失败 ⇒ 高度怀疑 flaky 测试或与同组 PR 的语义冲突,重排不解决。
  • 过去 24h 队列共有 29 个失败构建(不含本次)。

分诊清单:

  1. 失败测试在本 PR 改动的包里 → 真回归,修 PR。
  2. 失败测试与本 PR 无关 → 在其他 PR 的同类评论里搜同名测试;出现过 ⇒ flaky 实锤,开 issue 修/隔离那条测试。修好前重排只会再烧一轮全队列。
  3. 两者都不是 → 可能与同组 PR 语义冲突;等前面的 PR 落地或失败出队后再重排一次即可,不要连续重排。

Generated by Claude Code · merge-queue-triage workflow (#4859)

@github-actions

Copy link
Copy Markdown
Contributor

⛔ merge queue 构建失败 — 先分诊,再决定要不要重排

队列构建 32334642055 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集),
所以失败的测试可能在本 PR 没碰过的包里 —— 那不是重排能修的。每次盲目重排都会让排在后面的所有 PR 重建一轮。

失败的 job(日志抽取,best effort):

  • Test Core (3/3) — 失败步骤: Run this shard's tests

    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[41m�[1m FAIL �[22m�[49m src/dev-plugin-security-enforcement-warning.test.ts�[2m [ src/dev-plugin-security-enforcement-warning.test.ts ]�[22m
    

历史信号:

  • ⚠️本 PR 过去 24h 已在队列失败 2 次(不含本次)。 内容未变而反复失败 ⇒ 高度怀疑 flaky 测试或与同组 PR 的语义冲突,重排不解决。
  • 过去 24h 队列共有 30 个失败构建(不含本次)。

分诊清单:

  1. 失败测试在本 PR 改动的包里 → 真回归,修 PR。
  2. 失败测试与本 PR 无关 → 在其他 PR 的同类评论里搜同名测试;出现过 ⇒ flaky 实锤,开 issue 修/隔离那条测试。修好前重排只会再烧一轮全队列。
  3. 两者都不是 → 可能与同组 PR 语义冲突;等前面的 PR 落地或失败出队后再重排一次即可,不要连续重排。

Generated by Claude Code · merge-queue-triage workflow (#4859)

@github-actions

Copy link
Copy Markdown
Contributor

⛔ merge queue 构建失败 — 先分诊,再决定要不要重排

队列构建 32335141663 红了。队列跑的是全量套件(PR 侧 CI 只跑 affected 子集),
所以失败的测试可能在本 PR 没碰过的包里 —— 那不是重排能修的。每次盲目重排都会让排在后面的所有 PR 重建一轮。

失败的 job(日志抽取,best effort):

  • Test Core (3/3) — 失败步骤: Run this shard's tests

    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mdrops the subscription rather than delivering it wi
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[90mstdout�[2m | src/webhook-secret-at-rest.test.ts�[2m > �[22m�[2mfail-closed and re-arm, extended to headers (#7986 × #7799/#8022)�[2m > �[22m�[2mre-arms with its headers when the CryptoProvider re
    �[41m�[1m FAIL �[22m�[49m src/dev-plugin-security-enforcement-warning.test.ts�[2m [ src/dev-plugin-security-enforcement-warning.test.ts ]�[22m
    

历史信号:

  • ⚠️本 PR 过去 24h 已在队列失败 3 次(不含本次)。 内容未变而反复失败 ⇒ 高度怀疑 flaky 测试或与同组 PR 的语义冲突,重排不解决。
  • 过去 24h 队列共有 31 个失败构建(不含本次)。

分诊清单:

  1. 失败测试在本 PR 改动的包里 → 真回归,修 PR。
  2. 失败测试与本 PR 无关 → 在其他 PR 的同类评论里搜同名测试;出现过 ⇒ flaky 实锤,开 issue 修/隔离那条测试。修好前重排只会再烧一轮全队列。
  3. 两者都不是 → 可能与同组 PR 语义冲突;等前面的 PR 落地或失败出队后再重排一次即可,不要连续重排。

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
@os-warrenos-warren changed the title test(plugin-dev): warm the plugin-security import out of the enforcement-warning test bodiestest(plugin-dev): pay the plugin-security transform at module load, out of every clocked windowAug 20, 2026
@os-zhuang
os-zhuang enabled auto-merge August 20, 2026 06:24
@os-zhuang
os-zhuang added this pull request to the merge queueAug 20, 2026
Merged via the queue into main with commit e61ee68Aug 20, 2026
32 checks passed
@os-zhuang
os-zhuang deleted the claude/issue-10115-plugin-dev-enforcement-warning-timeout branch August 20, 2026 06:44
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/sskip-changesetPR has no user-facing published change; bypasses the changeset gatetests

Projects

None yet

3 participants

@os-warren@os-zhuang@claude