From e0ac7ef347102f2bb6169c01d8e3a20da6a0b27d Mon Sep 17 00:00:00 2001 From: os-warren Date: Thu, 20 Aug 2026 04:39:59 +0000 Subject: [PATCH 1/2] test(plugin-dev): warm the plugin-security import out of the enforcement-warning test bodies MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 Claude-Session: https://claude.ai/code/session_01PnJHU45vPJj5UQrxe946Bx --- ...lugin-security-enforcement-warning.test.ts | 34 ++++++++++++++++++- 1 file changed, 33 insertions(+), 1 deletion(-) diff --git a/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts b/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts index 3dc5e0ad08..02952e11a4 100644 --- a/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts +++ b/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts @@ -1,4 +1,4 @@ -import { describe, it, expect, vi } from 'vitest'; +import { describe, it, expect, vi, beforeAll } from 'vitest'; import { DevPlugin } from './dev-plugin'; // [#10036] The state under test is "SecurityPlugin LOADED but its start() @@ -66,6 +66,38 @@ async function boot(ctx: any, options: Record = {}) { return plugin; } +// [#10115] Pay the one-off module-graph cost HERE, before the first `it`. +// +// `DevPlugin.start()` reaches `@objectstack/plugin-security` through a dynamic +// `await import()`, and this file deliberately leaves that chain unmocked (see +// the header: the real plugin's `init()`/`start()` phase split IS the subject). +// So whichever test ran first paid the plugin's cold vite transform inside its +// own measured window. Measured on an idle 4-vCPU container, bail #1 cost +// 3110 / 3351 / 3360 ms — ~70% of vitest's 5000ms default `testTimeout` — while +// the 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 then +// inherited the still-cold import (2203-2931 ms) and went red with it on the +// busier CI shard. Because a PR that dirties a plugin-dev dependency both makes +// this file re-run AND makes it run beside a cold rebuild, the failure was +// intermittent and named neither the real cause nor the offending PR — it read +// as "your change broke security enforcement" when nothing of the sort happened. +// +// Warming the import here moves that one-off transform off every test's clock +// and onto vitest's separate `hookTimeout` (default 10000ms — twice the test +// budget), so each `it` measures only the behaviour it is about. Same machine, +// same load, after: bail #1 22-26 ms idle and 29-54 ms under the same four-build +// load, all four tests green. +// +// ⛔ This must stay a REAL import of the REAL plugin — replacing it with a stub, +// here or via `vi.mock`, deletes the subject exactly as the header warns. +// ⛔ Do not answer a future recurrence by raising `testTimeout` instead: that +// widens the window around the cost rather than moving the cost out of it, and +// it re-hides the next in-test transform that lands in this file. +beforeAll(async () => { + await import('@objectstack/plugin-security'); +}); + describe('[#10036] the "nothing is enforced" warning must fire when SecurityPlugin.start() bailed', () => { // ── The state the warning describes, constructed for real ─────────────── // From 7ef8159b786afba05fabd911e24d08a1dc810f79 Mon Sep 17 00:00:00 2001 From: Claude Date: Thu, 20 Aug 2026 06:09:20 +0000 Subject: [PATCH 2/2] test(plugin-dev): pay the plugin-security transform at module load, not in a clocked window MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 Claude-Session: https://claude.ai/code/session_01PnJHU45vPJj5UQrxe946Bx --- ...lugin-security-enforcement-warning.test.ts | 83 +++++++++++-------- 1 file changed, 50 insertions(+), 33 deletions(-) diff --git a/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts b/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts index 02952e11a4..b6668b86bb 100644 --- a/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts +++ b/packages/plugins/plugin-dev/src/dev-plugin-security-enforcement-warning.test.ts @@ -1,6 +1,55 @@ -import { describe, it, expect, vi, beforeAll } from 'vitest'; +import { describe, it, expect, vi } from 'vitest'; import { DevPlugin } from './dev-plugin'; +// [#10115] Pay the one-off `@objectstack/plugin-security` module-graph cost at +// MODULE LOAD, not inside any hook and not inside any test. +// +// `DevPlugin.start()` reaches the plugin through a dynamic `await import()`, and +// this file deliberately leaves that chain unmocked (see the header below: the +// real plugin's `init()`/`start()` phase split IS the subject). Something has to +// pay its cold vite transform; the only question is which clock is running when +// it does. This file has now answered that question wrongly twice: +// +// * paid inside whichever `it` ran first -> `Test timed out in 5000ms` +// (idle 3110/3351/3360 ms; red on every run under four concurrent builds). +// * moved into a `beforeAll` -> `Hook timed out in 10000ms`, +// which ejected this file from the merge queue four times in one night +// (runs 32334616926 / 32334642055 / 32334745861 / 32335141663, shard +// `Test Core (3/3)`, file duration 10024ms) while PR-side CI stayed green -- +// the queue runs the FULL suite, PR-side CI only the affected subset, so the +// queue shard is far heavier than anything the PR checks measure. +// +// Neither move took the cost OUT of a clocked window; each only widened or +// swapped the window around it, which relocates the cliff to the next heavier +// shard instead of removing it. A top-level import is paid during collection, +// and in vitest 4.1.10 collection is clocked against NOTHING. Verified against +// the installed runner, not recalled: `@vitest/runner` wraps exactly hooks and +// test bodies in `withTimeout(...)`, while `collectTests()` awaits +// `runner.importFile(filepath, 'collect')` bare and merely RECORDS +// `file.collectDuration` for reporters; and `vitest --help` on 4.1.10 offers +// exactly three timeout knobs -- `testTimeout`, `hookTimeout`, `teardownTimeout` +// -- none of which covers module loading. +// +// Measured on a 4-vCPU container with this run confined to a single core and a +// spinner beside it (idle -> loaded): the old `beforeAll` cost 3.3s -> 7.2-7.4s, +// i.e. 74% of its 10000ms budget on a machine that could not even reach the +// load the queue applies. After this change the file has NO hook at all, its +// four tests cost 2-70 ms each against the 5000ms `testTimeout`, and the run +// stays green even under `--hookTimeout=1` -- there is no hook time left to clock. +// +// `vi.mock` is hoisted above every import in this file, this one included, so +// the ten mocks below still register before this module is evaluated. +// +// This must stay a REAL, STATIC, side-effect import of the REAL plugin: +// - replacing it with a stub, here or via `vi.mock`, deletes the subject +// exactly as the header warns; +// - turning it back into a hook or a dynamic `await import()` puts the cost +// back inside a clocked window and re-arms the ejection; +// - answering a recurrence by raising `testTimeout` / `hookTimeout` widens the +// window around the cost rather than moving the cost out of it, and re-hides +// the next transform that lands in this file. +import '@objectstack/plugin-security'; + // [#10036] The state under test is "SecurityPlugin LOADED but its start() // bailed", so `@objectstack/plugin-security` is deliberately NOT mocked here — // the real plugin's real `init()`/`start()` phase split is what constructs the @@ -66,38 +115,6 @@ async function boot(ctx: any, options: Record = {}) { return plugin; } -// [#10115] Pay the one-off module-graph cost HERE, before the first `it`. -// -// `DevPlugin.start()` reaches `@objectstack/plugin-security` through a dynamic -// `await import()`, and this file deliberately leaves that chain unmocked (see -// the header: the real plugin's `init()`/`start()` phase split IS the subject). -// So whichever test ran first paid the plugin's cold vite transform inside its -// own measured window. Measured on an idle 4-vCPU container, bail #1 cost -// 3110 / 3351 / 3360 ms — ~70% of vitest's 5000ms default `testTimeout` — while -// the 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 then -// inherited the still-cold import (2203-2931 ms) and went red with it on the -// busier CI shard. Because a PR that dirties a plugin-dev dependency both makes -// this file re-run AND makes it run beside a cold rebuild, the failure was -// intermittent and named neither the real cause nor the offending PR — it read -// as "your change broke security enforcement" when nothing of the sort happened. -// -// Warming the import here moves that one-off transform off every test's clock -// and onto vitest's separate `hookTimeout` (default 10000ms — twice the test -// budget), so each `it` measures only the behaviour it is about. Same machine, -// same load, after: bail #1 22-26 ms idle and 29-54 ms under the same four-build -// load, all four tests green. -// -// ⛔ This must stay a REAL import of the REAL plugin — replacing it with a stub, -// here or via `vi.mock`, deletes the subject exactly as the header warns. -// ⛔ Do not answer a future recurrence by raising `testTimeout` instead: that -// widens the window around the cost rather than moving the cost out of it, and -// it re-hides the next in-test transform that lands in this file. -beforeAll(async () => { - await import('@objectstack/plugin-security'); -}); - describe('[#10036] the "nothing is enforced" warning must fire when SecurityPlugin.start() bailed', () => { // ── The state the warning describes, constructed for real ─────────────── //