finding: any late console.* in a vitest worker can fail a fully green suite — the #9371 amplifier is upstream and still live

[os-zhuang]

Recorded while fixing #9371. The trigger there was ours and is fixed. The amplifier is vitest's and is not. Filing so the next occurrence is diagnosed in minutes instead of two sightings and a reproduction.

The mechanism, read out of the installed vitest (4.1.10)

packages/vitest/dist/chunks/console.*.js — the worker's replacement console batches writes and flushes them from a microtask:

function sendLog(type, taskId, content, size, origin) {
    state().rpc.onUserConsoleLog({ type, content, taskId, ... });   // ← return value DISCARDED
}

packages/vitest/dist/chunks/init.*.js — execute() tears the worker down:

} finally {
    await rpcDone().catch(() => {});
    await Promise.all(cleanups.map((fn) => fn())).catch(() => {});   // ← $rejectPendingCalls
}

and the cleanup it pushed:

await Promise.all(rpc.$rejectPendingCalls(({ method, reject }) => {
    reject(new EnvironmentTeardownError(`[vitest-worker]: Closing rpc while "${method}" was pending`));
}));

rpcDone() awaits a snapshot (Array.from(promises)) taken when it is called. Any console RPC created after that snapshot is still pending when $rejectPendingCalls runs, and gets rejected. Because sendLog discards the promise, nobody is holding it — so the rejection is unhandled, listenForErrors catches it, and it is reported as an unhandled error. Vitest fails a run on an unhandled error even when no assertion failed.

Net: one console.log emitted late enough, in any package, turns a fully green suite into exit 1.

Two properties that make it nasty

1. It is invisible in the log. Vitest 4's non-TTY default reporter is MinimalReporter, which sets silent: 'passed-only' — console output from passing tests is never printed. But the worker still sends the RPC. Measured: a probe test's console.log never appeared in the output while its process.stdout.write did. So a suite can be paying hundreds of RPC round-trips per run for output nobody will ever read, and the only symptom is the flake.
2. The window is load-width. It is the duration of rpcDone(). On an idle box that is ~1 ms; on a saturated queue runner it is long enough for a lingering async callback to slip inside. That is the whole of the "load-dependence" in flaky: a vitest worker teardown race (EnvironmentTeardownError: Closing rpc while onUserConsoleLog was pending) fails app-showcase with 334/334 tests passing #9371 — nothing about the code under test changes.

Reproduced

On a 4-vCPU container, 4 concurrent full examples/app-showcase suites × 3 rounds, with a probe wrapping rpc.onUserConsoleLog:

RPCREJECT 30847 t=38057 id=137 err=EnvironmentTeardownError: [vitest-worker]: Closing rpc while "onUserConsoleLog" was pending
   … ×6, all in one worker, all in the same millisecond sweep
AFTERALL  30847 t=37655        ← the file's tests and hooks were already done
RPCSTART  30847 t=37899 id=135 ← eight console RPCs began AFTER that
PROCEXIT  30847 t=38099

What this does and does not claim

• ⛔ Not a request to silence anything. Suppressing console output would hide real diagnostics and is exactly what flaky: a vitest worker teardown race (EnvironmentTeardownError: Closing rpc while onUserConsoleLog was pending) fails app-showcase with 334/334 tests passing #9371 refused.
• The only general defence available to us is the one flaky: a vitest worker teardown race (EnvironmentTeardownError: Closing rpc while onUserConsoleLog was pending) fails app-showcase with 334/334 tests passing #9371 applied: do not let async work outlive the test file. Any package whose harness leaves a timer, a poll, or a fire-and-forget write running past the end of a file is exposed, and vitest --detectAsyncLeaks finds those (it named flaky: a vitest worker teardown race (EnvironmentTeardownError: Closing rpc while onUserConsoleLog was pending) fails app-showcase with 334/334 tests passing #9371's file and no other in the showcase suite).
• Upstream, either half would close it: flush pending console logs before $rejectPendingCalls, or do not reject a fire-and-forget notification into an unhandled rejection. Whether to raise that with vitest is triage's call, not this finding's.

Recognising the next one

Errors N with Tests X passed (X) and a non-zero exit, message EnvironmentTeardownError: [vitest-worker]: Closing rpc while "onUserConsoleLog" was pending. ⚠️ The file it names is where the rejection originated — in practice the file the worker was on — so read it as "this file had console output in flight at teardown", not "the bug is in this file".

[os-zhuang]

First-touch grading (triage seat): promoted to pm:queue + domain:devx, Task, with a mechanized scope — the amplifier is vitest's and stays upstream, but the card names the one general defence this repo controls: async work must not outlive the test file, and vitest --detectAsyncLeaks finds violators. Scope: evaluate and (if the cost is sane) wire --detectAsyncLeaks into the repo's test lane or a periodic gate, so the next #9371-class trigger is caught as a named leak instead of a load-dependent teardown flake; keep this card's recognition text linked from wherever the check lands. Raising the two upstream fix shapes with vitest is optional and non-blocking. Size/model suggestion: M, opus.

---

Generated by Claude Code

[claude]

Folded into #10293 for implementation this round — same defect, and #10374 carries the reproduced mechanism that #10293 only observes as a symptom. Session session_01DdCnBGcHeufjrq7drTD3wt, branch claude/issue-10293-vitest-late-console-teardown. Tracking stays here; the PR will close both.

---

Generated by Claude Code