fix(codex): log a late reply to a timed-out request instead of showing it in the chat (#23893)

* fix(codex): log a late reply to a timed-out request instead of showing it in the chat

* fix(codex): say a reply had no waiting request rather than an unknown id
This commit is contained in:
Brennan Benson
2026-09-29 13:19:48 -07:00
committed by GitHub
parent 18327d9665
commit ff59e2cd7b
3 changed files with 61 additions and 4 deletions
@@ -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)
@@ -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 })
@@ -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<string, unknown>) => void
rejectOversized: (rejected: NdjsonRejectedRecord & { kind: 'line-too-long' }) => void
} {
const pending = new Map<number, CodexPendingRequest>()
const timedOutMethods = new Map<number, string>()
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