mirror of
https://github.com/stablyai/orca.git
synced 2026-10-31 00:57:45 +00:00
Opening or resuming a Codex chat waits for Codex instead of failing after 30 seconds (#30395)
* fix(codex): opening or resuming a Codex chat waits for Codex instead of failing after 30 s The handshake (15 s) and thread/start / thread/resume (30 s) had their own deadlines because the Codex start ignored the host's startup signal. It now honours it, as Claude's start does, so those requests carry no deadline: the host's startup limits, a close, a Stop or quit end a start that hangs, and the abort reaps Codex. Calls after the start keep the 30 s default for now: they run in the session's queue, which a Stop or a close waits behind. * test(codex): keep the handshake wait test in its own file under the line limit * fix(codex): the one-shot app-server runner takes the same no-deadline option as the chat connection * test: accept nullable Codex request timeout in probe fake * fix(codex): bound direct opens at their caller * Remove obsolete Codex startup timeout scenario
This commit is contained in:
@@ -21,7 +21,8 @@ export type CodexAppServerConnection = {
|
||||
request: (
|
||||
method: string,
|
||||
params?: Record<string, unknown>,
|
||||
options?: { timeoutMs?: number; onReply?: () => void }
|
||||
/** `timeoutMs` null: no deadline; the caller bounds the wait. */
|
||||
options?: { timeoutMs?: number | null; onReply?: () => void }
|
||||
) => Promise<unknown>
|
||||
notify: (method: string, params?: Record<string, unknown>) => void
|
||||
respond: (id: number | string, result: unknown) => void
|
||||
|
||||
@@ -35,6 +35,9 @@ export { ROOT_ONLY_GRACEFUL_EXIT_MS as GRACEFUL_EXIT_MS } from '../provider-proc
|
||||
|
||||
export type CodexAppServerLaunch = ProviderProcessLaunch
|
||||
|
||||
// Why: calls made after the start run in the session's queue, which a Stop or a close waits behind,
|
||||
// so their deadline is what frees it from a Codex that never answers. Temporary: it goes once a
|
||||
// Stop or close can end the child without queueing behind its request.
|
||||
const DEFAULT_REQUEST_TIMEOUT_MS = 30_000
|
||||
|
||||
/** Builds the transport so an owner can record its process before initialization. */
|
||||
@@ -148,7 +151,7 @@ async function connectCodexAppServer(
|
||||
function request(
|
||||
method: string,
|
||||
params?: Record<string, unknown>,
|
||||
options: { timeoutMs?: number; onReply?: () => void } = {}
|
||||
options: { timeoutMs?: number | null; onReply?: () => void } = {}
|
||||
): Promise<unknown> {
|
||||
if (closing) {
|
||||
return Promise.reject(new Error(`codex app-server connection is closed (${method})`))
|
||||
@@ -160,19 +163,24 @@ async function connectCodexAppServer(
|
||||
return Promise.reject(buildExitError())
|
||||
}
|
||||
const id = nextRequestId++
|
||||
const timeoutMs = options.timeoutMs ?? DEFAULT_REQUEST_TIMEOUT_MS
|
||||
const timeoutMs =
|
||||
options.timeoutMs === undefined ? DEFAULT_REQUEST_TIMEOUT_MS : options.timeoutMs
|
||||
return new Promise<unknown>((resolve, reject) => {
|
||||
// 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.timeOutPending(id)
|
||||
reject(
|
||||
withProviderRequestTimeout(
|
||||
new CodexAppServerTimeoutError(`codex app-server ${method} exceeded ${timeoutMs}ms`),
|
||||
{ method, timeoutMs }
|
||||
)
|
||||
)
|
||||
}, timeoutMs)
|
||||
// Null requests are bounded by their caller; timed requests belong to this call.
|
||||
const timer =
|
||||
timeoutMs === null
|
||||
? undefined
|
||||
: setTimeout(() => {
|
||||
dispatcher.timeOutPending(id)
|
||||
reject(
|
||||
withProviderRequestTimeout(
|
||||
new CodexAppServerTimeoutError(
|
||||
`codex app-server ${method} exceeded ${timeoutMs}ms`
|
||||
),
|
||||
{ method, timeoutMs }
|
||||
)
|
||||
)
|
||||
}, timeoutMs)
|
||||
dispatcher.addPending(id, { method, resolve, reject, timer, onReply: options.onReply })
|
||||
try {
|
||||
sendLine(params === undefined ? { method, id } : { method, id, params })
|
||||
@@ -238,7 +246,8 @@ async function connectCodexAppServer(
|
||||
}
|
||||
if (initialize) {
|
||||
handshaking = true
|
||||
await initializeCodexAppServerConnection(connection)
|
||||
// Direct opens cannot expose the connection for cancellation until initialization finishes.
|
||||
await initializeCodexAppServerConnection(connection, 15_000)
|
||||
}
|
||||
} catch (error) {
|
||||
if ((await close()) !== true) {
|
||||
|
||||
@@ -0,0 +1,26 @@
|
||||
import { PassThrough } from 'node:stream'
|
||||
import { afterEach, expect, it, vi } from 'vitest'
|
||||
import { createFakePipedChild } from '../../shared/__fixtures__/fake-spawned-child'
|
||||
import { openCodexAppServerConnection } from './codex-app-server-connection'
|
||||
|
||||
afterEach(() => vi.useRealTimers())
|
||||
|
||||
it('ends a direct open and reaps its child when initialize never answers', async () => {
|
||||
vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] })
|
||||
const child = createFakePipedChild(9_999_999)
|
||||
child.stdout = new PassThrough()
|
||||
child.stderr = new PassThrough()
|
||||
child.stdin = new PassThrough()
|
||||
child.stdin.on('finish', () => child.emit('exit', 0, null))
|
||||
const opening = openCodexAppServerConnection(
|
||||
{ command: 'codex', args: ['app-server'] },
|
||||
{},
|
||||
() => child
|
||||
).catch((error: unknown) => error)
|
||||
|
||||
await vi.advanceTimersByTimeAsync(14_999)
|
||||
expect(child.stdin.writableEnded).toBe(false)
|
||||
await vi.advanceTimersByTimeAsync(1)
|
||||
expect(await opening).toMatchObject({ name: 'CodexAppServerTimeoutError' })
|
||||
expect(child.stdin.writableEnded).toBe(true)
|
||||
})
|
||||
@@ -1,9 +1,9 @@
|
||||
import type { CodexAppServerConnection } from './codex-app-server-connection-types'
|
||||
|
||||
const HANDSHAKE_TIMEOUT_MS = 15_000
|
||||
|
||||
/** The caller owns the bound; null leaves cancellation to its startup signal. */
|
||||
export async function initializeCodexAppServerConnection(
|
||||
connection: CodexAppServerConnection
|
||||
connection: CodexAppServerConnection,
|
||||
timeoutMs: number | null
|
||||
): Promise<void> {
|
||||
await connection.request(
|
||||
'initialize',
|
||||
@@ -16,7 +16,7 @@ export async function initializeCodexAppServerConnection(
|
||||
extensions: {}
|
||||
}
|
||||
},
|
||||
{ timeoutMs: HANDSHAKE_TIMEOUT_MS }
|
||||
{ timeoutMs }
|
||||
)
|
||||
connection.notify('initialized')
|
||||
}
|
||||
|
||||
@@ -16,7 +16,7 @@ export type CodexPendingRequest = {
|
||||
method: string
|
||||
resolve: (result: unknown) => void
|
||||
reject: (error: Error) => void
|
||||
timer: ReturnType<typeof setTimeout>
|
||||
timer: ReturnType<typeof setTimeout> | undefined
|
||||
/** Called as the reply is read, or as the request times out, before anything awaits it: in
|
||||
* stdout order with every notification read around it. */
|
||||
onReply?: () => void
|
||||
|
||||
@@ -72,11 +72,12 @@ type JsonRpcResponse = {
|
||||
}
|
||||
|
||||
export type CodexAppServerRpc = {
|
||||
/** `timeoutMs` bounds one call inside the session deadline, so a caller can drop it and go on. */
|
||||
/** `timeoutMs` bounds one call inside the session deadline, so a caller can drop it and go on;
|
||||
* absent or null, only the session deadline does. */
|
||||
request: (
|
||||
method: string,
|
||||
params?: Record<string, unknown>,
|
||||
options?: { timeoutMs?: number }
|
||||
options?: { timeoutMs?: number | null }
|
||||
) => Promise<unknown>
|
||||
notify: (method: string, params?: Record<string, unknown>) => void
|
||||
}
|
||||
@@ -241,7 +242,7 @@ export async function runCodexAppServerSession<T>(
|
||||
async function requestRpc(
|
||||
method: string,
|
||||
params?: Record<string, unknown>,
|
||||
options: { timeoutMs?: number } = {}
|
||||
options: { timeoutMs?: number | null } = {}
|
||||
): Promise<unknown> {
|
||||
if (spawnError) {
|
||||
throw spawnError
|
||||
@@ -256,8 +257,8 @@ export async function runCodexAppServerSession<T>(
|
||||
let requestTimer: ReturnType<typeof setTimeout> | undefined
|
||||
const response = await new Promise<JsonRpcResponse>((resolve, reject) => {
|
||||
pending.set(id, { resolve, reject })
|
||||
if (options.timeoutMs !== undefined) {
|
||||
const { timeoutMs } = options
|
||||
const { timeoutMs } = options
|
||||
if (typeof timeoutMs === 'number') {
|
||||
requestTimer = setTimeout(() => {
|
||||
pending.delete(id)
|
||||
reject(
|
||||
|
||||
@@ -80,7 +80,7 @@ describe('codex model catalog probe', () => {
|
||||
process.stdout.write(JSON.stringify({ id: message.id, result }) + '\n')
|
||||
})
|
||||
`
|
||||
const configReadTimeouts: (number | undefined)[] = []
|
||||
const configReadTimeouts: (number | null | undefined)[] = []
|
||||
const configReadFailures: unknown[] = []
|
||||
const probe = createCodexModelCatalogProbe({
|
||||
resolveEnvironment: async () => ({ PATH: '/bin' }),
|
||||
|
||||
@@ -19,12 +19,15 @@ export type ScriptedCodexChild = ScriptedAgentChild & {
|
||||
}
|
||||
|
||||
/** A held answer gives up on the request's own deadline, as the real connection's does (30 s when
|
||||
* the caller names none). */
|
||||
* the caller names none, never when it passes null). */
|
||||
function heldAnswer(
|
||||
answer: Promise<unknown>,
|
||||
method: string,
|
||||
timeoutMs = 30_000
|
||||
timeoutMs: number | null = 30_000
|
||||
): Promise<unknown> {
|
||||
if (timeoutMs === null) {
|
||||
return answer
|
||||
}
|
||||
let timer: ReturnType<typeof setTimeout> | undefined
|
||||
const timedOut = new Promise<never>((_resolve, reject) => {
|
||||
timer = setTimeout(
|
||||
|
||||
@@ -335,7 +335,7 @@ describe('first-turn catalog deadline', () => {
|
||||
async (
|
||||
method: string,
|
||||
_params?: Record<string, unknown>,
|
||||
options?: { timeoutMs?: number }
|
||||
options?: { timeoutMs?: number | null }
|
||||
) => {
|
||||
timeouts.push(options?.timeoutMs ?? 0)
|
||||
if (method === 'model/list') {
|
||||
|
||||
@@ -76,7 +76,10 @@ export async function openCodexStructuredSession(
|
||||
assertCodexConnectionOpen(connection, sessionId)
|
||||
}
|
||||
current()
|
||||
await waitForPromiseWithSignal(initializeCodexAppServerConnection(connection), openInput.signal)
|
||||
await waitForPromiseWithSignal(
|
||||
initializeCodexAppServerConnection(connection, null),
|
||||
openInput.signal
|
||||
)
|
||||
current()
|
||||
const threadLaunch = await waitForPromiseWithSignal(
|
||||
withCodexVisualsThreadConfig(connection, launch, {
|
||||
@@ -94,7 +97,9 @@ export async function openCodexStructuredSession(
|
||||
openCodexThread(
|
||||
connection,
|
||||
{ ...threadLaunch, commandEnv },
|
||||
deps.requestTimeoutMs,
|
||||
// No deadline of its own: resuming a long rollout or starting MCP servers takes what it
|
||||
// takes. The host's start ceiling, a close and a Stop end the wait through the signal.
|
||||
deps.requestTimeoutMs ?? null,
|
||||
openInput.signal
|
||||
),
|
||||
openInput.signal
|
||||
|
||||
@@ -75,7 +75,8 @@ export async function openCodexThread(
|
||||
/** Env every command the agent runs must see, whatever the user's shell environment policy. */
|
||||
commandEnv?: Record<string, string>
|
||||
},
|
||||
timeoutMs: number | undefined,
|
||||
/** null: no deadline; the start that opens the thread bounds it (`signal`). */
|
||||
timeoutMs: number | null | undefined,
|
||||
signal?: AbortSignal
|
||||
): Promise<CodexOpenedThread> {
|
||||
const resumeThreadId = launch.resumeThreadId
|
||||
|
||||
@@ -28,12 +28,16 @@ const VISUALS: NativeChatVisualsLaunch = {
|
||||
const MANUAL = codexStructuredPermissionPolicy('ask')
|
||||
const YOLO = codexStructuredPermissionPolicy('full-access')
|
||||
|
||||
type Call = { method: string; params?: Record<string, unknown>; timeoutMs?: number }
|
||||
type Call = { method: string; params?: Record<string, unknown>; timeoutMs?: number | null }
|
||||
|
||||
function connectionAnswering(routes: Record<string, () => unknown>) {
|
||||
const calls: Call[] = []
|
||||
const request = vi.fn(
|
||||
async (method: string, params?: Record<string, unknown>, options?: { timeoutMs?: number }) => {
|
||||
async (
|
||||
method: string,
|
||||
params?: Record<string, unknown>,
|
||||
options?: { timeoutMs?: number | null }
|
||||
) => {
|
||||
calls.push({ method, params, timeoutMs: options?.timeoutMs })
|
||||
const route = routes[method]
|
||||
return route ? route() : {}
|
||||
|
||||
@@ -1,6 +1,5 @@
|
||||
// Each step of a Codex start has its own bound: an `initialize` that never answers fails the start
|
||||
// at 15 s with the startup-failure words, and the host ends the child; one that answers in time
|
||||
// starts as usual.
|
||||
// A Codex start has no per-step deadline: a slow `initialize` still delivers the held message, and
|
||||
// one that never answers is ended by the start's own overall limit ("never finished starting").
|
||||
|
||||
import { mkdtemp, rm } from 'node:fs/promises'
|
||||
import { tmpdir } from 'node:os'
|
||||
@@ -13,13 +12,9 @@ import {
|
||||
hostTestAttachParams,
|
||||
hostTestMessage
|
||||
} from '../native-chat/agent-session-wire/structured-agent-session-host-test-data'
|
||||
import {
|
||||
createStructuredAgentSessionLogger,
|
||||
type StructuredAgentSessionLogger
|
||||
} from '../native-chat/agent-session-wire/structured-agent-session-logger'
|
||||
import { CodexAppServerTimeoutError } from '../codex/codex-app-server-session'
|
||||
import { withProviderRequestTimeout } from '../provider-process/provider-request-timeout'
|
||||
import { createStructuredAgentSessionLogger } from '../native-chat/agent-session-wire/structured-agent-session-logger'
|
||||
import { recordAgentSessionStartup } from '../observability/agent-session-instrumentation'
|
||||
import { STRUCTURED_AGENT_SESSION_STARTUP_CEILING_MS } from '../native-chat/agent-session-wire/structured-agent-session-startup-attempt-contract'
|
||||
import { readWholeAgentSessionFailureFact } from '../../shared/agent-session-failure'
|
||||
import type { ScriptedAgentChild } from './structured-agent-scripted-child.test-fixture'
|
||||
import {
|
||||
@@ -66,13 +61,10 @@ function envelope(method: string, fence: number, fields: Record<string, unknown>
|
||||
}
|
||||
}
|
||||
|
||||
async function chatHoldingAMessage(
|
||||
child: ScriptedAgentChild,
|
||||
logger: StructuredAgentSessionLogger = createStructuredAgentSessionLogger()
|
||||
) {
|
||||
async function chatHoldingAMessage(child: ScriptedAgentChild) {
|
||||
root = await mkdtemp(join(tmpdir(), 'orca-codex-start-deadline-'))
|
||||
const host = await ensureStructuredAgentSessionHost({
|
||||
logger,
|
||||
logger: createStructuredAgentSessionLogger(),
|
||||
stateDirectory: root,
|
||||
hostId: 'local',
|
||||
claimKeyId: 'key-1',
|
||||
@@ -100,10 +92,10 @@ function startupOutcomes(): string[] {
|
||||
return vi.mocked(recordAgentSessionStartup).mock.calls.map(([startup]) => startup.outcome)
|
||||
}
|
||||
|
||||
it('delivers the held message to a Codex that answers initialize within its bound', async () => {
|
||||
it('delivers the held message to a Codex that answers initialize after a minute', async () => {
|
||||
const child = codexScriptedChild()
|
||||
await chatHoldingAMessage(child)
|
||||
await vi.advanceTimersByTimeAsync(14_000)
|
||||
await vi.advanceTimersByTimeAsync(60_000)
|
||||
expect(child.closes()).toBe(0)
|
||||
|
||||
child.releaseHandshake()
|
||||
@@ -112,74 +104,20 @@ it('delivers the held message to a Codex that answers initialize within its boun
|
||||
expect(startupOutcomes()).toEqual(['ready'])
|
||||
})
|
||||
|
||||
it('fails the held message with the startup-failure words when initialize passes its bound', async () => {
|
||||
it('fails the held message as never finished starting when the start passes its overall limit', async () => {
|
||||
const child = codexScriptedChild()
|
||||
const host = await chatHoldingAMessage(child)
|
||||
await vi.advanceTimersByTimeAsync(15_000)
|
||||
await vi.advanceTimersByTimeAsync(STRUCTURED_AGENT_SESSION_STARTUP_CEILING_MS - 1_000)
|
||||
expect(child.closes()).toBe(0)
|
||||
await vi.advanceTimersByTimeAsync(1_000)
|
||||
|
||||
await vi.waitFor(async () => {
|
||||
await host.flushStreamedEvents(HOST_TEST_SESSION)
|
||||
const [held] = (await host.journalSnapshot(HOST_TEST_SESSION)).submissions
|
||||
expect(held?.dispatchState).toBe('rejected')
|
||||
expect(readWholeAgentSessionFailureFact(held?.rejection)).toMatchObject({ kind: 'startFailed' })
|
||||
expect(readWholeAgentSessionFailureFact(held?.rejection)).toMatchObject({ kind: 'hostStopped' })
|
||||
})
|
||||
await vi.waitFor(() => expect(child.closes()).toBe(1))
|
||||
expect(child.prompts()).toEqual([])
|
||||
expect(child.spawns()).toBe(1)
|
||||
})
|
||||
|
||||
it('names the request that ran out of time, in the chat and in the log, when thread/start never answers', async () => {
|
||||
const child = codexScriptedChild({
|
||||
'thread/start': () =>
|
||||
new Promise((_resolve, reject) =>
|
||||
setTimeout(
|
||||
() =>
|
||||
reject(
|
||||
withProviderRequestTimeout(
|
||||
new CodexAppServerTimeoutError('codex app-server thread/start exceeded 30000ms'),
|
||||
{ method: 'thread/start', timeoutMs: 30_000 }
|
||||
)
|
||||
),
|
||||
30_000
|
||||
)
|
||||
)
|
||||
})
|
||||
const logger = { warn: vi.fn(), error: vi.fn() }
|
||||
const host = await chatHoldingAMessage(child, logger)
|
||||
child.releaseHandshake()
|
||||
await vi.advanceTimersByTimeAsync(30_000)
|
||||
|
||||
const requestTimeout = { method: 'thread/start', timeoutMs: 30_000 }
|
||||
await vi.waitFor(async () => {
|
||||
await host.flushStreamedEvents(HOST_TEST_SESSION)
|
||||
const [held] = (await host.journalSnapshot(HOST_TEST_SESSION)).submissions
|
||||
expect(held?.dispatchState).toBe('rejected')
|
||||
expect(readWholeAgentSessionFailureFact(held?.rejection)).toEqual({
|
||||
kind: 'startFailed',
|
||||
requestTimeout
|
||||
})
|
||||
expect(held?.reason).toBe(
|
||||
'Codex took too long to start (no response to thread/start after 30s). Send your message to try again. If this keeps happening, the computer running this chat may be overloaded.'
|
||||
)
|
||||
})
|
||||
const rows = (await host.journalSnapshot(HOST_TEST_SESSION)).items.filter(
|
||||
(item) =>
|
||||
item.body.kind === 'status' &&
|
||||
readWholeAgentSessionFailureFact(item.body.failure)?.requestTimeout !== undefined
|
||||
)
|
||||
expect(rows).toHaveLength(1)
|
||||
await vi.waitFor(() => expect(child.closes()).toBe(1))
|
||||
|
||||
const failures = logger.warn.mock.calls.filter(
|
||||
([, fields]) => fields.scope === 'provider-open-failed'
|
||||
)
|
||||
expect(failures).toHaveLength(1)
|
||||
const logged = failures[0]
|
||||
expect(logged?.[1]).toMatchObject({
|
||||
sessionId: HOST_TEST_SESSION,
|
||||
failure: 'startFailed',
|
||||
...requestTimeout,
|
||||
error: expect.any(CodexAppServerTimeoutError)
|
||||
})
|
||||
expect(logged?.[1].openMs).toBeGreaterThanOrEqual(30_000)
|
||||
})
|
||||
|
||||
Reference in New Issue
Block a user