From ef30e59860ecf3d9c536a1cf6c1d96f65677330d Mon Sep 17 00:00:00 2001 From: Tom Boucher Date: Sun, 6 Sep 2026 21:06:48 -0400 Subject: [PATCH] fix(#4448): stop io.test.cjs's in-process runMain calls from corrupting node:test's own fd-1 IPC (#4452) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit tests/io.test.cjs's "review fix: pending-outcome cell lifetime" describe block deliberately drives runMain()/output() in-process (needed to observe a cross-invocation state leak) instead of via a subprocess. output() ends with a raw synchronous fs.writeSync(1, ...) to the real stdout fd, and Node's --test-isolation=process (default since Node 22) uses that same fd for the file's own parent-child reporter protocol. The two writes racing produced an intermittent "Unable to deserialize cloned data" that killed the whole file — observed twice on next's macOS lane, most recently on the commit that merged PR #4428 (unrelated to that PR's content; io.test.cjs isn't part of its diff). Empirically validated locally (gsd-test can't reach macOS): built a repro loop running N parallel copies of `node --test tests/io.test.cjs` to recreate CI-like contention. Baseline: ~13-17% of runs hit the corruption (12/90, 15/90 across two samples). A first fix attempt wrapped the writes in captureFdAsync (an await-aware twin of the existing captureFdSync, added because runMain() defers main() through a microtask chain, so a synchronous wrap restores before the real write fires) — but captureFdAsync always forwards to the real fs.writeSync by design (matching captureFdSync's "never swallow" contract, tests/helpers.cjs, #4306). Re-ran the same loop against that fix: 15/90, statistically unchanged. Forwarding the write doesn't stop it from reaching the fd node:test's own IPC also uses. Replaced it with suppressFdAsync: a narrow, deliberate exception to the never-swallow contract for a window the caller has verified is fully controlled (a single runMain() call plus its promise-chain settling, where nothing else can legitimately need that fd). It records the bytes for the test's own assertions but never lets them reach the real fd. Re-ran the loop: 0/300 across three samples (90+120+90), including one round at 8-way parallelism. Also caught and fixed a real bug surfaced by the same loop: the new regression assertion checked for compact-JSON `"error":"x"` but output() pretty-prints, so it failed 100% of runs deterministically until fixed to parse and check the structured value instead (io.test.cjs, matching this repo's "assert on structured output, not raw text" convention). Co-authored-by: sim Co-authored-by: Claude Sonnet 5 --- tests/helpers.cjs | 70 +++++++++++++++++++++++++++++++++++++++- tests/io.test.cjs | 81 +++++++++++++++++++++++++++++++++-------------- 2 files changed, 127 insertions(+), 24 deletions(-) diff --git a/tests/helpers.cjs b/tests/helpers.cjs index 9ffe7382d..6f54da5a3 100644 --- a/tests/helpers.cjs +++ b/tests/helpers.cjs @@ -640,6 +640,74 @@ function captureFdSync(captureFd, fn) { return Buffer.concat(chunks).toString('utf8'); } +/** + * NARROW, deliberate exception to `captureFdSync`'s + * "never swallow" philosophy (#4306) — do NOT reach for this casually. + * + * Async twin of `captureFdSync` that awaits `fn()` before restoring the + * patch, so a deferred write that happens after a microtask/macrotask + * boundary is still safely observed. Its patched `fs.writeSync` + * does NOT forward `captureFd`'s writes to the real `fs.writeSync` at all. + * It only records the bytes into `chunks` and returns the byte length of + * `data` as if the real syscall had succeeded, so a caller that inspects the + * return value sees a normal success and not an error. Every OTHER fd's + * writes still forward to the real `fs.writeSync` exactly as + * `captureFdSync` does — only the `captureFd`-matching branch + * differs. + * + * This exists for #4448: `runMain()`/`io.output()`'s deferred `fs.writeSync(1, + * ...)` races Node's own `node:test` child-to-parent IPC, which also uses fd + * 1 under the default `--test-isolation=process` — corrupting the parent's + * message parsing ("Unable to deserialize cloned data"). An always-forward + * capture (the first fix attempted for this issue) does not + * fix that: the corrupting write still physically reaches fd 1. Use this + * ONLY for a window the caller has verified is narrow and fully controlled — + * i.e. nothing else legitimately needs to write to `captureFd` during `fn()` + * — such as a single `runMain(...)` call plus its promise-chain settling. + * Reaching for this in a window where something else might legitimately + * write to `captureFd` will silently swallow that other write. + * + * @param {number} captureFd - the fd whose writes are suppressed and recorded + * (never delivered to the real fd) while `fn()` runs. + * @param {() => (Promise | void)} fn - function to run (and await) while suppressing. + * @returns {Promise} every byte that WOULD have been written to + * `captureFd` during `fn()`, joined as UTF-8 — none of it actually reached + * the real fd. + */ +async function suppressFdAsync(captureFd, fn) { + const chunks = []; + const orig = fs.writeSync; + fs.writeSync = (fd, data, ...rest) => { + if (fd === captureFd) { + const offset = Buffer.isBuffer(data) && typeof rest[0] === 'number' ? rest[0] : 0; + // No real syscall happens here (unlike captureFdSync, which slices to + // the real return value `n`), so the caller-requested `length` IS the + // count that must be recorded and returned — suppression always + // "succeeds" in full, so anything else silently drops or over-reports + // bytes. + const length = Buffer.isBuffer(data) && typeof rest[1] === 'number' ? rest[1] : undefined; + const buf = Buffer.isBuffer(data) + ? data.subarray(offset, length === undefined ? undefined : offset + length) + : Buffer.from(String(data), 'utf8'); + // Buffered, not decoded per-call: see captureFdSync's identical note on + // why joined-then-decoded avoids splitting a multi-byte UTF-8 codepoint. + chunks.push(buf); + // No real fs.writeSync call for this fd — that is the entire point of + // this helper. Return the byte length as if the write succeeded, so a + // caller inspecting the return value (Node's own writeSync contract) + // sees ordinary success rather than an error. + return buf.length; +} + return orig.call(fs, fd, data, ...rest); +}; + try { + await fn(); + } finally { + fs.writeSync = orig; +} + return Buffer.concat(chunks).toString('utf8'); +} + /** * Read a workflow .md file plus every .md file under its sibling * `/steps/` directory, concatenated in document order @@ -1182,7 +1250,7 @@ function writePackageSourceMarkerFixture(configDir) { return configDir; } -module.exports = { runGsdTools, createTempDir, createTempProject, createTempGitProject, cleanup, tmpRootCandidates, readFileNormalized, readWorkflowCombined, parseFrontmatter, isUsageOutput, captureConsole, toPosixPath, absPlanningPath, runNpm, isolatedNpmEnv, withIsolatedProcessState, delay, waitFor, resetRuntimeWarningCaches, SESSION_ENV_KEYS, saveSessionEnv, restoreSessionEnv, clearSessionEnv, isolateWorkstreamEnv, restoreWorkstreamEnv, TOOLS_PATH, SESSION_IDENTITY_ENV_KEYS, scrubConfigLocationEnv, installSpawnEnv, installSpawnHome, sandboxHome, writePackageSourceMarkerFixture, TEST_HOME_SANDBOX_MARKER, mockPartialWriteThenThrow, captureFdSync }; +module.exports = { runGsdTools, createTempDir, createTempProject, createTempGitProject, cleanup, tmpRootCandidates, readFileNormalized, readWorkflowCombined, parseFrontmatter, isUsageOutput, captureConsole, toPosixPath, absPlanningPath, runNpm, isolatedNpmEnv, withIsolatedProcessState, delay, waitFor, resetRuntimeWarningCaches, SESSION_ENV_KEYS, saveSessionEnv, restoreSessionEnv, clearSessionEnv, isolateWorkstreamEnv, restoreWorkstreamEnv, TOOLS_PATH, SESSION_IDENTITY_ENV_KEYS, scrubConfigLocationEnv, installSpawnEnv, installSpawnHome, sandboxHome, writePackageSourceMarkerFixture, TEST_HOME_SANDBOX_MARKER, mockPartialWriteThenThrow, captureFdSync, suppressFdAsync }; // Lazy, for the reason builtLib() is lazy: reading either of these is what // forces the built-lib require, so a test file that needs neither can still diff --git a/tests/io.test.cjs b/tests/io.test.cjs index 0e446956f..07aba6a0f 100644 --- a/tests/io.test.cjs +++ b/tests/io.test.cjs @@ -16,7 +16,7 @@ const assert = require('node:assert/strict'); const path = require('node:path'); const os = require('node:os'); const fs = require('node:fs'); -const { captureFdSync } = require('./helpers.cjs'); +const { captureFdSync, suppressFdAsync } = require('./helpers.cjs'); const io = require('../gsd-core/bin/lib/io.cjs'); const { @@ -717,7 +717,7 @@ describe('#3912 A1/B1: error() declares from ERROR_REASON, exhaustive over the 2 test(`v1: ERROR_REASON.${key} (${reasonValue}) exits 1`, () => { resolveContractVersion({ argv: ['node', 'x'], env: {} }); // v1 assert.throws( - () => io.error('msg', reasonValue), + () => captureFdSync(2, () => { io.error('msg', reasonValue); }), (err) => err instanceof ExitError && err.code === 1, `ERROR_REASON.${key} must exit 1 under v1`, ); @@ -727,7 +727,7 @@ describe('#3912 A1/B1: error() declares from ERROR_REASON, exhaustive over the 2 resolveContractVersion({ argv: ['node', 'x', '--exit-contract=v2'], env: {} }); const expected = expectedErrorCode3912(reasonValue, 'v2'); assert.throws( - () => io.error('msg', reasonValue), + () => captureFdSync(2, () => { io.error('msg', reasonValue); }), (err) => err instanceof ExitError && err.code === expected, `ERROR_REASON.${key} under v2 must exit ${expected}`, ); @@ -738,7 +738,7 @@ describe('#3912 A1/B1: error() declares from ERROR_REASON, exhaustive over the 2 test('A2: error() with no reason argument exits 1 under v1 (defaults to UNKNOWN)', () => { resolveContractVersion({ argv: ['node', 'x'], env: {} }); assert.throws( - () => io.error('no reason given'), + () => captureFdSync(2, () => { io.error('no reason given'); }), (err) => err instanceof ExitError && err.code === 1, ); }); @@ -746,7 +746,7 @@ describe('#3912 A1/B1: error() declares from ERROR_REASON, exhaustive over the 2 test('A2: error() with no reason argument stays FAIL (exit 1) under v2 too — UNKNOWN is not a specific outcome', () => { resolveContractVersion({ argv: ['node', 'x', '--exit-contract=v2'], env: {} }); assert.throws( - () => io.error('no reason given'), + () => captureFdSync(2, () => { io.error('no reason given'); }), (err) => err instanceof ExitError && err.code === 1, ); }); @@ -756,7 +756,7 @@ describe('#3912 A1/B1: error() declares from ERROR_REASON, exhaustive over the 2 resolveContractVersion({ argv: ['node', 'x', '--exit-contract=v2'], env: {} }); for (const key of ['SDK_MISSING_ARG', 'SDK_UNKNOWN_COMMAND', 'USAGE']) { assert.throws( - () => io.error('msg', io.ERROR_REASON[key]), + () => captureFdSync(2, () => { io.error('msg', io.ERROR_REASON[key]); }), (err) => err instanceof ExitError && err.code === 64, `${key} must project to 64 under v2`, ); @@ -768,10 +768,14 @@ describe('#3912 A1/B1: error() declares from ERROR_REASON, exhaustive over the 2 test('B5 (anti-vacuity): v1 and v2 differ for at least one reason', () => { resolveContractVersion({ argv: ['node', 'x'], env: {} }); let v1Code; - try { io.error('msg', io.ERROR_REASON.SDK_MISSING_ARG); } catch (e) { v1Code = e.code; } + captureFdSync(2, () => { + try { io.error('msg', io.ERROR_REASON.SDK_MISSING_ARG); } catch (e) { v1Code = e.code; } + }); resolveContractVersion({ argv: ['node', 'x', '--exit-contract=v2'], env: {} }); let v2Code; - try { io.error('msg', io.ERROR_REASON.SDK_MISSING_ARG); } catch (e) { v2Code = e.code; } + captureFdSync(2, () => { + try { io.error('msg', io.ERROR_REASON.SDK_MISSING_ARG); } catch (e) { v2Code = e.code; } + }); assert.equal(v1Code, 1); assert.equal(v2Code, 64); assert.notEqual(v1Code, v2Code, 'v1 and v2 must differ for at least one reason, or the declaration is decorative'); @@ -990,11 +994,22 @@ describe('review fix: pending-outcome cell lifetime (last-write-wins, cleared on try { // First invocation declares DEGRADED via a payload-carried error and // returns nothing — runMain projects it to 80 under v2. - runMain(() => { - io.output({ found: false, error: 'not found' }, false); - return undefined; + // + // runMain() defers main() via Promise.resolve().then(...), so the + // actual fs.writeSync(1, ...) fires in a later microtask, not + // synchronously inside this call. suppressFdAsync (not captureFdAsync) + // keeps fs.writeSync patched across that await AND prevents the + // deferred write from ever reaching the real fd 1 — this exact window + // races node:test's own fd-1 IPC protocol under + // --test-isolation=process and forwarding (as captureFdAsync does) was + // empirically confirmed to still corrupt it (#4448). + await suppressFdAsync(1, async () => { + runMain(() => { + io.output({ found: false, error: 'not found' }, false); + return undefined; + }); + await waitForRunMain(); }); - await waitForRunMain(); assert.strictEqual(process.exitCode, 80, 'first runMain should have projected the DEGRADED cell to 80'); // Second, unrelated invocation in the SAME process declares nothing @@ -1002,8 +1017,10 @@ describe('review fix: pending-outcome cell lifetime (last-write-wins, cleared on // runMain, so this would inherit the first call's stale DEGRADED and // also exit 80 — the exact bug the reviewers found. process.exitCode = undefined; - runMain(() => undefined); - await waitForRunMain(); + await suppressFdAsync(1, async () => { + runMain(() => undefined); + await waitForRunMain(); + }); assert.strictEqual( process.exitCode, undefined, @@ -1018,12 +1035,14 @@ describe('review fix: pending-outcome cell lifetime (last-write-wins, cleared on resolveContractVersion({ argv: ['node', 'x', '--exit-contract=v2'], env: {} }); const savedExitCode = process.exitCode; try { - runMain(() => { - io.output({ found: false, error: 'not found' }, false); - io.output({ ok: true }, false); - return undefined; + await suppressFdAsync(1, async () => { + runMain(() => { + io.output({ found: false, error: 'not found' }, false); + io.output({ ok: true }, false); + return undefined; + }); + await waitForRunMain(); }); - await waitForRunMain(); assert.strictEqual( process.exitCode, undefined, @@ -1038,13 +1057,29 @@ describe('review fix: pending-outcome cell lifetime (last-write-wins, cleared on resolveContractVersion({ argv: ['node', 'x', '--exit-contract=v2'], env: {} }); const savedExitCode = process.exitCode; try { - runMain(() => { - io.output({ error: 'x' }, false); - return undefined; + const captured = await suppressFdAsync(1, async () => { + runMain(() => { + io.output({ error: 'x' }, false); + return undefined; + }); + await waitForRunMain(); }); - await waitForRunMain(); assert.strictEqual(process.exitCode, 80); assert.strictEqual(getPendingOutcome(), undefined, 'the cell must be cleared once runMain has consumed it'); + // Load-bearing check on the wrap itself, not just the outcome it + // guards: proves suppressFdAsync actually intercepted the deferred + // bytes runMain wrote (rather than the patch having been restored + // before the deferred write ran, which would silently capture an + // empty string — verified as the failure mode of a naive + // captureFdSync wrap during development of this fix). These bytes + // never reached the real fd 1 by design (#4448) — only the in-memory + // recording is asserted on here. + const parsedCaptured = JSON.parse(captured); + assert.strictEqual( + parsedCaptured.error, + 'x', + `expected suppressFdAsync to intercept the output({error}) JSON bytes for fd 1; got: ${JSON.stringify(captured)}`, + ); } finally { process.exitCode = savedExitCode; }