diff --git a/packages/cli/test/serve-mcp-capability-collision.e2e.test.ts b/packages/cli/test/serve-mcp-capability-collision.e2e.test.ts index c7b929bf8c..e2bd58cbc8 100644 --- a/packages/cli/test/serve-mcp-capability-collision.e2e.test.ts +++ b/packages/cli/test/serve-mcp-capability-collision.e2e.test.ts @@ -233,12 +233,26 @@ function boot(env: Record, waitFor: RegExp): Promise const timer = setTimeout(() => { if (settled) return; settled = true; - rejectBoot(new Error(`serve never printed ${waitFor}\n--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`)); + rejectBoot(new Error(`serve never printed ${waitFor} (child-reported bound port: ${boundPort(out + err) ?? 'NEVER PRINTED'}; this file reserved ${port})\n--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`)); }, 150_000); const onOutput = () => { bootOutput = err; - if (!settled && waitFor.test(out + err)) { + if (settled) return; + // ⭐ #12526: the child is the authority on which port it bound, so read it + // back before handing this boot to assertions that will use `port`. + const bound = boundPort(out + err); + if (bound !== null && bound !== port) { + settled = true; + clearTimeout(timer); + rejectBoot(portDriftError(port, bound, out, err)); + return; + } + // `bound !== null` is part of the gate, not an optimisation: resolving on + // `waitFor` alone would let a boot through before the child had said which + // port it took, and the drift check would then be a no-op on an already + // settled promise. Every marker below arrives with or before the banner. + if (bound !== null && waitFor.test(out + err)) { settled = true; clearTimeout(timer); resolveBoot(child); @@ -262,6 +276,63 @@ function boot(env: Record, waitFor: RegExp): Promise }); } +/** + * The port the CHILD says it bound — read out of the child's OWN output, never + * out of what this file reserved (#12526, and #12441 ruling 2 before it). + * + * ## Why this file needs it at all + * + * The spawn below passes `--dev`, and `serve.ts` reads + * `portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'` — `flags.dev` + * ALONE opens the auto-select branch, whatever `NODE_ENV` is. So a port taken + * between `randomPort()`'s bind probe and this spawn does NOT fail the boot the + * way it does in `serve-node-env-production-default.e2e.test.ts` (no `--dev` + * there, so unset `NODE_ENV` defaults to production and a taken port is a hard + * `exit 1` that `portContentionError()` can name). Here `getAvailablePort()` + * silently hops the child onto the next free port and it reports itself READY. + * + * That is the strictly worse direction: a GREEN boot on the wrong port. Every + * request this file makes afterwards goes to `port` — the port it reserved and + * no longer owns — so it measures whatever else took it. Measured on this tree + * with a neighbour holding the reserved port: reserved 34259, child bound + * 34260, boot green, and the file's own next request was answered + * `{"iAm":"A NEIGHBOURING AGENT DEV SERVER, not os serve"}`. + * + * ⚠️ The `--dev` responsible has been on this spawn line since `83e6016fa` — it + * long predates #11707/#12459, which changed `NODE_ENV` and never touched it. + * This was never read, not newly introduced. + * + * Two patterns because either one alone can be absent: the structured log obeys + * `OS_LOG_LEVEL`, and the banner line is what survives when it does not. + */ +function boundPort(output: string): string | null { + const match = /HTTP server started successfully[^\n]*?"port":\s*(\d+)/.exec(output) + ?? /API:\s+http:\/\/localhost:(\d+)/.exec(output); + return match ? match[1] : null; +} + +/** + * A lost port race, said out loud — the failure this file used to hide behind a + * green boot (#12526). + */ +function portDriftError(reserved: string, bound: string, out: string, err: string): Error { + return new Error( + `PORT DRIFT: this file reserved port ${reserved}, but the child bound ${bound}.\n` + + `\`os serve -p ${reserved} --dev\` passes \`--dev\`, so \`serve.ts\`'s ` + + `\`portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'\` opened the auto-select ` + + `branch and \`getAvailablePort()\` hopped the child off the port that was asked for. The ` + + `boot SUCCEEDED — on the wrong port.\n` + + `⛔ Something else took ${reserved} between \`randomPort()\`'s bind probe and the spawn. That ` + + `is a HOST race (several agents share one container), not a verdict about the code under ` + + `test — but it is NOT harmless here: every assertion below talks to ${reserved}, which is ` + + `now that other process, so continuing would measure a stranger rather than this boot.\n` + + `⛔ Do not "fix" this by following the child to ${bound}: the point is that the port this ` + + `file uses and the port the child bound must be the SAME port. Re-run this file in ` + + `isolation; if it reproduces there, the port is genuinely held.\n` + + `--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`, + ); +} + async function stop(child: ChildProcessWithoutNullStreams): Promise { if (child.exitCode !== null || child.signalCode !== null) return; await new Promise((done) => { diff --git a/packages/cli/test/serve-mcp-stdio-answers.e2e.test.ts b/packages/cli/test/serve-mcp-stdio-answers.e2e.test.ts index 36a5881ca3..6a845fa6dc 100644 --- a/packages/cli/test/serve-mcp-stdio-answers.e2e.test.ts +++ b/packages/cli/test/serve-mcp-stdio-answers.e2e.test.ts @@ -229,12 +229,26 @@ function boot(env: Record, waitFor: RegExp): Promise if (settled) return; settled = true; rejectBoot( - new Error(`serve never printed ${waitFor}\n--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`), + new Error(`serve never printed ${waitFor} (child-reported bound port: ${boundPort(out + err) ?? 'NEVER PRINTED'}; this file reserved ${port})\n--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`), ); }, 150_000); const onOutput = () => { - if (!settled && waitFor.test(out + err)) { + if (settled) return; + // ⭐ #12526: the child is the authority on which port it bound, so read it + // back before handing this boot to assertions that will use `port`. + const bound = boundPort(out + err); + if (bound !== null && bound !== port) { + settled = true; + clearTimeout(timer); + rejectBoot(portDriftError(port, bound, out, err)); + return; + } + // `bound !== null` is part of the gate, not an optimisation: resolving on + // `waitFor` alone would let a boot through before the child had said which + // port it took, and the drift check would then be a no-op on an already + // settled promise. Every marker below arrives with or before the banner. + if (bound !== null && waitFor.test(out + err)) { settled = true; clearTimeout(timer); resolveBoot({ child, stdout: () => out, stderr: () => err }); @@ -260,6 +274,63 @@ function boot(env: Record, waitFor: RegExp): Promise }); } +/** + * The port the CHILD says it bound — read out of the child's OWN output, never + * out of what this file reserved (#12526, and #12441 ruling 2 before it). + * + * ## Why this file needs it at all + * + * The spawn below passes `--dev`, and `serve.ts` reads + * `portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'` — `flags.dev` + * ALONE opens the auto-select branch, whatever `NODE_ENV` is. So a port taken + * between `randomPort()`'s bind probe and this spawn does NOT fail the boot the + * way it does in `serve-node-env-production-default.e2e.test.ts` (no `--dev` + * there, so unset `NODE_ENV` defaults to production and a taken port is a hard + * `exit 1` that `portContentionError()` can name). Here `getAvailablePort()` + * silently hops the child onto the next free port and it reports itself READY. + * + * That is the strictly worse direction: a GREEN boot on the wrong port. Every + * request this file makes afterwards goes to `port` — the port it reserved and + * no longer owns — so it measures whatever else took it. Measured on this tree + * with a neighbour holding the reserved port: reserved 34259, child bound + * 34260, boot green, and the file's own next request was answered + * `{"iAm":"A NEIGHBOURING AGENT DEV SERVER, not os serve"}`. + * + * ⚠️ The `--dev` responsible has been on this spawn line since `83e6016fa` — it + * long predates #11707/#12459, which changed `NODE_ENV` and never touched it. + * This was never read, not newly introduced. + * + * Two patterns because either one alone can be absent: the structured log obeys + * `OS_LOG_LEVEL`, and the banner line is what survives when it does not. + */ +function boundPort(output: string): string | null { + const match = /HTTP server started successfully[^\n]*?"port":\s*(\d+)/.exec(output) + ?? /API:\s+http:\/\/localhost:(\d+)/.exec(output); + return match ? match[1] : null; +} + +/** + * A lost port race, said out loud — the failure this file used to hide behind a + * green boot (#12526). + */ +function portDriftError(reserved: string, bound: string, out: string, err: string): Error { + return new Error( + `PORT DRIFT: this file reserved port ${reserved}, but the child bound ${bound}.\n` + + `\`os serve -p ${reserved} --dev\` passes \`--dev\`, so \`serve.ts\`'s ` + + `\`portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'\` opened the auto-select ` + + `branch and \`getAvailablePort()\` hopped the child off the port that was asked for. The ` + + `boot SUCCEEDED — on the wrong port.\n` + + `⛔ Something else took ${reserved} between \`randomPort()\`'s bind probe and the spawn. That ` + + `is a HOST race (several agents share one container), not a verdict about the code under ` + + `test — but it is NOT harmless here: every assertion below talks to ${reserved}, which is ` + + `now that other process, so continuing would measure a stranger rather than this boot.\n` + + `⛔ Do not "fix" this by following the child to ${bound}: the point is that the port this ` + + `file uses and the port the child bound must be the SAME port. Re-run this file in ` + + `isolation; if it reproduces there, the port is genuinely held.\n` + + `--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`, + ); +} + async function stop(child: ChildProcessWithoutNullStreams): Promise { if (child.exitCode !== null || child.signalCode !== null) return; await new Promise((done) => { diff --git a/packages/cli/test/serve-node-env-production-default.e2e.test.ts b/packages/cli/test/serve-node-env-production-default.e2e.test.ts index 1f0d3957e3..7cdab640b6 100644 --- a/packages/cli/test/serve-node-env-production-default.e2e.test.ts +++ b/packages/cli/test/serve-node-env-production-default.e2e.test.ts @@ -108,8 +108,23 @@ * * THEY REACH IT NOW, and the declaration below is the whole reason that is * allowed. #11707 dropped that `NODE_ENV` pin: all three leave the variable - * unset and spawn `bin/run.js` through plain `node` — this file's own shape — - * and the `--dev` seed survives because `serve.ts` assigns + * unset and spawn `bin/run.js` through plain `node` — ⛔ but NOT this file's + * own shape, and the difference decides how each one FAILS on a taken port + * (#12526). Those three pass `--dev` on the spawn line; this file does not. + * `serve.ts`'s `portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'` + * is opened by `flags.dev` ALONE, so for those three a taken port is not an + * error at all: `getAvailablePort()` hops the child onto another port and the + * boot reports itself READY — the SILENT-DRIFT column, where their own + * requests then reach whatever else holds the port they reserved (measured: + * reserved 34259, child bound 34260, the next request answered by a + * neighbouring dev server). Only THIS file — `--dev` absent, so unset + * `NODE_ENV` defaults to production — is in the LOUD column where a taken port + * is a hard `exit 1` and `portContentionError()` below has something to read. + * ⚠️ That `--dev` has been on their spawn lines since `83e6016fa`, long + * predating #11707: it was never read, not newly introduced. Each of those + * three carries its own port-drift check now; ⛔ do not read this paragraph as + * putting them in this file's column. + * The `--dev` seed survives because `serve.ts` assigns * `process.env.NODE_ENV = 'development'` IN-PROCESS for `--dev` before * `runtime.start()`, which is after oclif has already resolved the command. * Measured when they moved, with a distinct marker planted in each tree: diff --git a/packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts b/packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts index cdcfed381e..5af353594b 100644 --- a/packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts +++ b/packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts @@ -225,13 +225,27 @@ function boot(env: Record, waitFor: RegExp): Promise settled = true; rejectBoot( new Error( - `serve never printed ${waitFor}\n--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`, + `serve never printed ${waitFor} (child-reported bound port: ${boundPort(out + err) ?? 'NEVER PRINTED'}; this file reserved ${port})\n--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`, ), ); }, 150_000); const onOutput = () => { - if (settled || !waitFor.test(out + err)) return; + if (settled) return; + // ⭐ #12526: the child is the authority on which port it bound, so read it + // back before handing this boot to assertions that will use `port`. + const bound = boundPort(out + err); + if (bound !== null && bound !== port) { + settled = true; + clearTimeout(timer); + rejectBoot(portDriftError(port, bound, out, err)); + return; + } + // `bound !== null` is part of the gate, not an optimisation: resolving on + // `waitFor` alone would let a boot through before the child had said which + // port it took, and the drift check would then be a no-op on an already + // settled promise. Every marker below arrives with or before the banner. + if (bound === null || !waitFor.test(out + err)) return; settled = true; clearTimeout(timer); resolveBoot({ child, stdout: () => out, stderr: () => err }); @@ -258,6 +272,63 @@ function boot(env: Record, waitFor: RegExp): Promise }); } +/** + * The port the CHILD says it bound — read out of the child's OWN output, never + * out of what this file reserved (#12526, and #12441 ruling 2 before it). + * + * ## Why this file needs it at all + * + * The spawn below passes `--dev`, and `serve.ts` reads + * `portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'` — `flags.dev` + * ALONE opens the auto-select branch, whatever `NODE_ENV` is. So a port taken + * between `randomPort()`'s bind probe and this spawn does NOT fail the boot the + * way it does in `serve-node-env-production-default.e2e.test.ts` (no `--dev` + * there, so unset `NODE_ENV` defaults to production and a taken port is a hard + * `exit 1` that `portContentionError()` can name). Here `getAvailablePort()` + * silently hops the child onto the next free port and it reports itself READY. + * + * That is the strictly worse direction: a GREEN boot on the wrong port. Every + * request this file makes afterwards goes to `port` — the port it reserved and + * no longer owns — so it measures whatever else took it. Measured on this tree + * with a neighbour holding the reserved port: reserved 34259, child bound + * 34260, boot green, and the file's own next request was answered + * `{"iAm":"A NEIGHBOURING AGENT DEV SERVER, not os serve"}`. + * + * ⚠️ The `--dev` responsible has been on this spawn line since `83e6016fa` — it + * long predates #11707/#12459, which changed `NODE_ENV` and never touched it. + * This was never read, not newly introduced. + * + * Two patterns because either one alone can be absent: the structured log obeys + * `OS_LOG_LEVEL`, and the banner line is what survives when it does not. + */ +function boundPort(output: string): string | null { + const match = /HTTP server started successfully[^\n]*?"port":\s*(\d+)/.exec(output) + ?? /API:\s+http:\/\/localhost:(\d+)/.exec(output); + return match ? match[1] : null; +} + +/** + * A lost port race, said out loud — the failure this file used to hide behind a + * green boot (#12526). + */ +function portDriftError(reserved: string, bound: string, out: string, err: string): Error { + return new Error( + `PORT DRIFT: this file reserved port ${reserved}, but the child bound ${bound}.\n` + + `\`os serve -p ${reserved} --dev\` passes \`--dev\`, so \`serve.ts\`'s ` + + `\`portAutoShiftAllowed = flags.dev || NODE_ENV === 'development'\` opened the auto-select ` + + `branch and \`getAvailablePort()\` hopped the child off the port that was asked for. The ` + + `boot SUCCEEDED — on the wrong port.\n` + + `⛔ Something else took ${reserved} between \`randomPort()\`'s bind probe and the spawn. That ` + + `is a HOST race (several agents share one container), not a verdict about the code under ` + + `test — but it is NOT harmless here: every assertion below talks to ${reserved}, which is ` + + `now that other process, so continuing would measure a stranger rather than this boot.\n` + + `⛔ Do not "fix" this by following the child to ${bound}: the point is that the port this ` + + `file uses and the port the child bound must be the SAME port. Re-run this file in ` + + `isolation; if it reproduces there, the port is genuinely held.\n` + + `--- stdout ---\n${out.slice(-4000)}\n--- stderr ---\n${err.slice(-4000)}`, + ); +} + async function stop(child: ChildProcessWithoutNullStreams): Promise { if (child.exitCode !== null || child.signalCode !== null) return; await new Promise((done) => {