From e7b2c2a3d09cb2269852485c9cb62e469bebd4a2 Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Sat, 4 Jul 2026 23:52:09 -0700 Subject: [PATCH 1/2] fix(selfhost): fast-fail codex when it never produces any output codex exec occasionally hangs having printed only its "Reading prompt from stdin..." startup banner, with no further stdout/stderr bytes ever arriving, until the full CODEX_AI_TIMEOUT_MS (up to 600s at max effort) elapses and it is SIGKILLed. Waiting out the full timeout to detect a dead subprocess stalls the codex -> claude-code fallback chain for up to 10 minutes per attempt. Add a separate, much shorter "first output" deadline to defaultSpawn: if neither stdout nor stderr has produced a single byte within firstOutputTimeoutMs, kill the process early and resolve with a distinguishable stalledNoOutput flag. createCodexAi surfaces this as codex_stalled_no_output, kept separate from codex_timeout so the two failure modes are independently observable in logs/Sentry. The full timeoutMs remains the unchanged outer safety net for output that starts flowing but stalls later. The option is generic on SpawnFn but only codex wires it up, via the new CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS env var (default 30s, independent of CODEX_AI_EFFORT since a slower completion does not imply a slower first byte). Claude Code's spawn path is unaffected. --- src/selfhost/ai.ts | 83 +++++++++++++++- test/unit/selfhost-ai.test.ts | 179 +++++++++++++++++++++++++++++++++- 2 files changed, 254 insertions(+), 8 deletions(-) diff --git a/src/selfhost/ai.ts b/src/selfhost/ai.ts index 0ffad0f690..8810dc7a04 100644 --- a/src/selfhost/ai.ts +++ b/src/selfhost/ai.ts @@ -151,6 +151,26 @@ export function resolveCodexCliTimeoutMs(env: Record return resolveCliTimeoutFrom(firstConfigured(env.CODEX_AI_TIMEOUT_MS), resolveCodexEffort(firstConfigured(env.CODEX_AI_EFFORT))); } +// Fast-fail deadline for Codex's "Reading prompt from stdin..." hang (GITTENSORY-K/GITTENSORY-M): observed in prod +// as `codex exec` printing ONLY its own startup banner to stderr and then never producing a single byte of JSONL +// on stdout before the FULL timeoutMs (up to 600_000ms at max effort) elapses and the process is SIGKILLed. That +// full timeout is sized for a legitimately long-running review, so waiting it out to detect a completely dead +// subprocess stalls the codex → claude-code fallback chain for up to 10 minutes per attempt. This is a SEPARATE, +// much shorter deadline: if not one single byte has arrived on EITHER stdout or stderr by this point, the process +// is almost certainly hung at the stdin-read step, not merely thinking — a working call, even a slow one under +// load, emits at least the startup banner well within this window. 30s default: long enough that a busy host +// (cold container start, contended CPU) doesn't false-positive on a merely-slow-to-start real call, short enough +// that the codex→claude-code fallback (or a caller retry) kicks in almost immediately instead of after a 10-minute +// stall. Independent of CODEX_AI_EFFORT/CODEX_AI_TIMEOUT_MS on purpose: a higher effort makes a COMPLETION take +// longer, it does not make the CLI slower to print its FIRST byte, so this must not scale with effort the way the +// full timeout does. Bounds mirror resolveCliTimeoutFrom's floor but cap well under the shortest full timeout +// (120_000ms) so this can never itself become the effective timeout. +export function resolveCodexFirstOutputTimeoutMs(env: Record): number { + const raw = Number(firstConfigured(env.CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS)); + if (Number.isFinite(raw) && raw > 0) return Math.min(120_000, Math.max(1_000, raw)); + return 30_000; +} + /** OpenAI-compatible endpoint (Ollama's /v1, OpenAI, vLLM, LM Studio, …) — chat + embeddings. */ export function createOpenAiCompatibleAi(opts: { baseUrl: string; @@ -515,8 +535,18 @@ export function codexErrorFromStdout(stdout: string): string | null { type SpawnFn = ( cmd: string, args: string[], - opts: { env: Record; input?: string; timeoutMs: number; cwd?: string }, -) => Promise<{ stdout: string; code: number | null; stderr?: string; timedOut?: boolean }>; + opts: { + env: Record; + input?: string; + timeoutMs: number; + cwd?: string; + // Optional, generic on SpawnFn (not codex-specific) so any CLI with the same "prints a startup banner then + // hangs" shape could opt in later — but ONLY codex wires it up today (see resolveCodexFirstOutputTimeoutMs): + // Claude Code has no comparable prod-observed dead-air hang, so leaving this undefined for that caller keeps + // its spawn path byte-identical to before this option existed. + firstOutputTimeoutMs?: number; + }, +) => Promise<{ stdout: string; code: number | null; stderr?: string; timedOut?: boolean; stalledNoOutput?: boolean }>; async function defaultSpawn(): Promise { const cp = await import("node:child_process"); @@ -528,6 +558,7 @@ async function defaultSpawn(): Promise { // Capture stderr too — the CLI's actual error (auth, rate limit, model-not-supported, OOM) lands here, and // it's what makes a `claude_code_exit_1` / `codex_exit_1` diagnosable instead of an opaque exit code (#26). let stderr = ""; + let sawAnyOutput = false; /* v8 ignore start */ // a 120s subprocess timeout is not unit-testable without a 2-minute wait const timer = setTimeout(() => { child.kill("SIGKILL"); @@ -536,14 +567,42 @@ async function defaultSpawn(): Promise { resolve({ stdout, code: null, stderr, timedOut: true }); }, o.timeoutMs); /* v8 ignore stop */ - child.stdout?.on("data", (d: Buffer) => (stdout += d.toString("utf8"))); - child.stderr?.on("data", (d: Buffer) => (stderr += d.toString("utf8"))); + // Fast-fail deadline (GITTENSORY-K/GITTENSORY-M): a SEPARATE, shorter timer that only fires if NEITHER + // stdout nor stderr has produced a single byte by firstOutputTimeoutMs — cleared the instant any data + // arrives on either stream, same as the full timer is cleared on `close`/`error`. This catches codex's + // "printed only the startup banner, then total silence" hang far sooner than the full timeoutMs, without + // touching the full timer at all: if output DOES start flowing but then stalls later, only the full + // timeoutMs above still governs — this timer has already been cleared by the first byte and never fires. + const firstOutputTimer = + o.firstOutputTimeoutMs != null + ? /* v8 ignore start */ // real-timer path; tests inject a fake spawnImpl instead of racing setTimeout + setTimeout(() => { + child.kill("SIGKILL"); + resolve({ stdout, code: null, stderr, timedOut: true, stalledNoOutput: true }); + }, o.firstOutputTimeoutMs) + : /* v8 ignore stop */ + undefined; + const onFirstOutput = (): void => { + if (sawAnyOutput) return; + sawAnyOutput = true; + if (firstOutputTimer) clearTimeout(firstOutputTimer); + }; + child.stdout?.on("data", (d: Buffer) => { + onFirstOutput(); + stdout += d.toString("utf8"); + }); + child.stderr?.on("data", (d: Buffer) => { + onFirstOutput(); + stderr += d.toString("utf8"); + }); child.on("error", (e) => { clearTimeout(timer); + if (firstOutputTimer) clearTimeout(firstOutputTimer); reject(e); }); child.on("close", (code) => { clearTimeout(timer); + if (firstOutputTimer) clearTimeout(firstOutputTimer); resolve({ stdout, code, stderr }); }); if (o.input != null) { @@ -693,6 +752,10 @@ export function createCodexAi( const codexModel = resolveModel(configuredCodexModel(parentEnv), model, ""); const effort = resolveCodexEffort(firstConfigured(parentEnv.CODEX_AI_EFFORT)); const timeoutMs = resolveCodexCliTimeoutMs(parentEnv); + // Clamp below timeoutMs so a misconfigured/low CODEX_AI_TIMEOUT_MS (its own floor is 30_000ms, the same as + // this deadline's default) can never make the fast-fail deadline equal or exceed the outer safety net — + // that would make the "outer" timeout unreachable and defeat the point of having two distinct signals. + const firstOutputTimeoutMs = Math.min(resolveCodexFirstOutputTimeoutMs(parentEnv), Math.max(1, timeoutMs - 1)); let attempted = false; let stdoutForMetrics = ""; try { @@ -706,14 +769,24 @@ export function createCodexAi( if (codexModel) args.push("--model", codexModel); args.push("-c", `model_reasoning_effort="${effort}"`); attempted = true; - const { stdout, code, stderr, timedOut } = await spawn("codex", args, { + const { stdout, code, stderr, timedOut, stalledNoOutput } = await spawn("codex", args, { env, // `codex exec` reads stdin when no prompt argv is provided; keep PR prompts/diffs out of process listings. input: prompt, timeoutMs, + firstOutputTimeoutMs, cwd: await isolatedCliCwd(), }); stdoutForMetrics = stdout; + if (timedOut && stalledNoOutput) { + // Fast-fail path (GITTENSORY-K/GITTENSORY-M): killed at firstOutputTimeoutMs, well before the full + // timeoutMs, because NEITHER stdout nor stderr produced a single byte — the "Reading prompt from + // stdin..." hang where codex prints its own startup banner and then never emits any JSONL. A DISTINCT + // error (never reusing `codex_timeout`) so this fast-fail is separately countable in Sentry/logs from a + // genuine full-timeout case where the process was at least doing something before it was killed — + // that distinction is what lets an operator tell "codex never started" apart from "codex hung mid-review". + throw new Error("codex_stalled_no_output: no stdout/stderr within firstOutputTimeoutMs — codex likely hung reading stdin"); + } if (timedOut) { // Include whatever the JSONL stream captured before the kill — codex writes errors there, not to stderr. const detail = codexErrorFromStdout(stdout) ?? (redactSecrets(stderr ?? "").slice(0, 200) || "no output"); diff --git a/test/unit/selfhost-ai.test.ts b/test/unit/selfhost-ai.test.ts index 0bdd693bf1..686387f167 100644 --- a/test/unit/selfhost-ai.test.ts +++ b/test/unit/selfhost-ai.test.ts @@ -2,7 +2,7 @@ import { chmodSync, mkdirSync, mkdtempSync, writeFileSync } from "node:fs"; import { tmpdir } from "node:os"; import { delimiter, join } from "node:path"; import { afterEach, describe, expect, it, vi } from "vitest"; -import { assertNoLegacySharedAiEnv, buildProvider, claudeErrorStatus, codexErrorFromStdout, createAnthropicAi, createChainAi, createClaudeCodeAi, createCodexAi, createOpenAiCompatibleAi, createSelfHostAi, extractCliText, extractCliUsage, isAiProviderHealthy, markAiProviderUnhealthyAtBoot, resetAiProviderCircuitBreakerForTest, resetAiProviderHealthForTest, resolveAiReviewerPlan, resolveClaudeCliTimeoutMs, resolveCodexAuthPath, resolveCodexCliTimeoutMs, resolveCodexEffort, resolveEffort, resolveModel, resolveProviderNames, resolveRequiredCliProviders, resolveSubscriptionCliPath, redactSecrets, routeProviders, shouldMarkAiProviderUnhealthyAtBoot, subscriptionCliEnv } from "../../src/selfhost/ai"; +import { assertNoLegacySharedAiEnv, buildProvider, claudeErrorStatus, codexErrorFromStdout, createAnthropicAi, createChainAi, createClaudeCodeAi, createCodexAi, createOpenAiCompatibleAi, createSelfHostAi, extractCliText, extractCliUsage, isAiProviderHealthy, markAiProviderUnhealthyAtBoot, resetAiProviderCircuitBreakerForTest, resetAiProviderHealthForTest, resolveAiReviewerPlan, resolveClaudeCliTimeoutMs, resolveCodexAuthPath, resolveCodexCliTimeoutMs, resolveCodexEffort, resolveCodexFirstOutputTimeoutMs, resolveEffort, resolveModel, resolveProviderNames, resolveRequiredCliProviders, resolveSubscriptionCliPath, redactSecrets, routeProviders, shouldMarkAiProviderUnhealthyAtBoot, subscriptionCliEnv } from "../../src/selfhost/ai"; import { labelSelfHostReviewerModel, labelSelfHostReviewerModels } from "../../src/selfhost/ai-config"; import { renderMetrics, resetMetrics } from "../../src/selfhost/metrics"; @@ -62,6 +62,22 @@ describe("provider-specific CLI timeouts (#selfhost — no shared timeout ambigu expect(resolveCodexCliTimeoutMs({ CODEX_AI_TIMEOUT_MS: "1000" })).toBe(30_000); expect(resolveCodexCliTimeoutMs({ CODEX_AI_TIMEOUT_MS: "9999999" })).toBe(1_800_000); }); + it("resolveCodexFirstOutputTimeoutMs defaults to 30s, is independent of effort, and honors + clamps CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS", () => { + // absent → the 30s default (?? right side) + expect(resolveCodexFirstOutputTimeoutMs({})).toBe(30_000); + // effort must NOT scale this deadline — a slow COMPLETION is not a slow first byte. + expect(resolveCodexFirstOutputTimeoutMs({ CODEX_AI_EFFORT: "max" })).toBe(30_000); + // present + valid → honored verbatim (?? left side, within bounds) + expect(resolveCodexFirstOutputTimeoutMs({ CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "15000" })).toBe(15_000); + // clamped to the 1s floor + expect(resolveCodexFirstOutputTimeoutMs({ CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "1" })).toBe(1_000); + // clamped to the 120s ceiling (well under the shortest full timeout, 120_000ms) + expect(resolveCodexFirstOutputTimeoutMs({ CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "999999" })).toBe(120_000); + // non-finite/garbage falls back to the default (Number.isFinite false branch) + expect(resolveCodexFirstOutputTimeoutMs({ CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "not-a-number" })).toBe(30_000); + // zero/negative also falls back (raw > 0 false branch) + expect(resolveCodexFirstOutputTimeoutMs({ CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "0" })).toBe(30_000); + }); }); afterEach(() => { @@ -71,11 +87,11 @@ afterEach(() => { resetAiProviderCircuitBreakerForTest(); }); -type SpawnResult = { stdout: string; code: number | null; stderr?: string; timedOut?: boolean }; +type SpawnResult = { stdout: string; code: number | null; stderr?: string; timedOut?: boolean; stalledNoOutput?: boolean }; type StubSpawn = ( cmd: string, args: string[], - opts: { env: Record; input?: string; timeoutMs: number; cwd?: string }, + opts: { env: Record; input?: string; timeoutMs: number; cwd?: string; firstOutputTimeoutMs?: number }, ) => Promise; // Bypasses the real ~/.codex/auth.json preflight so tests can focus on the spawn/exit behavior they target; // the preflight itself (resolveCodexAuthPath / assertCodexAuthConfigured) is covered separately below. @@ -1022,6 +1038,111 @@ describe("subscription CLI helpers + fail-safe", () => { } }); + // REGRESSION (GITTENSORY-K/GITTENSORY-M): the real defaultSpawn fast-fail path against a genuinely-hung fake + // `codex` that writes ABSOLUTELY NOTHING to either stream (the worst case of the prod hang — even the startup + // banner never lands, e.g. the binary itself is stuck loading) and never exits. CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS + // is set to a tiny value (not the 30s default) so this test resolves in milliseconds instead of actually + // waiting the production deadline out — same "inject a fast/controllable timer" approach the existing + // full-timeout tests use (a stub spawn) but here exercising the REAL setTimeout/kill wiring in defaultSpawn + // itself, since the fast path lives entirely inside that function rather than in createCodexAi's own logic. + it("REAL subprocess: a fake codex that never writes to either stream is killed at the fast-fail deadline, not the full timeout", async () => { + const dir = mkdtempSync(join(tmpdir(), "fakecli-")); + const fake = join(dir, "codex"); + // Consumes stdin, writes NOTHING to stdout or stderr, then hangs forever (no exit) — the "neither stream + // ever produced a byte" case the fast-fail deadline exists to catch quickly. + writeFileSync(fake, "#!/usr/bin/env node\nprocess.stdin.on('data',()=>{});\nsetInterval(()=>{},1000);\n"); + chmodSync(fake, 0o755); + const origPath = process.env.PATH; + try { + const start = Date.now(); + await expect( + createCodexAi( + { + PATH: `${dir}:${origPath ?? ""}`, + HOME: dir, + GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1", + // Full timeout stays large (60s) so a false-pass (hitting the FULL timeout instead of the fast one) + // would make this test hang for a minute rather than silently succeed for the wrong reason. + CODEX_AI_TIMEOUT_MS: "60000", + CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "200", + }, + undefined, + noAuthCheck, + ).run("", { prompt: "hello" }), + ).rejects.toThrow(/codex_stalled_no_output/); + // Killed at ~200ms (the fast-fail deadline), nowhere near the 60_000ms full timeout. + expect(Date.now() - start).toBeLessThan(5_000); + } finally { + process.env.PATH = origPath; + } + }, 10_000); + + // (b) unaffected path: output flows immediately and the process completes normally — byte-identical to today. + it("REAL subprocess: a fake codex that emits output quickly and completes normally is unaffected by the fast-fail deadline", async () => { + const dir = mkdtempSync(join(tmpdir(), "fakecli-")); + const fake = join(dir, "codex"); + writeFileSync( + fake, + "#!/usr/bin/env node\nlet i='';process.stdin.on('data',d=>i+=d);process.stdin.on('end',()=>process.stdout.write(JSON.stringify({type:'result',result:'OK:'+i.trim()})));\n", + ); + chmodSync(fake, 0o755); + const origPath = process.env.PATH; + try { + const out = await createCodexAi( + { + PATH: `${dir}:${origPath ?? ""}`, + HOME: dir, + GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1", + CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "200", + }, + undefined, + noAuthCheck, + ).run("", { prompt: "hello" }); + expect(out.response).toBe("OK:hello"); + } finally { + process.env.PATH = origPath; + } + }); + + // (c) output arrives within the fast-fail window but full completion takes longer than that window — must NOT + // be prematurely killed by the fast-fail path; only the (much larger) full timeoutMs still governs it. + it("REAL subprocess: output within the fast-fail window but a slow completion is governed only by the full timeoutMs, not fast-failed", async () => { + const dir = mkdtempSync(join(tmpdir(), "fakecli-")); + const fake = join(dir, "codex"); + // Writes stderr immediately (clearing the fast-fail timer), then waits LONGER than the fast-fail deadline + // (but well inside the full timeout) before completing — proving the first timer's clearance is permanent + // and the process is not killed once data has already flowed. + writeFileSync( + fake, + [ + "#!/usr/bin/env node", + "process.stderr.write('Reading prompt from stdin...');", + "let i='';process.stdin.on('data',d=>i+=d);", + "process.stdin.on('end',()=>{ setTimeout(()=>process.stdout.write(JSON.stringify({type:'result',result:'OK:'+i.trim()})), 400); });", + ].join("\n"), + ); + chmodSync(fake, 0o755); + const origPath = process.env.PATH; + try { + const out = await createCodexAi( + { + PATH: `${dir}:${origPath ?? ""}`, + HOME: dir, + GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1", + CODEX_AI_TIMEOUT_MS: "30000", + // Shorter than the 400ms completion delay above, but the process must survive because output already + // arrived before this deadline — proving the fast-fail timer is truly cleared, not merely deferred. + CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "150", + }, + undefined, + noAuthCheck, + ).run("", { prompt: "hello" }); + expect(out.response).toBe("OK:hello"); + } finally { + process.env.PATH = origPath; + } + }, 10_000); + it("Claude Code throws on no-token / non-zero exit / empty output", async () => { await expect(createClaudeCodeAi({}).run("m", { prompt: "x" })).rejects.toThrow(/claude_code_no_oauth_token/); const exit1: StubSpawn = async () => ({ stdout: "", code: 1 }); @@ -1048,6 +1169,41 @@ describe("subscription CLI helpers + fail-safe", () => { ); }); + it("REGRESSION (GITTENSORY-K/GITTENSORY-M): a stalled-no-output timeout is thrown as codex_stalled_no_output, distinct from codex_timeout, and passes firstOutputTimeoutMs through to spawn", async () => { + let capturedOpts: { timeoutMs: number; firstOutputTimeoutMs?: number } | undefined; + const stalled: StubSpawn = async (_cmd, _args, o) => { + capturedOpts = o; + return { stdout: "", code: null, stderr: "Reading prompt from stdin...", timedOut: true, stalledNoOutput: true }; + }; + await expect( + createCodexAi({ GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1" }, stalled, noAuthCheck).run("m", { prompt: "x" }), + ).rejects.toThrow(/codex_stalled_no_output/); + // Never the generic message — the whole point is that these two failure modes are separately observable. + await expect( + createCodexAi({ GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1" }, stalled, noAuthCheck).run("m", { prompt: "x" }), + ).rejects.not.toThrow(/^codex_timeout/); + // The fast-fail deadline defaults to 30s and is strictly less than the (120s-default) full timeout. + expect(capturedOpts?.firstOutputTimeoutMs).toBe(30_000); + expect(capturedOpts?.timeoutMs).toBe(120_000); + expect(capturedOpts?.firstOutputTimeoutMs).toBeLessThan(capturedOpts!.timeoutMs); + }); + + it("clamps firstOutputTimeoutMs below timeoutMs even when CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS is configured >= the full timeout", async () => { + let capturedOpts: { timeoutMs: number; firstOutputTimeoutMs?: number } | undefined; + const ok: StubSpawn = async (_cmd, _args, o) => { + capturedOpts = o; + return { stdout: JSON.stringify({ type: "result", result: "hi" }), code: 0 }; + }; + await createCodexAi( + { GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1", CODEX_AI_TIMEOUT_MS: "30000", CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "30000" }, + ok, + noAuthCheck, + ).run("m", { prompt: "x" }); + expect(capturedOpts?.timeoutMs).toBe(30_000); + // Would otherwise equal timeoutMs and make the outer safety net unreachable — clamped to timeoutMs - 1. + expect(capturedOpts?.firstOutputTimeoutMs).toBe(29_999); + }); + it("Codex on timeout prefers the JSONL error, then falls back to stderr, then a literal when both are empty", async () => { const withJsonlError: StubSpawn = async () => ({ stdout: `${JSON.stringify({ type: "other" })}\n${JSON.stringify({ error: "model unavailable" })}`, @@ -1241,6 +1397,23 @@ describe("subscription CLI helpers + fail-safe", () => { } }); + it("defaultSpawn's spawn-error handler clears whichever timers were actually armed — firstOutputTimer present (codex) vs absent (claude-code)", async () => { + // Explicit env (no ambient CODEX_HOME / GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER inherited from the operator's + // shell) so this reaches the REAL ENOENT spawn error deterministically, rather than short-circuiting on the + // credential-isolation guard the way an ambient CODEX_HOME would. + await expect( + createCodexAi({ PATH: "/nonexistent-gittensory-empty", GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1" }, undefined, noAuthCheck).run( + "gpt-5", + { prompt: "x" }, + ), + ).rejects.toThrow(/ENOENT/); + // Claude Code never sets firstOutputTimeoutMs (no comparable prod hang), so this exercises the SAME spawn() + // error path's firstOutputTimer-ABSENT branch — the option is simply never passed for this provider. + await expect( + createClaudeCodeAi({ PATH: "/nonexistent-gittensory-empty", CLAUDE_CODE_OAUTH_TOKEN: "t" }).run("sonnet", { prompt: "x" }), + ).rejects.toThrow(/ENOENT/); + }); + it("extractCliText falls back to the last JSON line (JSONL) and is empty when none parse", () => { expect(extractCliText('not json\n{"result":"x"}')).toBe("x"); expect(extractCliText("not json\nstill not json")).toBe(""); From d32e83172fcbae59573d44dcb800a5ad70c72a4d Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Sun, 5 Jul 2026 00:34:09 -0700 Subject: [PATCH 2/2] fix(selfhost): clear the codex fast-fail deadline on stdout only, not stderr The fast-fail timer was cleared by data on either stream, but codex's own "Reading prompt from stdin..." startup banner is unconditional stderr output on every invocation -- it would satisfy the deadline immediately and never catch the exact hang (stderr banner, then silence forever) this fix was written for. Real JSONL progress from `codex --json` always lands on stdout, so only stdout now counts as liveness. Also regenerates the stale selfhost env-reference doc for the new CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS var. --- .../src/lib/selfhost-env-reference.ts | 61 +++++++++------- src/selfhost/ai.ts | 73 ++++++++++--------- test/unit/selfhost-ai.test.ts | 63 ++++++++++++++-- 3 files changed, 128 insertions(+), 69 deletions(-) diff --git a/apps/gittensory-ui/src/lib/selfhost-env-reference.ts b/apps/gittensory-ui/src/lib/selfhost-env-reference.ts index 1df3203372..b8944dcb4f 100644 --- a/apps/gittensory-ui/src/lib/selfhost-env-reference.ts +++ b/apps/gittensory-ui/src/lib/selfhost-env-reference.ts @@ -7,11 +7,11 @@ export type SelfHostEnvReferenceRow = { export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ { name: "AI_COMBINE", - firstReference: "src/selfhost/ai.ts:1080", + firstReference: "src/selfhost/ai.ts:1160", }, { name: "AI_DUAL_REVIEW", - firstReference: "src/selfhost/ai.ts:1055", + firstReference: "src/selfhost/ai.ts:1135", }, { name: "AI_EMBED_API_KEY", @@ -23,11 +23,11 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "AI_EMBED_MODEL", - firstReference: "src/selfhost/ai.ts:952", + firstReference: "src/selfhost/ai.ts:1032", }, { name: "AI_ON_MERGE", - firstReference: "src/selfhost/ai.ts:1082", + firstReference: "src/selfhost/ai.ts:1162", }, { name: "AI_PROVIDER", @@ -35,7 +35,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "ANTHROPIC_AI_BASE_URL", - firstReference: "src/selfhost/ai.ts:956", + firstReference: "src/selfhost/ai.ts:1036", }, { name: "ANTHROPIC_AI_MODEL", @@ -43,7 +43,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "ANTHROPIC_API_KEY", - firstReference: "src/selfhost/ai.ts:955", + firstReference: "src/selfhost/ai.ts:1035", }, { name: "BACKUP_ACKNOWLEDGED", @@ -69,6 +69,10 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ name: "CODEX_AI_EFFORT", firstReference: "src/selfhost/ai.ts:151", }, + { + name: "CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS", + firstReference: "src/selfhost/ai.ts:171", + }, { name: "CODEX_AI_MODEL", firstReference: "src/selfhost/ai.ts:92", @@ -79,7 +83,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "CODEX_HOME", - firstReference: "src/selfhost/ai.ts:318", + firstReference: "src/selfhost/ai.ts:340", }, { name: "CRON_INTERVAL_MS", @@ -151,7 +155,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "HOME", - firstReference: "src/selfhost/ai.ts:318", + firstReference: "src/selfhost/ai.ts:340", }, { name: "MAINTENANCE_ADMISSION_DEFER_MS", @@ -199,11 +203,11 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "OLLAMA_AI_API_KEY", - firstReference: "src/selfhost/ai.ts:949", + firstReference: "src/selfhost/ai.ts:1029", }, { name: "OLLAMA_AI_BASE_URL", - firstReference: "src/selfhost/ai.ts:945", + firstReference: "src/selfhost/ai.ts:1025", }, { name: "OLLAMA_AI_MODEL", @@ -211,7 +215,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "OPENAI_AI_BASE_URL", - firstReference: "src/selfhost/ai.ts:947", + firstReference: "src/selfhost/ai.ts:1027", }, { name: "OPENAI_AI_MODEL", @@ -219,15 +223,15 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "OPENAI_API_KEY", - firstReference: "src/selfhost/ai.ts:949", + firstReference: "src/selfhost/ai.ts:1029", }, { name: "OPENAI_COMPATIBLE_AI_API_KEY", - firstReference: "src/selfhost/ai.ts:949", + firstReference: "src/selfhost/ai.ts:1029", }, { name: "OPENAI_COMPATIBLE_AI_BASE_URL", - firstReference: "src/selfhost/ai.ts:948", + firstReference: "src/selfhost/ai.ts:1028", }, { name: "OPENAI_COMPATIBLE_AI_MODEL", @@ -390,25 +394,26 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ export const SELFHOST_ENV_REFERENCE_MARKDOWN = [ "| Name | First reference |", "| --- | --- |", - "| `AI_COMBINE` | `src/selfhost/ai.ts:1080` |", - "| `AI_DUAL_REVIEW` | `src/selfhost/ai.ts:1055` |", + "| `AI_COMBINE` | `src/selfhost/ai.ts:1160` |", + "| `AI_DUAL_REVIEW` | `src/selfhost/ai.ts:1135` |", "| `AI_EMBED_API_KEY` | `src/server.ts:441` |", "| `AI_EMBED_BASE_URL` | `src/server.ts:438` |", - "| `AI_EMBED_MODEL` | `src/selfhost/ai.ts:952` |", - "| `AI_ON_MERGE` | `src/selfhost/ai.ts:1082` |", + "| `AI_EMBED_MODEL` | `src/selfhost/ai.ts:1032` |", + "| `AI_ON_MERGE` | `src/selfhost/ai.ts:1162` |", "| `AI_PROVIDER` | `src/selfhost/ai-config.ts:43` |", - "| `ANTHROPIC_AI_BASE_URL` | `src/selfhost/ai.ts:956` |", + "| `ANTHROPIC_AI_BASE_URL` | `src/selfhost/ai.ts:1036` |", "| `ANTHROPIC_AI_MODEL` | `src/selfhost/ai.ts:96` |", - "| `ANTHROPIC_API_KEY` | `src/selfhost/ai.ts:955` |", + "| `ANTHROPIC_API_KEY` | `src/selfhost/ai.ts:1035` |", "| `BACKUP_ACKNOWLEDGED` | `src/server.ts:380` |", "| `BROWSER_WS_ENDPOINT` | `src/selfhost/stubs/puppeteer.ts:11` |", "| `CLAUDE_AI_EFFORT` | `src/selfhost/ai.ts:147` |", "| `CLAUDE_AI_MODEL` | `src/selfhost/ai.ts:88` |", "| `CLAUDE_AI_TIMEOUT_MS` | `src/selfhost/ai.ts:147` |", "| `CODEX_AI_EFFORT` | `src/selfhost/ai.ts:151` |", + "| `CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS` | `src/selfhost/ai.ts:171` |", "| `CODEX_AI_MODEL` | `src/selfhost/ai.ts:92` |", "| `CODEX_AI_TIMEOUT_MS` | `src/selfhost/ai.ts:151` |", - "| `CODEX_HOME` | `src/selfhost/ai.ts:318` |", + "| `CODEX_HOME` | `src/selfhost/ai.ts:340` |", "| `CRON_INTERVAL_MS` | `src/server.ts:919` |", "| `DATABASE_PATH` | `src/server.ts:250` |", "| `DATABASE_URL` | `src/selfhost/preflight.ts:201` |", @@ -426,7 +431,7 @@ export const SELFHOST_ENV_REFERENCE_MARKDOWN = [ "| `GITHUB_INSTALLATION_CONCURRENCY_LIMIT` | `src/selfhost/installation-concurrency-admission.ts:43` |", "| `GITTENSORY_REPO_CONFIG_DIR` | `src/server.ts:289` |", "| `GITTENSORY_VERSION` | `src/selfhost/otel.ts:62` |", - "| `HOME` | `src/selfhost/ai.ts:318` |", + "| `HOME` | `src/selfhost/ai.ts:340` |", "| `MAINTENANCE_ADMISSION_DEFER_MS` | `src/selfhost/maintenance-admission.ts:171` |", "| `MAINTENANCE_ADMISSION_DRAIN_AGE_MS` | `src/selfhost/maintenance-admission.ts:145` |", "| `MAINTENANCE_ADMISSION_ENABLED` | `src/selfhost/maintenance-admission.ts:126` |", @@ -438,14 +443,14 @@ export const SELFHOST_ENV_REFERENCE_MARKDOWN = [ "| `MIGRATIONS_DIR` | `src/server.ts:393` |", "| `OBSERVABILITY_SMOKE_POLL_MS` | `scripts/smoke-observability-traces.mjs:8` |", "| `OBSERVABILITY_SMOKE_TIMEOUT_MS` | `scripts/smoke-observability-traces.mjs:6` |", - "| `OLLAMA_AI_API_KEY` | `src/selfhost/ai.ts:949` |", - "| `OLLAMA_AI_BASE_URL` | `src/selfhost/ai.ts:945` |", + "| `OLLAMA_AI_API_KEY` | `src/selfhost/ai.ts:1029` |", + "| `OLLAMA_AI_BASE_URL` | `src/selfhost/ai.ts:1025` |", "| `OLLAMA_AI_MODEL` | `src/selfhost/ai.ts:100` |", - "| `OPENAI_AI_BASE_URL` | `src/selfhost/ai.ts:947` |", + "| `OPENAI_AI_BASE_URL` | `src/selfhost/ai.ts:1027` |", "| `OPENAI_AI_MODEL` | `src/selfhost/ai.ts:101` |", - "| `OPENAI_API_KEY` | `src/selfhost/ai.ts:949` |", - "| `OPENAI_COMPATIBLE_AI_API_KEY` | `src/selfhost/ai.ts:949` |", - "| `OPENAI_COMPATIBLE_AI_BASE_URL` | `src/selfhost/ai.ts:948` |", + "| `OPENAI_API_KEY` | `src/selfhost/ai.ts:1029` |", + "| `OPENAI_COMPATIBLE_AI_API_KEY` | `src/selfhost/ai.ts:1029` |", + "| `OPENAI_COMPATIBLE_AI_BASE_URL` | `src/selfhost/ai.ts:1028` |", "| `OPENAI_COMPATIBLE_AI_MODEL` | `src/selfhost/ai.ts:102` |", "| `ORB_AIR_GAP` | `src/selfhost/orb-collector.ts:161` |", "| `ORB_ANONYMIZE` | `src/selfhost/orb-collector.ts:174` |", diff --git a/src/selfhost/ai.ts b/src/selfhost/ai.ts index 8810dc7a04..ec519563b6 100644 --- a/src/selfhost/ai.ts +++ b/src/selfhost/ai.ts @@ -156,15 +156,17 @@ export function resolveCodexCliTimeoutMs(env: Record // on stdout before the FULL timeoutMs (up to 600_000ms at max effort) elapses and the process is SIGKILLed. That // full timeout is sized for a legitimately long-running review, so waiting it out to detect a completely dead // subprocess stalls the codex → claude-code fallback chain for up to 10 minutes per attempt. This is a SEPARATE, -// much shorter deadline: if not one single byte has arrived on EITHER stdout or stderr by this point, the process -// is almost certainly hung at the stdin-read step, not merely thinking — a working call, even a slow one under -// load, emits at least the startup banner well within this window. 30s default: long enough that a busy host -// (cold container start, contended CPU) doesn't false-positive on a merely-slow-to-start real call, short enough -// that the codex→claude-code fallback (or a caller retry) kicks in almost immediately instead of after a 10-minute -// stall. Independent of CODEX_AI_EFFORT/CODEX_AI_TIMEOUT_MS on purpose: a higher effort makes a COMPLETION take -// longer, it does not make the CLI slower to print its FIRST byte, so this must not scale with effort the way the -// full timeout does. Bounds mirror resolveCliTimeoutFrom's floor but cap well under the shortest full timeout -// (120_000ms) so this can never itself become the effective timeout. +// much shorter deadline: if not one single byte has arrived on STDOUT by this point, the process is almost +// certainly hung at the stdin-read step, not merely thinking. Deliberately STDOUT-ONLY, not "either stream" — +// the startup banner itself is unconditional stderr output on every invocation, so treating it as "alive" would +// let it satisfy this deadline forever and never catch the exact hang it exists to detect; real JSONL progress +// from `codex --json` always lands on stdout, so stdout is the only reliable liveness signal. 30s default: long +// enough that a busy host (cold container start, contended CPU) doesn't false-positive on a merely-slow-to-start +// real call, short enough that the codex→claude-code fallback (or a caller retry) kicks in almost immediately +// instead of after a 10-minute stall. Independent of CODEX_AI_EFFORT/CODEX_AI_TIMEOUT_MS on purpose: a higher +// effort makes a COMPLETION take longer, it does not make the CLI slower to print its FIRST stdout byte, so this +// must not scale with effort the way the full timeout does. Bounds mirror resolveCliTimeoutFrom's floor but cap +// well under the shortest full timeout (120_000ms) so this can never itself become the effective timeout. export function resolveCodexFirstOutputTimeoutMs(env: Record): number { const raw = Number(firstConfigured(env.CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS)); if (Number.isFinite(raw) && raw > 0) return Math.min(120_000, Math.max(1_000, raw)); @@ -540,10 +542,11 @@ type SpawnFn = ( input?: string; timeoutMs: number; cwd?: string; - // Optional, generic on SpawnFn (not codex-specific) so any CLI with the same "prints a startup banner then - // hangs" shape could opt in later — but ONLY codex wires it up today (see resolveCodexFirstOutputTimeoutMs): - // Claude Code has no comparable prod-observed dead-air hang, so leaving this undefined for that caller keeps - // its spawn path byte-identical to before this option existed. + // Optional, generic on SpawnFn (not codex-specific) so any CLI whose real progress lands on STDOUT (not + // stderr banners/logs) could opt in later — but ONLY codex wires it up today (see + // resolveCodexFirstOutputTimeoutMs): Claude Code has no comparable prod-observed dead-air hang, so leaving + // this undefined for that caller keeps its spawn path byte-identical to before this option existed. See the + // stdout-only rationale on the timer construction below — this deadline is cleared by stdout data ONLY. firstOutputTimeoutMs?: number; }, ) => Promise<{ stdout: string; code: number | null; stderr?: string; timedOut?: boolean; stalledNoOutput?: boolean }>; @@ -558,7 +561,7 @@ async function defaultSpawn(): Promise { // Capture stderr too — the CLI's actual error (auth, rate limit, model-not-supported, OOM) lands here, and // it's what makes a `claude_code_exit_1` / `codex_exit_1` diagnosable instead of an opaque exit code (#26). let stderr = ""; - let sawAnyOutput = false; + let sawStdout = false; /* v8 ignore start */ // a 120s subprocess timeout is not unit-testable without a 2-minute wait const timer = setTimeout(() => { child.kill("SIGKILL"); @@ -567,12 +570,17 @@ async function defaultSpawn(): Promise { resolve({ stdout, code: null, stderr, timedOut: true }); }, o.timeoutMs); /* v8 ignore stop */ - // Fast-fail deadline (GITTENSORY-K/GITTENSORY-M): a SEPARATE, shorter timer that only fires if NEITHER - // stdout nor stderr has produced a single byte by firstOutputTimeoutMs — cleared the instant any data - // arrives on either stream, same as the full timer is cleared on `close`/`error`. This catches codex's - // "printed only the startup banner, then total silence" hang far sooner than the full timeoutMs, without - // touching the full timer at all: if output DOES start flowing but then stalls later, only the full - // timeoutMs above still governs — this timer has already been cleared by the first byte and never fires. + // Fast-fail deadline (GITTENSORY-K/GITTENSORY-M): a SEPARATE, shorter timer that only fires if STDOUT has + // not produced a single byte by firstOutputTimeoutMs — cleared the instant any data arrives on stdout, same + // as the full timer is cleared on `close`/`error`. Deliberately STDOUT-ONLY, not "either stream": codex's + // own "Reading prompt from stdin..." startup banner is written to STDERR unconditionally, on every + // invocation, whether or not it goes on to actually process anything — clearing on stderr too would let + // that banner alone satisfy the deadline forever, which is exactly the real hang this exists to catch + // (confirmed as a defect during review: the first version of this fix cleared on either stream and would + // never have fired for the actual "banner then silence" failure mode). Real JSONL progress from codex + // (`--json`) always lands on stdout, so stdout is the only reliable "codex is genuinely alive" signal. If + // output DOES start flowing on stdout but then stalls later, only the full timeoutMs above still governs — + // this timer has already been cleared by the first stdout byte and never fires. const firstOutputTimer = o.firstOutputTimeoutMs != null ? /* v8 ignore start */ // real-timer path; tests inject a fake spawnImpl instead of racing setTimeout @@ -582,17 +590,14 @@ async function defaultSpawn(): Promise { }, o.firstOutputTimeoutMs) : /* v8 ignore stop */ undefined; - const onFirstOutput = (): void => { - if (sawAnyOutput) return; - sawAnyOutput = true; - if (firstOutputTimer) clearTimeout(firstOutputTimer); - }; child.stdout?.on("data", (d: Buffer) => { - onFirstOutput(); + if (!sawStdout) { + sawStdout = true; + if (firstOutputTimer) clearTimeout(firstOutputTimer); + } stdout += d.toString("utf8"); }); child.stderr?.on("data", (d: Buffer) => { - onFirstOutput(); stderr += d.toString("utf8"); }); child.on("error", (e) => { @@ -780,12 +785,14 @@ export function createCodexAi( stdoutForMetrics = stdout; if (timedOut && stalledNoOutput) { // Fast-fail path (GITTENSORY-K/GITTENSORY-M): killed at firstOutputTimeoutMs, well before the full - // timeoutMs, because NEITHER stdout nor stderr produced a single byte — the "Reading prompt from - // stdin..." hang where codex prints its own startup banner and then never emits any JSONL. A DISTINCT - // error (never reusing `codex_timeout`) so this fast-fail is separately countable in Sentry/logs from a - // genuine full-timeout case where the process was at least doing something before it was killed — - // that distinction is what lets an operator tell "codex never started" apart from "codex hung mid-review". - throw new Error("codex_stalled_no_output: no stdout/stderr within firstOutputTimeoutMs — codex likely hung reading stdin"); + // timeoutMs, because STDOUT produced no bytes at all — the "Reading prompt from stdin..." hang where + // codex prints its own startup banner to STDERR and then never emits any JSONL. Stdout-only is + // deliberate: that banner would otherwise satisfy an "either stream" deadline on every single + // invocation, defeating the point. A DISTINCT error (never reusing `codex_timeout`) so this fast-fail + // is separately countable in Sentry/logs from a genuine full-timeout case where the process was at + // least emitting JSONL before it was killed — that distinction is what lets an operator tell "codex + // never started" apart from "codex hung mid-review". + throw new Error("codex_stalled_no_output: no stdout within firstOutputTimeoutMs — codex likely hung reading stdin"); } if (timedOut) { // Include whatever the JSONL stream captured before the kill — codex writes errors there, not to stderr. diff --git a/test/unit/selfhost-ai.test.ts b/test/unit/selfhost-ai.test.ts index 686387f167..d688f91172 100644 --- a/test/unit/selfhost-ai.test.ts +++ b/test/unit/selfhost-ai.test.ts @@ -1104,19 +1104,63 @@ describe("subscription CLI helpers + fail-safe", () => { } }); - // (c) output arrives within the fast-fail window but full completion takes longer than that window — must NOT - // be prematurely killed by the fast-fail path; only the (much larger) full timeoutMs still governs it. - it("REAL subprocess: output within the fast-fail window but a slow completion is governed only by the full timeoutMs, not fast-failed", async () => { + // REGRESSION (caught in review of the first version of this fix): a fake codex that writes ONLY the real + // "Reading prompt from stdin..." banner to STDERR — exactly what prod codex does on every invocation — and + // then produces NOTHING on stdout and never exits. The first version of this fix cleared the fast-fail timer + // on EITHER stream, so a stderr-only banner would have satisfied it forever and this exact hang (the one + // GITTENSORY-K/M is actually about) would never have been caught until the full timeout. Must still fast-fail. + it("REAL subprocess: a fake codex that writes ONLY the stderr startup banner and nothing on stdout is still killed at the fast-fail deadline", async () => { const dir = mkdtempSync(join(tmpdir(), "fakecli-")); const fake = join(dir, "codex"); - // Writes stderr immediately (clearing the fast-fail timer), then waits LONGER than the fast-fail deadline - // (but well inside the full timeout) before completing — proving the first timer's clearance is permanent - // and the process is not killed once data has already flowed. writeFileSync( fake, [ "#!/usr/bin/env node", "process.stderr.write('Reading prompt from stdin...');", + "process.stdin.on('data',()=>{});", + "setInterval(()=>{},1000);", + ].join("\n"), + ); + chmodSync(fake, 0o755); + const origPath = process.env.PATH; + try { + const start = Date.now(); + await expect( + createCodexAi( + { + PATH: `${dir}:${origPath ?? ""}`, + HOME: dir, + GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1", + CODEX_AI_TIMEOUT_MS: "60000", + CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "200", + }, + undefined, + noAuthCheck, + ).run("", { prompt: "hello" }), + ).rejects.toThrow(/codex_stalled_no_output/); + expect(Date.now() - start).toBeLessThan(5_000); + } finally { + process.env.PATH = origPath; + } + }, 10_000); + + // (c) output arrives on STDOUT within the fast-fail window but full completion takes longer than that window + // — must NOT be prematurely killed by the fast-fail path; only the (much larger) full timeoutMs still governs + // it. Also writes the real stderr banner first (matching a genuinely-working codex invocation) to prove stderr + // output alone is correctly ignored and it's the STDOUT byte that clears the deadline. + it("REAL subprocess: stdout output within the fast-fail window but a slow completion is governed only by the full timeoutMs, not fast-failed", async () => { + const dir = mkdtempSync(join(tmpdir(), "fakecli-")); + const fake = join(dir, "codex"); + // Writes the stderr banner immediately (must NOT clear the fast-fail timer), then a stdout byte shortly after + // (which DOES clear it), then waits LONGER than the fast-fail deadline (but well inside the full timeout) + // before completing — proving the stdout timer's clearance is permanent and the process is not killed once + // real output has already flowed. + writeFileSync( + fake, + [ + "#!/usr/bin/env node", + "process.stderr.write('Reading prompt from stdin...');", + "setTimeout(()=>process.stdout.write(' '), 50);", "let i='';process.stdin.on('data',d=>i+=d);", "process.stdin.on('end',()=>{ setTimeout(()=>process.stdout.write(JSON.stringify({type:'result',result:'OK:'+i.trim()})), 400); });", ].join("\n"), @@ -1130,13 +1174,16 @@ describe("subscription CLI helpers + fail-safe", () => { HOME: dir, GITTENSORY_ENABLE_UNSAFE_CODEX_REVIEWER: "1", CODEX_AI_TIMEOUT_MS: "30000", - // Shorter than the 400ms completion delay above, but the process must survive because output already - // arrived before this deadline — proving the fast-fail timer is truly cleared, not merely deferred. + // Shorter than the 400ms completion delay above, but the process must survive because a stdout byte + // already arrived (at ~50ms) before this deadline — proving the fast-fail timer is truly cleared by + // stdout, not merely deferred, and that the earlier stderr banner did not itself clear anything. CODEX_AI_FIRST_OUTPUT_TIMEOUT_MS: "150", }, undefined, noAuthCheck, ).run("", { prompt: "hello" }); + // extractCliText trims the whole stdout string first, so the leading space byte (written purely to clear + // the fast-fail timer at ~50ms) disappears before JSON parsing — the parsed result is exactly "OK:hello". expect(out.response).toBe("OK:hello"); } finally { process.env.PATH = origPath;