From c5d8d3a1bf50a66c4f17e2e9a89565332aaa6ae3 Mon Sep 17 00:00:00 2001 From: Edgar Durand Date: Thu, 22 Oct 2026 18:42:55 -0300 Subject: [PATCH] fix(cli): end an opencode turn on its terminal provider error MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit opencode logs a provider error ("stream error … Free usage limit reached") and keeps retrying, but never reports it over ACP: the prompt stays open with no update until the 90 s idle watchdog trips and the user gets a generic retry bubble. On 2026-10-22 OpenCode Zen's free quota ran out for every Box (they share fleet-1's egress IP) and half the opencode turns of the day failed that way, for all four opencode users. - spawn `opencode acp --print-logs --log-level ERROR` so its errors reach the adapter stderr we already read; - AdapterSpec.fatalTurnStderr: a matching line ends the in-flight prompt at once and cancels the turn (opencode would keep retrying); - a free-limit failure gets its own bubble (add a key, switch agent, or OpenCode Go) and the cli_turn code AGENT_FREE_LIMIT. Only terminal errors match (free limit, quota, invalid key, unauthorized); rate limits and 5xx stay with opencode's own retry. Co-Authored-By: Claude Opus 5.5 --- .../agents/acp.fatalTurnStderr.test.ts | 143 ++++++++++++++++++ apps/cli/src/agents/acp/adapters.ts | 28 +++- apps/cli/src/agents/acp/client.ts | 76 +++++++--- apps/cli/src/agents/acp/command-handlers.ts | 6 +- apps/cli/src/agents/acp/failure-messages.ts | 24 +++ 5 files changed, 254 insertions(+), 23 deletions(-) create mode 100644 apps/cli/__tests__/agents/acp.fatalTurnStderr.test.ts diff --git a/apps/cli/__tests__/agents/acp.fatalTurnStderr.test.ts b/apps/cli/__tests__/agents/acp.fatalTurnStderr.test.ts new file mode 100644 index 00000000..9f53e6be --- /dev/null +++ b/apps/cli/__tests__/agents/acp.fatalTurnStderr.test.ts @@ -0,0 +1,143 @@ +/** + * opencode keeps a turn open forever after a terminal provider error: it logs + * `message="stream error"` and retries, but never answers the ACP prompt. On + * 2026-10-22 OpenCode Zen's free quota ran out for every Box (they share one + * egress IP) and each message hung 90 s, then failed with the generic idle + * bubble. The client now ends the turn on the first such stderr line, cancels + * it (opencode would keep retrying), and the bubble names the real cause. + */ + +import { describe, expect, it, vi } from 'vitest'; + +vi.mock('../../src/agents/acp/idleTimeout', () => ({ + createIdleTimeout: () => ({ + promise: new Promise(() => {}), + bump: () => {}, + suspend: () => {}, + clear: () => {}, + }), +})); + +import { AcpClient, agentErrorOf, type AcpClientOptions } from '../../src/agents/acp/client'; +import { OPENCODE_FATAL_TURN_STDERR_RE, getAcpAdapter } from '../../src/agents/acp/adapters'; +import { AGENT_FREE_LIMIT_MESSAGE, failureBubble } from '../../src/agents/acp/failure-messages'; + +// Verbatim from a Box's `opencode acp --print-logs --log-level ERROR` (2026-10-22). +const FREE_LIMIT_LINE = + 'timestamp=2026-10-22T21:38:33.582Z level=ERROR run=fc660dd6 message="stream error" providerID=opencode modelID=big-pickle session.id=ses_e9a72d54bffeSlhGZ7xjQunKvi small=false agent=build mode=primary error.error="AI_APICallError: Free usage limit reached. Subscribe to OpenCode Go to keep going: https://opencode.ai/go"'; +const RATE_LIMIT_LINE = + 'timestamp=2026-10-22T21:38:33.582Z level=ERROR run=fc660dd6 message="stream error" providerID=openrouter modelID=x session.id=ses_1 error.error="AI_APICallError: Rate limit exceeded, retry in 10s"'; +const SERVER_ERROR_LINE = + 'timestamp=2026-10-22T21:38:33.582Z level=ERROR run=fc660dd6 message="stream error" providerID=anthropic modelID=x session.id=ses_1 error.error="AI_APICallError: Internal server error"'; + +interface ClientInternals { + connection: { + prompt: (p: unknown) => Promise; + cancel: (p: unknown) => Promise; + } | null; + sessionId: string | null; + fatalTurnStderr: RegExp | null; + onAdapterStderrLine(line: string): void; +} + +function clientWithOpenTurn() { + const client = new AcpClient({ + adapter: { command: 'opencode', args: [] }, + cwd: '/tmp', + onSessionUpdate: () => {}, + } as unknown as AcpClientOptions); + const internals = client as unknown as ClientInternals; + let answer: (v: unknown) => void = () => {}; + const cancel = vi.fn(async () => answer({ stopReason: 'cancelled' })); + internals.connection = { + // Never answers on its own — exactly what opencode does after the error. + prompt: () => new Promise((resolve) => (answer = resolve)), + cancel, + }; + internals.sessionId = 'ses_1'; + internals.fatalTurnStderr = OPENCODE_FATAL_TURN_STDERR_RE; + return { client, internals, cancel }; +} + +describe('opencode fatal turn errors', () => { + it('the pattern catches terminal errors only', () => { + expect(OPENCODE_FATAL_TURN_STDERR_RE.test(FREE_LIMIT_LINE)).toBe(true); + expect( + OPENCODE_FATAL_TURN_STDERR_RE.test( + FREE_LIMIT_LINE.replace( + /error\.error="[^"]+"/, + 'error.error="AI_APICallError: Invalid API key"', + ), + ), + ).toBe(true); + // opencode retries these on its own; ending the turn would cut a recovery. + expect(OPENCODE_FATAL_TURN_STDERR_RE.test(RATE_LIMIT_LINE)).toBe(false); + expect(OPENCODE_FATAL_TURN_STDERR_RE.test(SERVER_ERROR_LINE)).toBe(false); + }); + + it('pulls the agent error out of the log line', () => { + expect(agentErrorOf(FREE_LIMIT_LINE)).toBe( + 'AI_APICallError: Free usage limit reached. Subscribe to OpenCode Go to keep going: https://opencode.ai/go', + ); + expect(agentErrorOf('plain text')).toBe('plain text'); + }); + + it('ends the turn on the first fatal line and cancels it', async () => { + const { client, internals, cancel } = clientWithOpenTurn(); + const turn = client.prompt('hola'); + await new Promise((r) => setImmediate(r)); + internals.onAdapterStderrLine(FREE_LIMIT_LINE); + await expect(turn).rejects.toThrow( + /^AGENT_TURN_FAILED: AI_APICallError: Free usage limit reached/, + ); + expect(cancel).toHaveBeenCalledWith({ sessionId: 'ses_1' }); + }); + + it('a retryable error leaves the turn running', async () => { + const { client, internals, cancel } = clientWithOpenTurn(); + let settled = false; + const turn = client.prompt('hola').finally(() => (settled = true)); + await new Promise((r) => setImmediate(r)); + internals.onAdapterStderrLine(RATE_LIMIT_LINE); + await new Promise((r) => setImmediate(r)); + expect(settled).toBe(false); + expect(cancel).not.toHaveBeenCalled(); + internals.onAdapterStderrLine(FREE_LIMIT_LINE); + await expect(turn).rejects.toThrow(/AGENT_TURN_FAILED/); + }); + + it('a fatal line outside a turn is only logged', () => { + const { internals } = clientWithOpenTurn(); + expect(() => internals.onAdapterStderrLine(FREE_LIMIT_LINE)).not.toThrow(); + }); + + it('the bubble names the free limit and the ways forward', () => { + const bubble = failureBubble({ + detail: `AGENT_TURN_FAILED: ${agentErrorOf(FREE_LIMIT_LINE)}`, + recentStderr: FREE_LIMIT_LINE, + hadText: false, + agent: 'opencode', + env: {}, + }); + expect(bubble).toBe(AGENT_FREE_LIMIT_MESSAGE); + expect(bubble).toContain('Profile › Agents'); + }); + + it('a partial reply still gets the free-limit bubble', () => { + expect( + failureBubble({ + detail: 'AGENT_TURN_FAILED: Free usage limit reached.', + recentStderr: '', + hadText: true, + agent: 'opencode', + env: {}, + }), + ).toBe(AGENT_FREE_LIMIT_MESSAGE); + }); + + it('opencode is launched with its errors on stderr and the fatal pattern', () => { + const spec = getAcpAdapter('opencode'); + expect(spec?.args).toEqual(['acp', '--print-logs', '--log-level', 'ERROR']); + expect(spec?.fatalTurnStderr).toBe(OPENCODE_FATAL_TURN_STDERR_RE); + }); +}); diff --git a/apps/cli/src/agents/acp/adapters.ts b/apps/cli/src/agents/acp/adapters.ts index 8077187a..921f4378 100644 --- a/apps/cli/src/agents/acp/adapters.ts +++ b/apps/cli/src/agents/acp/adapters.ts @@ -65,8 +65,30 @@ export interface AdapterSpec { * happy path (binary already present → zero delay). */ waitForBinary(opts?: { timeoutMs?: number }): Promise; + /** + * Adapter stderr lines that END the in-flight turn: the agent hit an error it + * will never recover from on its own, but keeps the ACP prompt open (no + * update, no response) — see {@link OPENCODE_FATAL_TURN_STDERR_RE}. The client + * fails the prompt on the first match instead of waiting out the idle window. + */ + fatalTurnStderr?: RegExp; } +/** + * opencode's terminal provider errors, as `opencode acp --print-logs + * --log-level ERROR` prints them. On a provider error opencode logs + * `message="stream error" … error.error="…"` and RETRIES, but never reports the + * error over ACP: the prompt stays open with no update until our 90 s idle + * watchdog trips, and the user sees a generic retry bubble. 2026-10-22: every + * Box shares fleet-1's egress IP, so OpenCode Zen's free quota ran out for all + * of them ("Free usage limit reached. Subscribe to OpenCode Go…") and half the + * opencode turns of the day failed that way (4/4 users). Only errors a retry + * cannot fix are listed — a 5xx or a plain 429 rate limit is left to opencode's + * own retry. + */ +export const OPENCODE_FATAL_TURN_STDERR_RE = + /message="stream error".*error\.error="[^"]*(Free usage limit reached|insufficient[_ ]quota|invalid[_ ]api[_ ]key|incorrect api key|unauthorized)/i; + /** Claude's native binary is the SDK's bundled optional platform pkg. */ function claudeBinaryWaiter(opts: WaitForClaudeBinaryOptions = {}): Promise { return waitForClaudeNativeBinary(opts).then((p) => p !== null); @@ -260,8 +282,12 @@ const REGISTRY: Partial AdapterSpec | null>> = { // the ACP client spawns the adapter with `env: { ...process.env, ...extraEnv }`. opencode: () => ({ command: 'opencode', - args: ['acp'], + // `--print-logs --log-level ERROR`: opencode writes its provider errors only + // to its own log file, so without these flags they never reach the adapter + // stderr we read (see OPENCODE_FATAL_TURN_STDERR_RE). + args: ['acp', '--print-logs', '--log-level', 'ERROR'], requiresAgentBinary: 'opencode', + fatalTurnStderr: OPENCODE_FATAL_TURN_STDERR_RE, waitForBinary: async (o) => { if (isLocalSession()) await ensureOpencodeInstalled(); // Same stale-PATH guard as kimi above (~/.opencode/bin). diff --git a/apps/cli/src/agents/acp/client.ts b/apps/cli/src/agents/acp/client.ts index adee71bd..c92e735a 100644 --- a/apps/cli/src/agents/acp/client.ts +++ b/apps/cli/src/agents/acp/client.ts @@ -197,6 +197,14 @@ export const FATAL_STARTUP_RE = */ const NEWSESSION_TIMEOUT_MS = 120_000; +/** + * The agent's own error out of a logfmt stderr line (`error.error="…"`, what + * opencode prints), or the whole line when it carries none. + */ +export function agentErrorOf(line: string): string { + return /error\.error="([^"]+)"/.exec(line)?.[1] ?? line; +} + /** * How long the AGENT waits for ONE MCP server to finish starting, handed to it * as `MCP_TIMEOUT`. @@ -469,6 +477,12 @@ export class AcpClient { * engages; with it, the crash rejects immediately → retry respawns once the * install settles. Broader than {@link startupFailureReject} (newSession-only). */ private startAbortReject: ((err: Error) => void) | null = null; + /** The adapter's {@link AdapterSpec.fatalTurnStderr}, set at spawn. */ + private fatalTurnStderr: RegExp | null = null; + /** Set while a `session/prompt` is in flight; the stderr watcher calls it on + * a {@link fatalTurnStderr} line to end the turn now (opencode keeps a turn + * open forever after a terminal provider error — see the adapter spec). */ + private turnFailureReject: ((err: Error) => void) | null = null; constructor(private readonly opts: AcpClientOptions) {} @@ -602,6 +616,7 @@ export class AcpClient { 'acpClient', `provider routing ${formatProviderRouting(describeProviderRouting(childEnv, { cwd }), adapter.command)}`, ); + this.fatalTurnStderr = adapter.fatalTurnStderr ?? null; const child = spawn(adapter.command, adapter.args, { cwd, env: childEnv, @@ -633,24 +648,7 @@ export class AcpClient { child.stderr?.on('data', (chunk: string) => { for (const line of chunk.split(/\r?\n/)) { const trimmed = line.trim(); - if (trimmed) { - // Bump to info — adapter stderr is the primary signal when - // the agent's auth / install / config is wrong and the - // protocol just stalls. Trace-level suppression hid the - // root cause on every smoke test up to v2.27.6. - log.info('acpAdapter', trimmed); - this.opts.onStderr?.(trimmed); - this.recentStderr.push(trimmed); - if (this.recentStderr.length > 12) this.recentStderr.shift(); - // Fail `newSession` fast when the adapter prints a fatal startup - // error (auth / tier ineligibility). gemini --acp logs these to - // stderr but never rejects the RPC, so the only other signal is the - // timeout backstop — surfacing it here makes the error immediate. - if (this.startupFailureReject && FATAL_STARTUP_RE.test(trimmed)) { - this.startupFailureReject(new Error(`AGENT_STARTUP_FAILED: ${trimmed}`)); - this.startupFailureReject = null; - } - } + if (trimmed) this.onAdapterStderrLine(trimmed); } }); @@ -988,11 +986,18 @@ export class AcpClient { PROMPT_ACTIVE_IDLE_TIMEOUT_MS, ); this.promptIdle = idle; + let fatalTripped = false; + const fatal = new Promise((_, reject) => { + this.turnFailureReject = (err) => { + fatalTripped = true; + reject(err); + }; + }); // Fresh tool-call ledger per turn so a stale entry from a prior // turn can't keep this turn's watchdog suspended forever. this.pendingToolCalls.clear(); try { - const result = await Promise.race([send, idle.promise]); + const result = await Promise.race([send, idle.promise, fatal]); // Root-cause fix (fleet-1 handoff-robustness round 3, empirically // confirmed on a live box): the ACP SDK's stdio dispatch resolves a // `session/prompt` RPC response in ONE promise hop @@ -1035,18 +1040,47 @@ export class AcpClient { // cleanup cancel does, and the cancel kills IT instead — opencode even // folds a prompt into a still-running turn (codeagent-u7mm: a queued // message failed as "empty reply"). - if (idleTripped) await this.cancelAbandonedTurn(sessionId, send); + // A fatal stderr error leaves the same open turn behind — and opencode + // keeps retrying it against the provider until it is cancelled. + if (idleTripped || fatalTripped) await this.cancelAbandonedTurn(sessionId, send); throw err; } finally { // Permanently disarm so a late bump/timer can't reject after // we've moved on, and drop the handle for the next prompt. idle.clear(); this.promptIdle = null; + this.turnFailureReject = null; + } + } + + /** One non-empty adapter stderr line: logged, kept in the ring, and checked + * for the fatal startup / fatal turn errors that end a stuck RPC early. */ + private onAdapterStderrLine(trimmed: string): void { + // Bump to info — adapter stderr is the primary signal when + // the agent's auth / install / config is wrong and the + // protocol just stalls. Trace-level suppression hid the + // root cause on every smoke test up to v2.27.6. + log.info('acpAdapter', trimmed); + this.opts.onStderr?.(trimmed); + this.recentStderr.push(trimmed); + if (this.recentStderr.length > 12) this.recentStderr.shift(); + // Fail `newSession` fast when the adapter prints a fatal startup + // error (auth / tier ineligibility). gemini --acp logs these to + // stderr but never rejects the RPC, so the only other signal is the + // timeout backstop — surfacing it here makes the error immediate. + if (this.startupFailureReject && FATAL_STARTUP_RE.test(trimmed)) { + this.startupFailureReject(new Error(`AGENT_STARTUP_FAILED: ${trimmed}`)); + this.startupFailureReject = null; + } + // Same for a turn: an error the agent logs but never reports over ACP. + if (this.turnFailureReject && this.fatalTurnStderr?.test(trimmed)) { + this.turnFailureReject(new Error(`AGENT_TURN_FAILED: ${agentErrorOf(trimmed)}`)); + this.turnFailureReject = null; } } /** - * Cancel a turn the idle watchdog abandoned and wait, bounded, for the + * Cancel a turn the idle watchdog (or a fatal stderr error) abandoned and wait, bounded, for the * adapter to answer its `session/prompt` — the proof the turn is over before * the next prompt is sent. Best-effort: a dead adapter can't hold the queue * longer than {@link ABANDONED_TURN_SETTLE_MS}. diff --git a/apps/cli/src/agents/acp/command-handlers.ts b/apps/cli/src/agents/acp/command-handlers.ts index 4063fcd5..a1f11c44 100644 --- a/apps/cli/src/agents/acp/command-handlers.ts +++ b/apps/cli/src/agents/acp/command-handlers.ts @@ -102,6 +102,7 @@ import { replyLanguageContextOnce } from './reply-language'; import { shouldOfferOneMRecovery } from './oneMContextRecovery'; import { formatPromptEchoLine, formatAgentReplyLine } from './promptEcho'; import { + AGENT_FREE_LIMIT_MESSAGE, AUTH_FAILURE_MESSAGE, CURSOR_UPGRADE_MESSAGE, ONE_M_CREDITS_MESSAGE, @@ -864,6 +865,7 @@ type TurnFailureCode = | 'PROVIDER_BILLING' | 'AUTH_FAILED' | 'ONE_M_CREDITS' + | 'AGENT_FREE_LIMIT' | 'EMPTY_REPLY' | 'TURN_ERROR' | 'TURN_ERROR_PARTIAL' @@ -1399,7 +1401,9 @@ async function runStartTaskTurn( ? 'AUTH_FAILED' : bubble === ONE_M_CREDITS_MESSAGE ? 'ONE_M_CREDITS' - : failed.partialReplyKept + : bubble === AGENT_FREE_LIMIT_MESSAGE + ? 'AGENT_FREE_LIMIT' + : failed.partialReplyKept ? 'TURN_ERROR_PARTIAL' : 'TURN_ERROR', ); diff --git a/apps/cli/src/agents/acp/failure-messages.ts b/apps/cli/src/agents/acp/failure-messages.ts index ff1e74e8..5040c6c5 100644 --- a/apps/cli/src/agents/acp/failure-messages.ts +++ b/apps/cli/src/agents/acp/failure-messages.ts @@ -433,6 +433,27 @@ export const IDLE_TURN_FAILURE_MESSAGE = const IDLE_TURN_RE = /ACP prompt idle/; +const AGENT_FREE_LIMIT_RE = /Free usage limit reached/i; + +/** + * The agent's free model quota is spent (OpenCode Zen: "Free usage limit + * reached. Subscribe to OpenCode Go to keep going"). Not a crash and not the + * user's credential: every message fails the same way until the quota resets, + * so the bubble says so and names the ways forward. + */ +export function looksLikeAgentFreeLimit(text: string): boolean { + return AGENT_FREE_LIMIT_RE.test(text); +} + +export const AGENT_FREE_LIMIT_MESSAGE = [ + '⚠️ **OpenCode’s free models have hit their usage limit, so this message wasn’t answered.**', + '', + 'Messages will keep failing until the limit resets. To keep going now:', + '• add your own provider key for opencode in **Profile › Agents** (OpenRouter, Anthropic, OpenAI, …),', + '• switch this session to another agent, or', + '• subscribe to OpenCode Go: [opencode.ai/go](https://opencode.ai/go).', +].join('\n'); + /** * Persistent, actionable message for a turn that completed NORMALLY (no * throw — `stopReason: 'end_turn'`) but the agent's own ACP server streamed @@ -634,6 +655,9 @@ export function failureBubble(opts: { if (looksLikeHouseAgentLimit(opts.detail) || looksLikeHouseAgentLimit(opts.recentStderr)) { return houseAgentLimitMessage(`${opts.detail}\n${opts.recentStderr}`); } + if (looksLikeAgentFreeLimit(opts.detail) || looksLikeAgentFreeLimit(opts.recentStderr)) { + return AGENT_FREE_LIMIT_MESSAGE; + } // BYO provider 402 BEFORE auth: Claude wraps it as "Failed to authenticate. // API Error: 402 Insufficient credits…", which the auth branch would turn // into a re-auth loop on a valid key. Never on the house rail (see