Milestone v1 (v2.0.0): Mokosh — Session Capture #1
82
.planning/debug/resolved/01-10-vitest-build-test-timeout.md
Normal file
82
.planning/debug/resolved/01-10-vitest-build-test-timeout.md
Normal file
@@ -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
|
||||||
@@ -244,6 +244,13 @@ async function runProductionBuild(): Promise<void> {
|
|||||||
}
|
}
|
||||||
|
|
||||||
describe('production bundle has no test-hook leaks (Tier-1 gate — T-1-11-01)', () => {
|
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 () => {
|
it('npm run build completes and dist/ exists with at least one chunk', async () => {
|
||||||
if (process.env.SKIP_BUILD !== '1') {
|
if (process.env.SKIP_BUILD !== '1') {
|
||||||
await runProductionBuild();
|
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 ` +
|
`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.`,
|
`regression class than a hook leak. Investigate before proceeding to the hook-leak assertion.`,
|
||||||
).toBeGreaterThan(0);
|
).toBeGreaterThan(0);
|
||||||
});
|
}, 30_000);
|
||||||
|
|
||||||
for (const needle of FORBIDDEN_HOOK_STRINGS) {
|
for (const needle of FORBIDDEN_HOOK_STRINGS) {
|
||||||
it(`production bundle does not contain '${needle}' (T-1-11-01 surface)`, () => {
|
it(`production bundle does not contain '${needle}' (T-1-11-01 surface)`, () => {
|
||||||
|
|||||||
Reference in New Issue
Block a user