Skip to content

Commit bf1d500

Browse files
authored
fix(ai): stop a buffered-CLI timeout burning the full retry budget, and two subprocess leaks (#9476, #9479) (#9505)
claude --output-format json buffers its whole response, so ANY run exceeding its effort timeout has produced zero stdout when the deadline lands -- which trips the first-output watchdog and throws claude_stalled_no_output rather than subscription_cli_timeout. The retry-break tested for the latter by strict string equality, so it never matched: every timed-out review burned all three attempts (3x180s at default effort, 3x600s at the top tier) before the fallback model was tried at all. With QUEUE_CONCURRENCY defaulting to 8 that parks the whole queue during a provider slowdown, and the per-provider circuit breaker needs three FULL-LENGTH failures before it trips. Matched by prefix, since these errors carry a detail suffix -- the strict equality is the original bug. subscription_cli_timeout was effectively unreachable for claude-code, making #3987's fix dead code on this deployment. child.on("error") catches spawn failures only; it never receives stdio stream errors. A CLI that exits before draining stdin (an unknown flag on an upgraded binary, an auth abort, an OOM kill) made the ~250KB stdin write fail with EPIPE on an emitter with no error listener, which Node escalates to an uncaught exception -> exit(1), taking down every in-flight queue job in the container. Per-call temp dirs were never removed. Every AI review minted one and, where repo review instructions are configured, wrote the composed system prompt into it -- so they accumulated on the container's writable overlay layer until recreation, leaving those instructions on disk indefinitely. Removed in the same finally that records CLI usage metrics, best-effort so a cleanup failure can never turn a completed review into a thrown error. The systemAppend test now reads the appended-prompt file inside the spawn stub rather than after the call returns, and additionally asserts the directory does not outlive the call -- which is both the new behaviour and a closer match to how the file is actually used.
1 parent b5cfc9a commit bf1d500

4 files changed

Lines changed: 100 additions & 6 deletions

File tree

src/selfhost/ai.ts

Lines changed: 29 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -598,6 +598,21 @@ async function isolatedCliCwd(): Promise<string> {
598598
return mkdtemp(join(tmpdir(), "loopover-ai-"));
599599
}
600600

601+
/** #9479: remove a per-call temp dir once the subprocess is done with it. Nothing removed these: every AI review
602+
* call minted one (and, when repo review instructions are configured, wrote the composed system prompt into it),
603+
* so they accumulated on the container's writable overlay layer until it was recreated -- and left those repo
604+
* instructions on disk indefinitely. Best-effort by design: a cleanup failure must never turn a completed
605+
* review into a thrown error, and the next container recreation still collects anything missed. */
606+
async function removeIsolatedCliCwd(cwd: string | undefined): Promise<void> {
607+
if (!cwd) return;
608+
try {
609+
const { rm } = await import("node:fs/promises");
610+
await rm(cwd, { recursive: true, force: true });
611+
} catch {
612+
// best-effort -- see the doc comment.
613+
}
614+
}
615+
601616
/** Write `systemAppend` into `cwd` (the SAME per-call isolated temp dir already used for the subprocess's
602617
* cwd, so it shares that directory's lifecycle) and return its path, for `--append-system-prompt-file`.
603618
* Keeps repo review instructions out of argv/`ps aux` (#3951's concern) WITHOUT falling back to smuggling
@@ -903,6 +918,13 @@ async function defaultSpawn(): Promise<SpawnFn> {
903918
resolve({ stdout, code, stderr });
904919
});
905920
if (o.input != null) {
921+
// #9479: `child.on("error")` catches SPAWN failures only -- it never receives stdio stream errors. If
922+
// the CLI exits before draining stdin (an unknown flag on an upgraded binary, an immediate auth abort,
923+
// an OOM kill), this ~250KB write fails with EPIPE on an emitter with no "error" listener, which Node
924+
// escalates to an uncaught exception -> installSelfHostCrashHandlers -> exit(1), taking down every
925+
// in-flight queue job in the container. The real failure is already surfaced by the exit-code and
926+
// empty-output guards below, so swallowing the stream error here loses no diagnostic.
927+
child.stdin?.on("error", () => undefined);
906928
child.stdin?.write(o.input);
907929
child.stdin?.end();
908930
}
@@ -997,6 +1019,7 @@ export function createClaudeCodeAi(parentEnv: Record<string, string | undefined>
9971019
);
9981020
let attempted = false;
9991021
let stdoutForMetrics = "";
1022+
let cliCwd: string | undefined;
10001023
try {
10011024
if (!token) throw new Error("claude_code_no_oauth_token");
10021025
// Usage telemetry (#claude-code-otel-passthrough): the allowlist deliberately excludes these -- they are
@@ -1019,7 +1042,8 @@ export function createClaudeCodeAi(parentEnv: Record<string, string | undefined>
10191042
const systemAppend = normalizedSystemAppend(options);
10201043
const prompt = toCliPrompt(options, systemAppend);
10211044
const spawn = spawnImpl ?? (await defaultSpawn());
1022-
const cwd = await isolatedCliCwd();
1045+
cliCwd = await isolatedCliCwd();
1046+
const cwd = cliCwd;
10231047
// Keep bypassPermissions (not "plan") only to avoid a headless approval prompt; the actual boundary is
10241048
// tool removal. --tools "" removes every built-in tool, --strict-mcp-config prevents user/home MCP config
10251049
// from loading, and mcp__* is a defense-in-depth deny for CLIs that still have MCP tools available. This
@@ -1088,6 +1112,7 @@ export function createClaudeCodeAi(parentEnv: Record<string, string | undefined>
10881112
throw error;
10891113
} finally {
10901114
if (attempted) recordCliUsageMetrics("claude-code", claudeModel, effort, stdoutForMetrics);
1115+
await removeIsolatedCliCwd(cliCwd);
10911116
}
10921117
},
10931118
};
@@ -1119,6 +1144,7 @@ export function createCodexAi(
11191144
);
11201145
let attempted = false;
11211146
let stdoutForMetrics = "";
1147+
let cliCwd: string | undefined;
11221148
try {
11231149
assertCodexCredentialIsolation(parentEnv);
11241150
await authCheckImpl(parentEnv);
@@ -1136,7 +1162,7 @@ export function createCodexAi(
11361162
input: prompt,
11371163
timeoutMs,
11381164
firstOutputTimeoutMs,
1139-
cwd: await isolatedCliCwd(),
1165+
cwd: (cliCwd = await isolatedCliCwd()),
11401166
});
11411167
stdoutForMetrics = stdout;
11421168
if (timedOut && stalledNoOutput) {
@@ -1190,6 +1216,7 @@ export function createCodexAi(
11901216
throw error;
11911217
} finally {
11921218
if (attempted) recordCliUsageMetrics("codex", codexModel, effort, stdoutForMetrics);
1219+
await removeIsolatedCliCwd(cliCwd);
11931220
}
11941221
},
11951222
};

src/services/ai-review.ts

Lines changed: 20 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1380,6 +1380,25 @@ function isSubscriptionCliTimeout(error: unknown): boolean {
13801380
return error instanceof Error && error.message === "subscription_cli_timeout";
13811381
}
13821382

1383+
/**
1384+
* #9476: the CLI adapter's OTHER non-transient deadline signal, and in practice the one that actually fires.
1385+
* `claude --output-format json` buffers its whole response, so any run that exceeds its effort timeout has
1386+
* produced zero stdout bytes when the deadline lands -- which trips the first-output watchdog
1387+
* (`resolveClaudeFirstOutputTimeoutMs`, clamped to `timeoutMs - 1`) rather than the plain timeout. The adapter
1388+
* therefore throws `claude_stalled_no_output: <detail>` and `subscription_cli_timeout` is effectively
1389+
* unreachable for claude-code, so the strict-equality check above never matched and every timed-out review
1390+
* burned all three attempts: 3 x 180s at default effort, 3 x 600s at the top tier, before the fallback model
1391+
* was even tried. With QUEUE_CONCURRENCY defaulting to 8 that parks the whole queue during a provider
1392+
* slowdown, and the per-provider circuit breaker needs three FULL-LENGTH failures before it trips.
1393+
*
1394+
* Matched by PREFIX because these carry a `: detail` suffix -- the strict equality that missed this case is
1395+
* exactly the bug.
1396+
*/
1397+
function isStalledNoOutput(error: unknown): boolean {
1398+
if (!(error instanceof Error)) return false;
1399+
return error.message.startsWith("claude_stalled_no_output") || error.message.startsWith("codex_stalled_no_output");
1400+
}
1401+
13831402
/** True for a provider's own HTTP-429 signal (`src/selfhost/ai.ts`'s `claude_code_error_429` /
13841403
* `ai_http_429` / `anthropic_http_429`, and the generic Workers-AI equivalent). #5385-sentry
13851404
* (GITTENSORY-K/8): an immediate same-model retry against a rate limit that is still in its window has
@@ -1633,7 +1652,7 @@ async function runWorkersOpinion(
16331652
// A structural config error (missing/expired credentials) is stronger still: it is DETERMINISTIC, not
16341653
// just unlikely to clear in time -- the same model will fail the identical way on attempt 2 and 3 too,
16351654
// confirmed live (GITTENSORY-K/8: 2094 + 544 events over 16 days from one never-fixed misconfiguration).
1636-
if (isSubscriptionCliTimeout(error) || isRateLimitError(error) || isStructuralProviderConfigError(error)) break;
1655+
if (isSubscriptionCliTimeout(error) || isStalledNoOutput(error) || isRateLimitError(error) || isStructuralProviderConfigError(error)) break;
16371656
}
16381657
}
16391658
}

test/unit/ai-review.test.ts

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3515,6 +3515,46 @@ describe("pure helpers", () => {
35153515
expect(run).toHaveBeenCalledTimes(2); // 1 primary (timed out) + 1 fallback (succeeded on its first try).
35163516
});
35173517

3518+
// #9476 regression: `claude --output-format json` buffers its whole response, so ANY run that exceeds its
3519+
// effort timeout has produced zero stdout when the deadline lands -- tripping the first-output watchdog and
3520+
// throwing `claude_stalled_no_output: <detail>` rather than `subscription_cli_timeout`. The break condition
3521+
// tested above used strict equality, so it never matched: every timed-out review burned all three attempts
3522+
// (3 x 180s at default effort, 3 x 600s at the top tier) before the fallback was even tried, and at
3523+
// QUEUE_CONCURRENCY=8 that parks the whole queue during a provider slowdown. The suffix is why prefix
3524+
// matching is required -- strict equality is the original bug.
3525+
it.each([
3526+
["claude_stalled_no_output: no stdout within firstOutputTimeoutMs — claude likely hung"],
3527+
["codex_stalled_no_output: no stdout within firstOutputTimeoutMs — codex likely hung reading stdin"],
3528+
])("REGRESSION (#9476): runWorkersOpinion stops retrying after ONE %s", async (message) => {
3529+
let primaryAttempts = 0;
3530+
const run = vi.fn(async (model: string) => {
3531+
if (model === "fallback") return { response: reviewJson() };
3532+
primaryAttempts += 1;
3533+
throw new Error(message);
3534+
});
3535+
const env = createTestEnv({ AI: { run } as unknown as Ai });
3536+
const diagnostics: Array<{ status: string; model: string }> = [];
3537+
const parsed = await runWorkersOpinion(env, "primary", "fallback", "sys", "user", 256, diagnostics as never);
3538+
expect(parsed.review?.assessment).toContain("reasonable");
3539+
expect(primaryAttempts).toBe(1); // NOT 3 -- the stall short-circuits further retries of this model.
3540+
expect(run).toHaveBeenCalledTimes(2); // 1 primary (stalled) + 1 fallback (succeeded on its first try).
3541+
});
3542+
3543+
it("REGRESSION (#9476): a genuinely transient error still gets the FULL retry budget (the break is narrow)", async () => {
3544+
// Guards against over-broadening the break: only the non-transient deadline/rate-limit/config signals
3545+
// short-circuit. A dropped connection must still be retried up to the budget.
3546+
let primaryAttempts = 0;
3547+
const run = vi.fn(async (model: string) => {
3548+
if (model === "fallback") return { response: reviewJson() };
3549+
primaryAttempts += 1;
3550+
throw new Error("ECONNRESET");
3551+
});
3552+
const env = createTestEnv({ AI: { run } as unknown as Ai });
3553+
const diagnostics: Array<{ status: string; model: string }> = [];
3554+
await runWorkersOpinion(env, "primary", "fallback", "sys", "user", 256, diagnostics as never);
3555+
expect(primaryAttempts).toBe(3);
3556+
});
3557+
35183558
it("REGRESSION (#5385-sentry, GITTENSORY-K/8): runWorkersOpinion stops retrying a model after ONE 429 rate-limit error, same as a CLI timeout", async () => {
35193559
let primaryAttempts = 0;
35203560
const run = vi.fn(async (model: string) => {

test/unit/selfhost-ai.test.ts

Lines changed: 11 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
import { chmodSync, mkdirSync, mkdtempSync, readFileSync, writeFileSync } from "node:fs";
1+
import { chmodSync, existsSync, mkdirSync, mkdtempSync, readFileSync, writeFileSync } from "node:fs";
22
import { tmpdir } from "node:os";
33
import { delimiter, join } from "node:path";
44
import { afterEach, describe, expect, it, vi } from "vitest";
@@ -1603,9 +1603,15 @@ describe("subscription CLI helpers + fail-safe", () => {
16031603
const systemAppend = "REPOSITORY REVIEW INSTRUCTIONS: Follow async-error conventions.";
16041604
let seen: string[] = [];
16051605
let capturedInput = "";
1606+
// #9479: the per-call temp dir is now removed once the subprocess finishes, so the appended-prompt file
1607+
// must be read WHILE the CLI would still be running -- i.e. inside the spawn stub -- not after the call
1608+
// returns. Reading it here also matches reality more closely: the file exists exactly for the CLI's lifetime.
1609+
let capturedSystemAppendFile: string | undefined;
16061610
const cap: StubSpawn = async (_c, a, o) => {
16071611
seen = a;
16081612
capturedInput = o.input ?? "";
1613+
const flagAt = a.indexOf("--append-system-prompt-file");
1614+
if (flagAt > -1) capturedSystemAppendFile = readFileSync(a[flagAt + 1] as string, "utf8");
16091615
return { stdout: JSON.stringify({ type: "result", result: "ok" }), code: 0 };
16101616
};
16111617
await createClaudeCodeAi({ CLAUDE_CODE_OAUTH_TOKEN: "t" }, cap).run("", {
@@ -1625,8 +1631,10 @@ describe("subscription CLI helpers + fail-safe", () => {
16251631
expect(capturedInput).toContain("Review this diff.");
16261632
const flagIndex = seen.indexOf("--append-system-prompt-file");
16271633
expect(flagIndex).toBeGreaterThan(-1);
1628-
const filePath = seen[flagIndex + 1] as string;
1629-
expect(readFileSync(filePath, "utf8")).toBe(systemAppend);
1634+
expect(capturedSystemAppendFile).toBe(systemAppend);
1635+
// ... and the directory holding it does not outlive the call (#9479): these dirs accumulated on the
1636+
// container's writable layer forever, with repo review instructions left on disk.
1637+
expect(existsSync(seen[flagIndex + 1] as string)).toBe(false);
16301638

16311639
await createClaudeCodeAi({ CLAUDE_CODE_OAUTH_TOKEN: "t" }, cap).run("", {
16321640
prompt: "Review this diff.",

0 commit comments

Comments
 (0)