diff --git a/src/main/codex/codex-app-server-connection.test.ts b/src/main/codex/codex-app-server-connection.test.ts index a4ebd72cf01..3d95e7ce380 100644 --- a/src/main/codex/codex-app-server-connection.test.ts +++ b/src/main/codex/codex-app-server-connection.test.ts @@ -21,6 +21,7 @@ const originalCodexHome = process.env.CODEX_HOME afterEach(() => { vi.useRealTimers() + vi.restoreAllMocks() if (originalCodexHome === undefined) { delete process.env.CODEX_HOME } else { @@ -340,13 +341,42 @@ describe('openCodexAppServerConnection', () => { ) child.stdout.write(`${JSON.stringify({ id: 'late-string-id', result: { value: 1 } })}\n`) - child.stdout.write(`${JSON.stringify({ id: 999, result: { value: 2 } })}\n`) + child.stdout.write(`${JSON.stringify({ id: null, error: { message: 'parse error' } })}\n`) await vi.waitFor(() => expect(frames).toHaveLength(2)) - expect(frames.map((frame) => frame.kind)).toEqual(['frame:unclassified', 'response:unmatched']) + expect(frames.map((frame) => frame.kind)).toEqual(['frame:unclassified', 'frame:unclassified']) await connection.close() }) + it('logs a reply to a timed-out request instead of surfacing it as a frame', async () => { + vi.useFakeTimers() + const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + const { child, spawnImpl, written } = stubChild() + answerInitialize(child) + const frames: string[] = [] + const connection = await openCodexAppServerConnection( + { command: 'codex', args: ['app-server'] }, + { onUnhandledFrame: (kind) => frames.push(kind) }, + spawnImpl + ) + + const slow = rejection(connection.request('turn/interrupt', undefined, { timeoutMs: 50 })) + await vi.advanceTimersByTimeAsync(60) + expect((await slow).name).toBe('CodexAppServerTimeoutError') + const id = Number(written.find((frame) => frame.method === 'turn/interrupt')?.id) + child.stdout.write(`${JSON.stringify({ id, result: {} })}\n`) + child.stdout.write(`${JSON.stringify({ id: 999, error: { message: 'no such request' } })}\n`) + await vi.waitFor(() => expect(warn).toHaveBeenCalledTimes(2)) + + expect(frames).toEqual([]) + expect(warn.mock.calls.map((call) => call[0])).toEqual([ + `[codex-app-server] late reply to turn/interrupt after timeout (id ${id})`, + '[codex-app-server] reply with no waiting request (id 999)' + ]) + expect(warn.mock.calls[1][1]).toBe('no such request') + await vi.advanceTimersByTimeAsync(0) + }) + it('fails in-flight requests and reports an unexpected exit once', async () => { const { child, spawnImpl } = stubChild({ exitOnStdinEnd: false }) answerInitialize(child) diff --git a/src/main/codex/codex-app-server-connection.ts b/src/main/codex/codex-app-server-connection.ts index 5bed3b594d7..3e7d16ea1bb 100644 --- a/src/main/codex/codex-app-server-connection.ts +++ b/src/main/codex/codex-app-server-connection.ts @@ -213,7 +213,7 @@ export async function openCodexAppServerConnection( // Why: per request, not per session — a chat session outlives every call, // so only the individual call can carry a deadline. const timer = setTimeout(() => { - dispatcher.deletePending(id) + dispatcher.timeOutPending(id) reject(new CodexAppServerTimeoutError(`codex app-server ${method} exceeded ${timeoutMs}ms`)) }, timeoutMs) dispatcher.addPending(id, { method, resolve, reject, timer }) diff --git a/src/main/codex/codex-app-server-record-dispatch.ts b/src/main/codex/codex-app-server-record-dispatch.ts index b1d3605b38f..cbac80f3643 100644 --- a/src/main/codex/codex-app-server-record-dispatch.ts +++ b/src/main/codex/codex-app-server-record-dispatch.ts @@ -10,6 +10,7 @@ import { import { classifyJsonRpcPrefix } from './codex-app-server-record-prefix' const OVERSIZED_REQUEST_ERROR_CODE = -32001 +const MAX_REMEMBERED_TIMEOUTS = 64 export type CodexPendingRequest = { method: string @@ -25,11 +26,26 @@ export function createCodexAppServerRecordDispatcher(input: { }): { addPending: (id: number, waiter: CodexPendingRequest) => void deletePending: (id: number) => void + timeOutPending: (id: number) => void failPending: (error: Error) => void dispatch: (message: Record) => void rejectOversized: (rejected: NdjsonRejectedRecord & { kind: 'line-too-long' }) => void } { const pending = new Map() + const timedOutMethods = new Map() + + const timeOutPending = (id: number): void => { + const waiter = pending.get(id) + if (!waiter) { + return + } + pending.delete(id) + timedOutMethods.set(id, waiter.method) + const oldest = timedOutMethods.keys().next() + if (timedOutMethods.size > MAX_REMEMBERED_TIMEOUTS && !oldest.done) { + timedOutMethods.delete(oldest.value) + } + } const failPending = (error: Error): void => { for (const waiter of pending.values()) { @@ -72,7 +88,17 @@ export function createCodexAppServerRecordDispatcher(input: { } const waiter = pending.get(message.id) if (!waiter) { - input.handlers.onUnhandledFrame?.('response:unmatched', message) + // Transport diagnostics, not conversation: only the request that gave up could have + // interpreted this reply, and it already reported its own outcome. + const timedOutMethod = timedOutMethods.get(message.id) + timedOutMethods.delete(message.id) + const error = isAppServerRecord(message.error) ? message.error.message : undefined + console.warn( + timedOutMethod + ? `[codex-app-server] late reply to ${timedOutMethod} after timeout (id ${message.id})` + : `[codex-app-server] reply with no waiting request (id ${message.id})`, + ...(typeof error === 'string' ? [error] : []) + ) return } pending.delete(message.id) @@ -160,6 +186,7 @@ export function createCodexAppServerRecordDispatcher(input: { return { addPending: (id, waiter) => pending.set(id, waiter), deletePending: (id) => pending.delete(id), + timeOutPending, failPending, dispatch, rejectOversized