diff --git a/.planning/debug/resolved/01-10-vitest-build-test-timeout.md b/.planning/debug/resolved/01-10-vitest-build-test-timeout.md new file mode 100644 index 0000000..d4118a1 --- /dev/null +++ b/.planning/debug/resolved/01-10-vitest-build-test-timeout.md @@ -0,0 +1,82 @@ +--- +slug: 01-10-vitest-build-test-timeout +status: resolved +goal: find_and_fix +trigger: "npm test (full run, no SKIP_BUILD=1) fails 1/150 with timeout in tests/background/no-test-hooks-in-prod-bundle.test.ts at line 247 — Test timed out in 5000ms" +phase: 01-stabilize-video-pipeline +plan: 01-10 +opened: 2026-05-20 +closed: 2026-05-20 +orchestrator_diagnosed: true +--- + +# Debug session 01-10-vitest-build-test-timeout — vitest it() default 5s ceiling races slower welcome-page build + +## Problem statement + +After Plan 01-10 closure (commits d48a715 welcome mark + 4bba679 notif-text), `npm test` (full run, no `SKIP_BUILD=1`) failed 1/150 with a vitest timeout in `tests/background/no-test-hooks-in-prod-bundle.test.ts` at line 247: + +``` +FAIL tests/background/no-test-hooks-in-prod-bundle.test.ts > production bundle has no test-hook leaks (Tier-1 gate — T-1-11-01) > npm run build completes and dist/ exists with at least one chunk +Error: Test timed out in 5000ms. +``` + +Standalone `npm run build` had slowed from ~2.88s (pre-Plan-01-10) to ~5.28s due to welcome page Vite processing + SVG `?url` import + 8 WOFF2 fonts shipped in d48a715 / 49f087f. With the build now exceeding 5s, vitest's default 5000ms `it()` ceiling races and loses. + +`SKIP_BUILD=1 npm test` was passing 150/150 GREEN, confirming this was purely a test-infrastructure timeout-tuning issue, NOT a real build/grep-gate regression. + +## Root cause + +The `it()` block at `tests/background/no-test-hooks-in-prod-bundle.test.ts:247` was declared without a 3rd-arg timeout option: + +```ts +it('npm run build completes and dist/ exists with at least one chunk', async () => { + if (process.env.SKIP_BUILD !== '1') { + await runProductionBuild(); + } + // ... +}); // <-- no timeout 3rd arg → vitest's 5000ms default applies +``` + +The test author had correctly bounded the EXEC-level child-process timeout via `BUILD_TIMEOUT_MS = 60_000` at line 240 (passed to `execFileAsync`), but **forgot to bound the surrounding `it()` block**. Vitest's default it() timeout is 5000ms; the build now takes ~5.28s, so the it() ceiling fires before the exec bound is even close. + +This is the classic "two-tier timeout where only one tier is configured" bug. The exec timeout existed but was useless because the outer it() timeout fired first. + +## Fix design + +Surgical one-line change: add `, 30_000` as the 3rd arg to the failing `it()` call. + +30 seconds was chosen because: +- Generously above the observed 5.28s build + npm overhead (~6× headroom) +- Well below the 60s exec bound (`BUILD_TIMEOUT_MS`), so the exec timeout remains the dominant ceiling for true hangs +- Above the 15s minimum requested by the orchestrator +- Consistent with vitest convention for build-touching it() blocks (real-IO tests routinely declare 10s+ ceilings) + +Inline comment added above the `it()` documenting why the 30s ceiling exists, citing the +2.4s welcome-page-asset slowdown and the relationship to `BUILD_TIMEOUT_MS`. + +The alternative — setting a global `testTimeout` in `vitest.config.ts` — was rejected because: +- 95% of vitest cases are pure-CPU and should keep the 5s default (catches accidental hangs fast) +- Only this one it() touches IO at build scale +- Per-it() timeouts are the standard vitest idiom for "this specific test does slow IO" + +`SKIP_BUILD=1` env-var escape hatch left untouched for CI environments. + +## Files modified + +- `tests/background/no-test-hooks-in-prod-bundle.test.ts` (line 247 it() — added `, 30_000` 3rd arg + 7-line explanatory comment above) + +## Acceptance gates — all PASS + +- `npm test` (FULL run, no SKIP_BUILD=1): **150/150 GREEN**, exit 0, 12.89s total +- `npx tsc --noEmit`: exit 0 +- `npm run build`: exit 0, 4.86s (within new 30s it() ceiling with ~6× margin) +- Tier-1 grep gate: PASS (all 12 FORBIDDEN_HOOK_STRINGS asserted against `dist/`, including the build-completes gate that was previously timing out — now passes within the new ceiling) + +## Noteworthy + +- **The exec-level `BUILD_TIMEOUT_MS = 60_000` ceiling still bounds the child process.** This fix only adjusts the SURROUNDING vitest it() ceiling so the exec bound becomes reachable. If `npm run build` ever truly hangs, the exec timeout fires at 60s; the it() ceiling fires at 30s. Both bounds remain active and meaningful. +- **No SKIP_BUILD logic touched.** CI environments using `SKIP_BUILD=1` (with a pre-existing dist/) skip the slow path entirely and are unaffected. +- **Build slowdown attribution** (for future archaeology): + - d48a715: welcome page mokosh-mark.svg via `?url` import (+~0.4s Vite asset processing) + - 49f087f: welcome HTML/CSS/JS entries + 8 WOFF2 font assets (+~2.0s emit + manifest) + - Net: ~2.88s → ~5.28s on this hardware diff --git a/tests/background/no-test-hooks-in-prod-bundle.test.ts b/tests/background/no-test-hooks-in-prod-bundle.test.ts index d025141..15c9302 100644 --- a/tests/background/no-test-hooks-in-prod-bundle.test.ts +++ b/tests/background/no-test-hooks-in-prod-bundle.test.ts @@ -244,6 +244,13 @@ async function runProductionBuild(): Promise { } describe('production bundle has no test-hook leaks (Tier-1 gate — T-1-11-01)', () => { + // Plan 01-10 closure: `npm run build` slowed from ~2.88s → ~5.28s after + // the welcome page assets landed (welcome HTML + SVG ?url import + 8 WOFF2 + // fonts shipped in d48a715 / 49f087f). Vitest's default 5000ms it() ceiling + // now races the build child. The EXEC-level `BUILD_TIMEOUT_MS = 60_000` + // bound on the child process still applies; this it()-level 30000ms + // ceiling is the surrounding-block companion. 30s is generously above the + // observed 5.28s + npm overhead and well below the 60s exec bound. it('npm run build completes and dist/ exists with at least one chunk', async () => { if (process.env.SKIP_BUILD !== '1') { await runProductionBuild(); @@ -259,7 +266,7 @@ describe('production bundle has no test-hook leaks (Tier-1 gate — T-1-11-01)', `dist/ is empty after npm run build — the build produced no output, which is a different ` + `regression class than a hook leak. Investigate before proceeding to the hook-leak assertion.`, ).toBeGreaterThan(0); - }); + }, 30_000); for (const needle of FORBIDDEN_HOOK_STRINGS) { it(`production bundle does not contain '${needle}' (T-1-11-01 surface)`, () => {