From a6d9e07f95387ed6295136a14cbdaf5af78bc9d0 Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Fri, 21 Aug 2026 04:38:24 +0000 Subject: [PATCH 1/4] test(showcase): disarm the vitest console-forwarding teardown race (#10293, #10374) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit vitest 4.1.10's worker console ships every write to the main thread over RPC and discards the returned promise (`sendLog` in its console chunk). Teardown awaits a SNAPSHOT of in-flight calls (`rpcDone()`) and then rejects whatever is still pending, so a console.log emitted after that snapshot is rejected with EnvironmentTeardownError with no handler attached — an unhandled rejection, and vitest fails a run on an unhandled error even when every assertion passed. Reproduced deterministically-enough to measure: a fixture that leaves a console.log rescheduling past the end of its file reddens a 1-passed/1-passed run 8/10 times on an idle box. Turn the interception off for this app: with no RPC there is no pending call to reject, so no future leak can redden a green run this way. It is not a silencing — the non-TTY reporter already discards this app's passing-test console output after paying the round-trip, so writing it straight to stdout makes it visible for the first time. The pin spawns real vitest processes over the fixture: an ablation leg under vitest defaults that must still reproduce the harm, and a guarded leg under this app's real config that must exit 0. Both assert the fixture was collected, so a run that collected nothing cannot read as a pass. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01DdCnBGcHeufjrq7drTD3wt --- .changeset/tidy-pugs-repeat.md | 11 ++ .../leaked-console.test.ts | 34 ++++ .../vitest.unguarded.config.ts | 21 ++ .../test/vitest-console-teardown-race.test.ts | 180 ++++++++++++++++++ examples/app-showcase/vitest.config.ts | 55 +++++- 5 files changed, 300 insertions(+), 1 deletion(-) create mode 100644 .changeset/tidy-pugs-repeat.md create mode 100644 examples/app-showcase/test/fixtures/late-console-teardown/leaked-console.test.ts create mode 100644 examples/app-showcase/test/fixtures/late-console-teardown/vitest.unguarded.config.ts create mode 100644 examples/app-showcase/test/vitest-console-teardown-race.test.ts diff --git a/.changeset/tidy-pugs-repeat.md b/.changeset/tidy-pugs-repeat.md new file mode 100644 index 0000000000..1895872f33 --- /dev/null +++ b/.changeset/tidy-pugs-repeat.md @@ -0,0 +1,11 @@ +--- +--- + +Stop a `console.log` that outlives its test file from failing an otherwise-green +`@objectstack/example-showcase` run. vitest 4's worker forwards console output to the main +thread over RPC and discards the promise, so a log emitted inside the teardown window is +rejected with `EnvironmentTeardownError` that nobody handles — and vitest fails a run on an +unhandled error even with zero failed assertions, which dequeued three merge-queue PRs in one +afternoon. The suite now runs with vitest's own `disableConsoleIntercept`, which removes the +RPC the race needs, and a pin drives a deliberately leaking fixture through both legs so the +guard cannot be removed silently. Test harness only; no published package changes behaviour. diff --git a/examples/app-showcase/test/fixtures/late-console-teardown/leaked-console.test.ts b/examples/app-showcase/test/fixtures/late-console-teardown/leaked-console.test.ts new file mode 100644 index 0000000000..74276ab83c --- /dev/null +++ b/examples/app-showcase/test/fixtures/late-console-teardown/leaked-console.test.ts @@ -0,0 +1,34 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * FIXTURE — not part of this app's suite. + * + * `vitest.config.ts` excludes `test/fixtures/**`, so a normal + * `pnpm --filter @objectstack/example-showcase test` never collects this file. + * It is run only by `test/vitest-console-teardown-race.test.ts`, which spawns + * vitest against THIS directory as its root (at which point the exclude no + * longer matches, because the path is relative to the root being used). + * + * WHAT IT REPRODUCES. The file passes its one assertion and then leaves a + * `console.log` rescheduling itself past the end of the file — the shape #9371 + * had (a messaging dispatcher that outlived its test file) and the shape any + * leaked timer, poll or fire-and-forget write has. In a worker whose console is + * intercepted, each of those logs is an `onUserConsoleLog` RPC whose promise + * vitest discards, so one landing inside the teardown window is rejected with + * `EnvironmentTeardownError` and nobody holds it — an unhandled rejection, and + * vitest fails a run on an unhandled error even with zero failed assertions. + * + * ⛔ Do not "fix" the leak here. The leak IS the instrument. + */ + +import { it, expect } from 'vitest'; + +it('passes, and leaves a console.log rescheduling past the end of the file', () => { + const tick = (): void => { + console.log('late log from a callback that outlived the test file'); + setImmediate(tick).unref?.(); + }; + setImmediate(tick).unref?.(); + + expect(1).toBe(1); +}); diff --git a/examples/app-showcase/test/fixtures/late-console-teardown/vitest.unguarded.config.ts b/examples/app-showcase/test/fixtures/late-console-teardown/vitest.unguarded.config.ts new file mode 100644 index 0000000000..9ca7db41f7 --- /dev/null +++ b/examples/app-showcase/test/fixtures/late-console-teardown/vitest.unguarded.config.ts @@ -0,0 +1,21 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * The ABLATION leg of `test/vitest-console-teardown-race.test.ts`. + * + * `disableConsoleIntercept: false` is vitest's own default, spelled out here + * rather than left implicit: this config exists to state that the ONE variable + * between the two legs is the guard, and to keep the leg honest if the default + * ever changes upstream. It deliberately does not extend the app's real config + * — the fixture imports nothing from the workspace, so the app's aliases and + * excludes cannot affect the measurement, and re-exporting a config that reads + * `__dirname` from a different directory would silently repoint them. + */ + +import { defineConfig } from 'vitest/config'; + +export default defineConfig({ + test: { + disableConsoleIntercept: false, + }, +}); diff --git a/examples/app-showcase/test/vitest-console-teardown-race.test.ts b/examples/app-showcase/test/vitest-console-teardown-race.test.ts new file mode 100644 index 0000000000..c3397c95bc --- /dev/null +++ b/examples/app-showcase/test/vitest-console-teardown-race.test.ts @@ -0,0 +1,180 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * [#10293 / #10374] A green suite must not be reddened by a console.log that + * outlives its test file. + * + * THE DEFECT, read out of the installed vitest (4.1.10). The worker replaces + * `console` with one that forwards every write to the main thread over RPC, and + * `sendLog` in `packages/vitest/dist/chunks/console.*.js` DISCARDS the promise + * that forwarding returns. Teardown in `packages/vitest/dist/chunks/init.*.js` + * then runs `await rpcDone()` and, immediately after, a cleanup that calls + * `rpc.$rejectPendingCalls(...)` — and `rpcDone()` awaits a SNAPSHOT + * (`Array.from(promises)`) taken at the moment it is called. Any console RPC + * created after that snapshot is still pending when the rejection sweep runs, + * is rejected with `EnvironmentTeardownError`, and — because `sendLog` kept no + * reference — nobody handles it. vitest fails a run on an unhandled error even + * when no assertion failed, so the signature is a fully green suite exiting 1: + * + * Test Files 21 passed (21) + * Tests 342 passed (342) + * Errors 1 error + * EnvironmentTeardownError: [vitest-worker]: Closing rpc while + * "onUserConsoleLog" was pending + * + * That is what evicted PRs from the merge queue three times in one afternoon: + * the dequeue forces every speculative build behind the PR to rebuild. + * + * WHY IT READS AS LOAD-DEPENDENT. The window is exactly the duration of + * `rpcDone()` — the time to drain the RPC round-trips already in flight. Idle + * that is about a millisecond; on a saturated runner it is wide enough for a + * leaked timer, poll or fire-and-forget write to log inside it. Nothing about + * the code under test changes between the green run and the red one, which is + * why the two reproductions before this one both concluded "cannot reproduce". + * + * WHAT THIS PIN ASSERTS, and why it spawns vitest instead of asserting inline. + * The failure happens during worker teardown, i.e. strictly AFTER every test in + * the file has finished — no assertion inside the affected file can observe it, + * and the only visible symptom is the process exit code. So the pin drives a + * real vitest process over a fixture that deliberately leaks a logging callback + * (`test/fixtures/late-console-teardown/`) and reads the exit code: + * + * - the ABLATION leg runs it under vitest's defaults and requires the harm to + * still reproduce — a positive control, so this pin can never go quietly + * green because the fixture stopped provoking anything; + * - the GUARDED leg runs the SAME fixture under this app's real + * `vitest.config.ts` and requires exit 0. + * + * Delete `disableConsoleIntercept: true` from that config and the guarded leg + * turns red. Both legs also assert `Test Files 1 passed (1)`, because a run + * that collected NOTHING exits 0 too and would read as a pass. + * + * ⚠️ The ablation is a race, not a certainty: measured 8/10, 10/12 and 9/12 on + * an idle 4-vCPU container across three fixture shapes. It is therefore + * retried, and only the exhaustion of every attempt is a failure — reported as + * "the instrument stopped reproducing", never as "the guard broke". + */ + +import { describe, it, expect } from 'vitest'; +import { spawnSync } from 'node:child_process'; +import { dirname, resolve } from 'node:path'; +import { existsSync } from 'node:fs'; +import { fileURLToPath } from 'node:url'; + +const HERE = dirname(fileURLToPath(import.meta.url)); + +const VITEST_BIN = resolve(HERE, '../node_modules/.bin/vitest'); +const APP_CONFIG = resolve(HERE, '../vitest.config.ts'); +const FIXTURE_ROOT = resolve(HERE, 'fixtures/late-console-teardown'); +const ABLATION_CONFIG = resolve(FIXTURE_ROOT, 'vitest.unguarded.config.ts'); + +/** The exact message vitest 4.1.10 rejects a pending console RPC with. */ +const TEARDOWN_ERROR = 'Closing rpc while "onUserConsoleLog" was pending'; + +/** Attempts allowed to the ablation leg before it is declared broken. */ +const ABLATION_ATTEMPTS = 8; +/** Repetitions of the guarded leg. A removed guard reproduces ~80% per run. */ +const GUARDED_REPETITIONS = 4; + +interface Leg { + readonly status: number | null; + readonly output: string; + readonly reproduced: boolean; + readonly collectedOneFile: boolean; +} + +/** + * `-c` is resolved RELATIVE TO `--root`, so both paths are absolute here; a + * relative config path silently becomes `/` and the run dies in + * config loading rather than measuring anything. + * + * The child's environment drops vitest's own worker variables: this process IS + * a vitest worker, and leaking `VITEST_POOL_ID` / `VITEST_WORKER_ID` into a + * nested run makes the child believe it was spawned by a pool. + */ +function runFixture(config: string): Leg { + const env: NodeJS.ProcessEnv = { ...process.env }; + for (const key of Object.keys(env)) { + if (key.startsWith('VITEST')) delete env[key]; + } + delete env.NODE_V8_COVERAGE; + + const result = spawnSync(VITEST_BIN, ['run', '-c', config, '--root', FIXTURE_ROOT], { + encoding: 'utf8', + timeout: 120_000, + env, + }); + + const output = `${result.stdout ?? ''}${result.stderr ?? ''}`; + return { + status: result.status, + output, + reproduced: output.includes(TEARDOWN_ERROR), + collectedOneFile: /Test Files\s+1 passed \(1\)/.test(output), + }; +} + +describe('[#10293] vitest console-forwarding teardown race', () => { + it('has a fixture and an ablation config to measure against', () => { + expect(existsSync(VITEST_BIN), `vitest binary missing at ${VITEST_BIN}`).toBe(true); + expect(existsSync(resolve(FIXTURE_ROOT, 'leaked-console.test.ts'))).toBe(true); + expect(existsSync(ABLATION_CONFIG)).toBe(true); + }); + + it( + 'ABLATION: the fixture still reddens a green run under vitest defaults', + { timeout: 240_000 }, + () => { + const attempts: Leg[] = []; + for (let i = 0; i < ABLATION_ATTEMPTS; i++) { + const leg = runFixture(ABLATION_CONFIG); + attempts.push(leg); + if (leg.reproduced) break; + } + + // A run that collected no test file exits 0 and would read as "the harm + // is gone". Grade collection before grading the harm. + expect( + attempts.every((leg) => leg.collectedOneFile), + 'the fixture was not collected — the ablation measured nothing', + ).toBe(true); + + const reproduced = attempts.find((leg) => leg.reproduced); + expect( + reproduced, + `the instrument stopped reproducing: ${attempts.length} attempts under vitest ` + + `defaults produced no "${TEARDOWN_ERROR}". Either vitest changed its console ` + + `forwarding (check sendLog/rpcDone in its dist chunks) or the fixture stopped ` + + `leaking. Do NOT relax the guarded leg on the strength of this.`, + ).toBeDefined(); + + // Every assertion in the fixture passed, and the run still failed. That + // conjunction is the whole defect. + expect(reproduced?.status).not.toBe(0); + expect(reproduced?.output).toContain('Tests 1 passed (1)'); + }, + ); + + it( + 'GUARDED: the same fixture exits 0 under this app’s real vitest config', + { timeout: 240_000 }, + () => { + const legs = Array.from({ length: GUARDED_REPETITIONS }, () => runFixture(APP_CONFIG)); + + expect( + legs.every((leg) => leg.collectedOneFile), + 'the fixture was not collected under the app config — this leg measured nothing', + ).toBe(true); + + const teardownErrors = legs.filter((leg) => leg.reproduced); + expect( + teardownErrors.length, + `${teardownErrors.length}/${legs.length} runs hit the teardown race under the app's ` + + `own config. If disableConsoleIntercept was removed from vitest.config.ts, restore ` + + `it — the docblock there explains why.\n${teardownErrors[0]?.output ?? ''}`, + ).toBe(0); + + expect(legs.map((leg) => leg.status)).toEqual(legs.map(() => 0)); + }, + ); +}); diff --git a/examples/app-showcase/vitest.config.ts b/examples/app-showcase/vitest.config.ts index d677b284f6..2192b1cdce 100644 --- a/examples/app-showcase/vitest.config.ts +++ b/examples/app-showcase/vitest.config.ts @@ -39,6 +39,59 @@ export default defineConfig({ ], }, test: { - exclude: [...configDefaults.exclude, '**/e2e/**'], + // `test/fixtures/**` holds the deliberately-broken inputs that + // `test/vitest-console-teardown-race.test.ts` spawns vitest against. They + // are `*.test.ts` on purpose — that pin runs them with vitest's DEFAULT + // include and this very config, only with the fixture directory as `root`, + // at which point this exclude no longer matches them (it is evaluated + // against the path relative to the root in use). Collecting them here + // instead would import a leaked-console-log fixture into the app's own + // suite, i.e. arm the exact flake the pin exists to keep disarmed. + exclude: [...configDefaults.exclude, '**/e2e/**', 'test/fixtures/**'], + + // ⛔ Do not remove without reading `test/vitest-console-teardown-race.test.ts` + // — that pin fails when this is off, and its ablation leg is what proves it. + // + // THE DEFECT (#10293, mechanism in #10374). vitest 4's worker replaces + // `console` with one that ships every write to the main thread over RPC. + // In `packages/vitest/dist/chunks/console.*.js`: + // + // state().rpc.onUserConsoleLog({ type, content, taskId, ... }); + // + // — the returned promise is DISCARDED. Teardown, in + // `packages/vitest/dist/chunks/init.*.js`, then does + // `await rpcDone()` followed by `$rejectPendingCalls(...)`, and `rpcDone()` + // awaits a SNAPSHOT (`Array.from(promises)`) taken when it is called. A + // console RPC created after that snapshot is still pending when + // `$rejectPendingCalls` runs, is rejected with `EnvironmentTeardownError`, + // and — because nobody kept the promise — surfaces as an UNHANDLED + // rejection. vitest fails a run on an unhandled error even when every + // assertion passed, so the observed signature is a green suite that exits + // 1: `Test Files 21 passed (21) / Tests 342 passed (342) / Errors 1 error`. + // Measured cost when it lands in the merge queue: the PR is dequeued and + // every speculative build behind it rebuilds. + // + // WHY THE WINDOW IS LOAD-DEPENDENT, which is why it reads as a flake: the + // window is the duration of `rpcDone()`, i.e. the time to complete the RPC + // round-trips already in flight. Idle that is ~1ms; on a saturated runner + // it is long enough for a leaked timer or poll to log inside it. Nothing + // about the code under test changes. + // + // WHY THIS SETTING AND NOT A QUIETER SUITE. Turning the interception off is + // vitest's own supported option, and it removes the MECHANISM rather than + // narrowing the trigger: with no RPC there is no pending call to reject, so + // no leak in any future test can redden a green run this way. It is also + // not a silencing: vitest's non-TTY default reporter sets + // `silent: 'passed-only'`, so today this app's console output from passing + // tests is discarded AFTER paying the round-trip. Written straight to the + // worker's stdout it is visible for the first time. Measured on this suite: + // 72 `onUserConsoleLog` calls per run, all currently discarded. + // + // WHAT IT COSTS. Console output loses vitest's `stdout | file > test` + // attribution header and its per-task buffering, so it interleaves in + // arrival order across forks — which is already how the bulk of this app's + // test output behaves, because ObjectQL's logger writes to `process.stdout` + // directly and never went through this path at all. + disableConsoleIntercept: true, }, }); From acb040920f77b90cf9f625996b9e28be4fa8425d Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Fri, 21 Aug 2026 04:51:02 +0000 Subject: [PATCH 2/4] test(showcase): fit the teardown-race pin to the package's own type surface MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This package deliberately ships without @types/node (types/node-shim.d.ts, and the tsconfig note explaining why vitest.config.ts is kept out of `include`), and compiles as CommonJS under module: NodeNext — so `import.meta.url` is rejected outright by `tsc --noEmit` with TS1470, and `process.env` is not on the shimmed `process`. Seed paths from `process.cwd()`, which is what test/coverage.test.ts and test/inert-wirings.test.ts already use and what the shim is cut for, and widen the shim by exactly the two members the pin needs: a synchronous-only `spawnSync` with the three result fields it reads, and `process.env`. Also correct the measured cost recorded in vitest.config.ts: the 72 onUserConsoleLog calls per run carry batched buffers, so the visible log grows by 285 lines, not 72. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01DdCnBGcHeufjrq7drTD3wt --- .../test/vitest-console-teardown-race.test.ts | 21 ++++++++++-------- examples/app-showcase/types/node-shim.d.ts | 22 ++++++++++++++++++- examples/app-showcase/vitest.config.ts | 7 +++++- 3 files changed, 39 insertions(+), 11 deletions(-) diff --git a/examples/app-showcase/test/vitest-console-teardown-race.test.ts b/examples/app-showcase/test/vitest-console-teardown-race.test.ts index c3397c95bc..9bc1b4ab25 100644 --- a/examples/app-showcase/test/vitest-console-teardown-race.test.ts +++ b/examples/app-showcase/test/vitest-console-teardown-race.test.ts @@ -57,16 +57,19 @@ import { describe, it, expect } from 'vitest'; import { spawnSync } from 'node:child_process'; -import { dirname, resolve } from 'node:path'; import { existsSync } from 'node:fs'; -import { fileURLToPath } from 'node:url'; -const HERE = dirname(fileURLToPath(import.meta.url)); +// `process.cwd()` is this package's established seed for its own files +// (`test/coverage.test.ts`, `test/inert-wirings.test.ts`) and the one the +// `types/node-shim.d.ts` surface is cut for. `import.meta.url` is NOT available +// here: this package compiles as CommonJS under `module: NodeNext`, so +// `tsc --noEmit` rejects it with TS1470. +const PACKAGE_ROOT = process.cwd(); -const VITEST_BIN = resolve(HERE, '../node_modules/.bin/vitest'); -const APP_CONFIG = resolve(HERE, '../vitest.config.ts'); -const FIXTURE_ROOT = resolve(HERE, 'fixtures/late-console-teardown'); -const ABLATION_CONFIG = resolve(FIXTURE_ROOT, 'vitest.unguarded.config.ts'); +const VITEST_BIN = `${PACKAGE_ROOT}/node_modules/.bin/vitest`; +const APP_CONFIG = `${PACKAGE_ROOT}/vitest.config.ts`; +const FIXTURE_ROOT = `${PACKAGE_ROOT}/test/fixtures/late-console-teardown`; +const ABLATION_CONFIG = `${FIXTURE_ROOT}/vitest.unguarded.config.ts`; /** The exact message vitest 4.1.10 rejects a pending console RPC with. */ const TEARDOWN_ERROR = 'Closing rpc while "onUserConsoleLog" was pending'; @@ -93,7 +96,7 @@ interface Leg { * nested run makes the child believe it was spawned by a pool. */ function runFixture(config: string): Leg { - const env: NodeJS.ProcessEnv = { ...process.env }; + const env: Record = { ...process.env }; for (const key of Object.keys(env)) { if (key.startsWith('VITEST')) delete env[key]; } @@ -117,7 +120,7 @@ function runFixture(config: string): Leg { describe('[#10293] vitest console-forwarding teardown race', () => { it('has a fixture and an ablation config to measure against', () => { expect(existsSync(VITEST_BIN), `vitest binary missing at ${VITEST_BIN}`).toBe(true); - expect(existsSync(resolve(FIXTURE_ROOT, 'leaked-console.test.ts'))).toBe(true); + expect(existsSync(`${FIXTURE_ROOT}/leaked-console.test.ts`)).toBe(true); expect(existsSync(ABLATION_CONFIG)).toBe(true); }); diff --git a/examples/app-showcase/types/node-shim.d.ts b/examples/app-showcase/types/node-shim.d.ts index 04fac89b2d..afbbd8a343 100644 --- a/examples/app-showcase/types/node-shim.d.ts +++ b/examples/app-showcase/types/node-shim.d.ts @@ -31,4 +31,24 @@ declare module 'node:path' { export function dirname(path: string): string; } -declare const process: { cwd(): string }; +// `test/vitest-console-teardown-race.test.ts` drives a real vitest process over +// a fixture, because the defect it pins (a console RPC rejected during worker +// teardown) is only observable as the child's EXIT CODE — it happens after every +// test in the file has finished, so no in-process assertion can see it. +// Narrowed to the synchronous form and to the three result members that pin +// reads: it must not grow into the whole `child_process` surface. +declare module 'node:child_process' { + export function spawnSync( + command: string, + args: readonly string[], + options: { + encoding: 'utf8'; + timeout?: number; + env?: Record; + }, + ): { status: number | null; stdout: string | null; stderr: string | null }; +} + +// `env` joins `cwd()` for the same pin: the nested run must NOT inherit this +// process's own `VITEST_*` variables, or the child believes a pool spawned it. +declare const process: { cwd(): string; env: Record }; diff --git a/examples/app-showcase/vitest.config.ts b/examples/app-showcase/vitest.config.ts index 2192b1cdce..3a1cb1f977 100644 --- a/examples/app-showcase/vitest.config.ts +++ b/examples/app-showcase/vitest.config.ts @@ -85,7 +85,12 @@ export default defineConfig({ // `silent: 'passed-only'`, so today this app's console output from passing // tests is discarded AFTER paying the round-trip. Written straight to the // worker's stdout it is visible for the first time. Measured on this suite: - // 72 `onUserConsoleLog` calls per run, all currently discarded. + // 72 `onUserConsoleLog` calls per run — each carrying a batched buffer, so + // 285 lines — every one of them discarded before this change. That is the + // honest cost too: this app's share of a Test Core log grows by those 285 + // lines (~0.9% of a 31,839-line shard log), most of it `[Registry]` + // registration chatter. Quieting THAT is a separate question about + // `@objectstack/objectql`'s own default log level, not about this setting. // // WHAT IT COSTS. Console output loses vitest's `stdout | file > test` // attribution header and its per-task buffering, so it interleaves in From b13c4fad075530afb822410cac16be9e25f4db02 Mon Sep 17 00:00:00 2001 From: "claude[bot]" <209825114+claude[bot]@users.noreply.github.com> Date: Fri, 21 Aug 2026 04:54:58 +0000 Subject: [PATCH 3/4] chore: drop the empty changeset in favour of the skip-changeset label MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `pnpm check:empty-changeset` refuses an empty-frontmatter changeset outright, and its reasoning applies exactly here: this PR touches `examples/` and tests only, so it releases nothing, while an empty changeset is still a REAL input to changesets/action — an all-empty pending set makes the action print "All changesets are empty; not creating PR" and return green, which is how 17.0.0-rc.2 stalled silently. Route 2 it is: no changeset, `skip-changeset` label on the PR. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01DdCnBGcHeufjrq7drTD3wt --- .changeset/tidy-pugs-repeat.md | 11 ----------- 1 file changed, 11 deletions(-) delete mode 100644 .changeset/tidy-pugs-repeat.md diff --git a/.changeset/tidy-pugs-repeat.md b/.changeset/tidy-pugs-repeat.md deleted file mode 100644 index 1895872f33..0000000000 --- a/.changeset/tidy-pugs-repeat.md +++ /dev/null @@ -1,11 +0,0 @@ ---- ---- - -Stop a `console.log` that outlives its test file from failing an otherwise-green -`@objectstack/example-showcase` run. vitest 4's worker forwards console output to the main -thread over RPC and discards the promise, so a log emitted inside the teardown window is -rejected with `EnvironmentTeardownError` that nobody handles — and vitest fails a run on an -unhandled error even with zero failed assertions, which dequeued three merge-queue PRs in one -afternoon. The suite now runs with vitest's own `disableConsoleIntercept`, which removes the -RPC the race needs, and a pin drives a deliberately leaking fixture through both legs so the -guard cannot be removed silently. Test harness only; no published package changes behaviour. From d88f4445d1455ecfa48afdb974a94b1edfa014da Mon Sep 17 00:00:00 2001 From: Claude Date: Fri, 21 Aug 2026 05:39:14 +0000 Subject: [PATCH 4/4] test(showcase): read the nested vitest run from plain bytes, not coloured prose MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The teardown-race pin scraped the child's human reporter output for `Test Files 1 passed (1)`. vitest 4 colourises that line on any machine std-env does not classify as an agent shell, so the escapes land between `Test Files` and its count and the regex can never match on CI — while it matches for the author, whose shell sets AI_AGENT/CLAUDECODE and makes vitest call disableDefaultColors() and pick the `agent` reporter. Pin the child to plain output (NO_COLOR, no FORCE_COLOR, an explicitly named reporter), strip ANSI from the captured bytes before any predicate reads them, and print each graded child's exit status and output tail so a CI-only collection failure is diagnosable from the log it fails in. --- .../test/vitest-console-teardown-race.test.ts | 83 +++++++++++++++++-- examples/app-showcase/types/node-shim.d.ts | 9 ++ 2 files changed, 83 insertions(+), 9 deletions(-) diff --git a/examples/app-showcase/test/vitest-console-teardown-race.test.ts b/examples/app-showcase/test/vitest-console-teardown-race.test.ts index 9bc1b4ab25..44c9592133 100644 --- a/examples/app-showcase/test/vitest-console-teardown-race.test.ts +++ b/examples/app-showcase/test/vitest-console-teardown-race.test.ts @@ -53,11 +53,26 @@ * an idle 4-vCPU container across three fixture shapes. It is therefore * retried, and only the exhaustion of every attempt is a failure — reported as * "the instrument stopped reproducing", never as "the guard broke". + * + * ⚠️ WHY THE CHILD'S OUTPUT IS NORMALISED BEFORE ANYTHING READS IT. Every + * predicate below is a substring of a REPORTER line, and vitest 4 decides both + * the colour and the reporter from the environment it finds itself in: + * `std-env`'s `isAgent` — true when `AI_AGENT`, `CLAUDECODE` and friends are + * set, i.e. in the shell an agent authors this from — makes it call + * tinyrainbow's `disableDefaultColors()` and select the `agent` reporter. A CI + * runner has none of those variables, so the SAME summary line arrives with + * escapes sitting BETWEEN `Test Files` and its count, and a regex written + * against the plain line matches in an agent shell and can never match in CI. + * Measured, on this pin's own first red: the anti-vacuity guard below refused + * to grade a run it could not read, and was right to. So the child is asked for + * plain bytes AND the captured text is stripped before it is read — the guard + * is never the thing that bends. */ import { describe, it, expect } from 'vitest'; import { spawnSync } from 'node:child_process'; import { existsSync } from 'node:fs'; +import { stripVTControlCharacters } from 'node:util'; // `process.cwd()` is this package's established seed for its own files // (`test/coverage.test.ts`, `test/inert-wirings.test.ts`) and the one the @@ -81,6 +96,7 @@ const GUARDED_REPETITIONS = 4; interface Leg { readonly status: number | null; + /** The child's combined stdout+stderr, ALREADY stripped of ANSI escapes. */ readonly output: string; readonly reproduced: boolean; readonly collectedOneFile: boolean; @@ -94,6 +110,20 @@ interface Leg { * The child's environment drops vitest's own worker variables: this process IS * a vitest worker, and leaking `VITEST_POOL_ID` / `VITEST_WORKER_ID` into a * nested run makes the child believe it was spawned by a pool. + * + * It also pins the child to PLAIN, ENVIRONMENT-INDEPENDENT output, for the + * reason in this file's docblock: + * - `NO_COLOR` is the one switch tinyrainbow short-circuits on, ahead of + * every enabling condition, so it turns colour off wherever the child runs. + * `FORCE_COLOR` is DELETED rather than set to `'0'`, because tinyrainbow + * tests its PRESENCE (`'FORCE_COLOR' in env`) — the disabling spelling + * would have switched colour ON. + * - `--reporter=default` NAMES the reporter instead of letting vitest pick it + * from `isAgent`, which is how the author and CI came to read two different + * summary formats out of the same fixture. + * Then `stripVTControlCharacters` runs over the captured bytes anyway: belt and + * braces, so an escape arriving from some other source cannot quietly + * un-measure this pin the way one already did. */ function runFixture(config: string): Leg { const env: Record = { ...process.env }; @@ -101,14 +131,20 @@ function runFixture(config: string): Leg { if (key.startsWith('VITEST')) delete env[key]; } delete env.NODE_V8_COVERAGE; + delete env.FORCE_COLOR; + env.NO_COLOR = '1'; + + const result = spawnSync( + VITEST_BIN, + ['run', '-c', config, '--root', FIXTURE_ROOT, '--reporter=default'], + { + encoding: 'utf8', + timeout: 120_000, + env, + }, + ); - const result = spawnSync(VITEST_BIN, ['run', '-c', config, '--root', FIXTURE_ROOT], { - encoding: 'utf8', - timeout: 120_000, - env, - }); - - const output = `${result.stdout ?? ''}${result.stderr ?? ''}`; + const output = stripVTControlCharacters(`${result.stdout ?? ''}${result.stderr ?? ''}`); return { status: result.status, output, @@ -117,6 +153,33 @@ function runFixture(config: string): Leg { }; } +/** + * The anti-vacuity guards below grade the CHILD, whose output is captured and + * therefore never reaches the job log on its own. Saying only "measured + * nothing" leaves a CI-only failure undiagnosable from the log it fails in — + * measured, at the cost of one round trip. So every graded run names its exit + * status and shows the tail of what it actually wrote. + * + * Bounded at three runs and fifteen lines each: a leg can grade eight, and when + * they fail they fail the same way, so an unbounded dump buries the one thing + * being read in seven copies of itself. + */ +const DESCRIBED_RUNS = 3; + +function describeRuns(legs: readonly Leg[]): string { + const blocks = legs.slice(0, DESCRIBED_RUNS).map((leg, index) => { + const tail = leg.output.trimEnd().split('\n').slice(-15).join('\n'); + return ( + `\n--- child run ${index + 1}/${legs.length}: exit=${leg.status}, ` + + `collectedOneFile=${leg.collectedOneFile}, reproduced=${leg.reproduced}\n` + + `${tail === '' ? '(the child wrote nothing at all)' : tail}` + ); + }); + const elided = legs.length - blocks.length; + if (elided > 0) blocks.push(`\n--- ${elided} further run(s) not shown`); + return blocks.join('\n'); +} + describe('[#10293] vitest console-forwarding teardown race', () => { it('has a fixture and an ablation config to measure against', () => { expect(existsSync(VITEST_BIN), `vitest binary missing at ${VITEST_BIN}`).toBe(true); @@ -139,7 +202,8 @@ describe('[#10293] vitest console-forwarding teardown race', () => { // is gone". Grade collection before grading the harm. expect( attempts.every((leg) => leg.collectedOneFile), - 'the fixture was not collected — the ablation measured nothing', + `the fixture was not collected — the ablation measured nothing. What the ` + + `child runs actually wrote:${describeRuns(attempts)}`, ).toBe(true); const reproduced = attempts.find((leg) => leg.reproduced); @@ -166,7 +230,8 @@ describe('[#10293] vitest console-forwarding teardown race', () => { expect( legs.every((leg) => leg.collectedOneFile), - 'the fixture was not collected under the app config — this leg measured nothing', + `the fixture was not collected under the app config — this leg measured ` + + `nothing. What the child runs actually wrote:${describeRuns(legs)}`, ).toBe(true); const teardownErrors = legs.filter((leg) => leg.reproduced); diff --git a/examples/app-showcase/types/node-shim.d.ts b/examples/app-showcase/types/node-shim.d.ts index afbbd8a343..74d0858736 100644 --- a/examples/app-showcase/types/node-shim.d.ts +++ b/examples/app-showcase/types/node-shim.d.ts @@ -49,6 +49,15 @@ declare module 'node:child_process' { ): { status: number | null; stdout: string | null; stderr: string | null }; } +// Same pin, one member: it reads the child's reporter output, and vitest +// colourises that output on any machine `std-env` does not recognise as an +// agent shell. Stripping is delegated to the platform rather than to a +// hand-written escape regex, which would have to spell control characters in +// repo source (`pnpm check:nul-bytes`'s territory). +declare module 'node:util' { + export function stripVTControlCharacters(str: string): string; +} + // `env` joins `cwd()` for the same pin: the nested run must NOT inherit this // process's own `VITEST_*` variables, or the child believes a pool spawned it. declare const process: { cwd(): string; env: Record };