-
Notifications
You must be signed in to change notification settings - Fork 1.6k
fix: salvage a stalled Codex turn instead of hanging forever #390
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from all commits
70b97eb
aa64160
31e16e5
6eeb68a
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -24,6 +24,8 @@ | |
| * pendingCollaborations: Set<string>, | ||
| * activeSubagentTurns: Set<string>, | ||
| * completionTimer: ReturnType<typeof setTimeout> | null, | ||
| * idleTimer: ReturnType<typeof setTimeout> | null, | ||
| * timedOut: boolean, | ||
| * lastAgentMessage: string, | ||
| * reviewText: string, | ||
| * reasoningSummary: string[], | ||
|
|
@@ -51,6 +53,36 @@ const DEFAULT_CONTINUE_PROMPT = | |
| const EXTERNAL_AGENT_IMPORT_COMPLETED = "externalAgentConfig/import/completed"; | ||
| const EXTERNAL_AGENT_IMPORT_TIMEOUT_MS = 2 * 60 * 1000; | ||
|
|
||
| export const TURN_IDLE_TIMEOUT_ENV = "CODEX_COMPANION_TURN_IDLE_TIMEOUT_MS"; | ||
| export const DEFAULT_TURN_IDLE_TIMEOUT_MS = 900000; | ||
| // Node's setTimeout caps delays at 2^31-1 ms; larger values overflow to 1 ms (near-immediate fire). | ||
| const MAX_TURN_IDLE_TIMEOUT_MS = 2147483647; | ||
|
|
||
| /** | ||
| * Resolve the inter-event idle window (ms) after which a silent turn is salvaged. | ||
| * This is an inter-event gap, NOT a total-duration ceiling: it resets on every | ||
| * notification that belongs to the turn. The whole trimmed value must be a decimal | ||
| * integer of milliseconds; anything else (blank, negative, decimal, or unit-suffixed | ||
| * like "15m" / "0ms") falls back to the default rather than parseInt's lenient numeric | ||
| * prefix. An explicit 0 is preserved and disables the watchdog; values above setTimeout's | ||
| * 2^31-1 ms ceiling are clamped to it. Avoid `Number(value) || DEFAULT` here - it would | ||
| * turn 0 into the default. | ||
| * @param {NodeJS.ProcessEnv} [env] | ||
| * @returns {number} | ||
| */ | ||
| export function resolveTurnIdleMs(env = process.env) { | ||
| const raw = env?.[TURN_IDLE_TIMEOUT_ENV]; | ||
| const trimmed = raw == null ? "" : String(raw).trim(); | ||
| if (!/^\d+$/.test(trimmed)) { | ||
| return DEFAULT_TURN_IDLE_TIMEOUT_MS; | ||
| } | ||
| const parsed = Number.parseInt(trimmed, 10); | ||
| if (!Number.isFinite(parsed)) { | ||
| return DEFAULT_TURN_IDLE_TIMEOUT_MS; | ||
| } | ||
| return Math.min(parsed, MAX_TURN_IDLE_TIMEOUT_MS); | ||
| } | ||
|
|
||
| function cleanCodexStderr(stderr) { | ||
| return stderr | ||
| .split(/\r?\n/) | ||
|
|
@@ -325,6 +357,8 @@ function createTurnCaptureState(threadId, options = {}) { | |
| pendingCollaborations: new Set(), | ||
| activeSubagentTurns: new Set(), | ||
| completionTimer: null, | ||
| idleTimer: null, | ||
| timedOut: false, | ||
| lastAgentMessage: "", | ||
| reviewText: "", | ||
| reasoningSummary: [], | ||
|
|
@@ -343,12 +377,43 @@ function clearCompletionTimer(state) { | |
| } | ||
| } | ||
|
|
||
| function clearIdleTimer(state) { | ||
| if (state.idleTimer) { | ||
| clearTimeout(state.idleTimer); | ||
| state.idleTimer = null; | ||
| } | ||
| } | ||
|
|
||
| /** | ||
| * (Re)arm the idle watchdog. Fires purely on silence: if no turn-belonging | ||
| * notification arrives within `idleMs`, the turn is salvaged as timed out. | ||
| * It deliberately does NOT consult pendingCollaborations/activeSubagentTurns - | ||
| * a subagent whose own terminal event was also dropped would never drain and | ||
| * would re-create the hang. Active subagents are protected by the reset surface | ||
| * (their streaming notifications re-arm this timer) instead. `idleMs <= 0` disables it. | ||
| */ | ||
| function armIdleTimer(state, idleMs) { | ||
| clearIdleTimer(state); | ||
| if (!(idleMs > 0)) { | ||
| return; | ||
| } | ||
| state.idleTimer = setTimeout(() => { | ||
| state.idleTimer = null; | ||
| if (state.completed) { | ||
| return; | ||
| } | ||
| completeTurn(state, null, { inferred: true, timedOut: true }); | ||
| }, Math.min(idleMs, MAX_TURN_IDLE_TIMEOUT_MS)); | ||
| state.idleTimer.unref?.(); | ||
| } | ||
|
|
||
| function completeTurn(state, turn = null, options = {}) { | ||
| if (state.completed) { | ||
| return; | ||
| } | ||
|
|
||
| clearCompletionTimer(state); | ||
| clearIdleTimer(state); | ||
| state.completed = true; | ||
|
|
||
| if (turn) { | ||
|
|
@@ -357,13 +422,27 @@ function completeTurn(state, turn = null, options = {}) { | |
| state.turnId = turn.id; | ||
| } | ||
| } else if (!state.finalTurn) { | ||
| state.finalTurn = { | ||
| id: state.turnId ?? "inferred-turn", | ||
| status: "completed" | ||
| }; | ||
| if (options.timedOut) { | ||
| // Salvaged without a confirmed completion: report a non-success status so | ||
| // buildResultStatus returns 1 and the job is recorded as failed, never a | ||
| // false "completed". The normal drained-after-final_answer inferred path | ||
| // (no timedOut) keeps the "completed" status. | ||
| state.timedOut = true; | ||
| state.finalTurn = { | ||
| id: state.turnId ?? "inferred-turn", | ||
| status: "incomplete" | ||
| }; | ||
| } else { | ||
| state.finalTurn = { | ||
| id: state.turnId ?? "inferred-turn", | ||
| status: "completed" | ||
| }; | ||
| } | ||
| } | ||
|
|
||
| if (options.inferred) { | ||
| if (options.timedOut) { | ||
| emitProgress(state.onProgress, "Turn salvaged: Codex stopped emitting events before confirming completion; returning the captured output.", "finalizing"); | ||
| } else if (options.inferred) { | ||
| emitProgress(state.onProgress, "Turn completion inferred after the main thread finished and subagent work drained.", "finalizing"); | ||
| } | ||
|
|
||
|
|
@@ -559,6 +638,14 @@ function applyTurnNotification(state, message) { | |
| async function captureTurn(client, threadId, startRequest, options = {}) { | ||
| const state = createTurnCaptureState(threadId, options); | ||
| const previousHandler = client.notificationHandler; | ||
| const idleMs = options.turnIdleMs ?? resolveTurnIdleMs(options.env ?? process.env); | ||
| emitProgress( | ||
| state.onProgress, | ||
| idleMs > 0 | ||
| ? `Turn idle watchdog armed (${idleMs}ms inter-event window).` | ||
| : "Turn idle watchdog disabled.", | ||
| "starting" | ||
| ); | ||
|
|
||
| client.setNotificationHandler((message) => { | ||
| if (!state.turnId) { | ||
|
|
@@ -568,6 +655,12 @@ async function captureTurn(client, threadId, startRequest, options = {}) { | |
|
|
||
| if (message.method === "thread/started" || message.method === "thread/name/updated") { | ||
| applyTurnNotification(state, message); | ||
| // thread/started / thread/name/updated register a (subagent) thread for THIS turn - | ||
| // that is live turn activity, so reset the watchdog here too. This branch returns | ||
| // before the belongsToTurn reset below, so the reset has to be repeated here. | ||
| if (!state.completed) { | ||
| armIdleTimer(state, idleMs); | ||
| } | ||
| return; | ||
| } | ||
|
|
||
|
|
@@ -579,6 +672,12 @@ async function captureTurn(client, threadId, startRequest, options = {}) { | |
| } | ||
|
|
||
| applyTurnNotification(state, message); | ||
| // Reset the idle watchdog on every turn-belonging notification (including active | ||
| // subagent streaming). Do NOT reset on the forwarded !belongsToTurn branch above, | ||
| // or an unrelated broker session would keep a dead turn alive. | ||
| if (!state.completed) { | ||
| armIdleTimer(state, idleMs); | ||
| } | ||
| }); | ||
|
|
||
| try { | ||
|
|
@@ -589,8 +688,18 @@ async function captureTurn(client, threadId, startRequest, options = {}) { | |
| state.threadTurnIds.set(state.threadId, state.turnId); | ||
| } | ||
| for (const message of state.bufferedNotifications) { | ||
| if (belongsToTurn(state, message)) { | ||
| if (message.method === "thread/started" || message.method === "thread/name/updated") { | ||
| // Mirror the live handler: these register turn threads (e.g. subagents) and carry no | ||
| // turnId, so belongsToTurn would reject them. Apply and reset the watchdog here too. | ||
| applyTurnNotification(state, message); | ||
| if (!state.completed) { | ||
| armIdleTimer(state, idleMs); | ||
| } | ||
| } else if (belongsToTurn(state, message)) { | ||
| applyTurnNotification(state, message); | ||
| if (!state.completed) { | ||
| armIdleTimer(state, idleMs); | ||
|
Comment on lines
690
to
+701
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
When the app server writes the Useful? React with 👍 / 👎. |
||
| } | ||
| } else { | ||
| if (previousHandler) { | ||
| previousHandler(message); | ||
|
|
@@ -603,9 +712,31 @@ async function captureTurn(client, threadId, startRequest, options = {}) { | |
| completeTurn(state, response.turn); | ||
| } | ||
|
|
||
| return await state.completion; | ||
| // Arm the watchdog only once the turn is live (after startRequest resolved); arming | ||
| // before it would race a still-pending RPC that rejects on disconnect. | ||
| if (!state.completed) { | ||
| armIdleTimer(state, idleMs); | ||
| } | ||
|
|
||
| // Layer A: race normal completion against transport death. exitPromise resolves within | ||
| // ms when the pipe/socket dies but is never linked to state.completion, so without this | ||
| // race a dropped terminal event on a dead connection would hang until the idle window. | ||
| const outcome = await Promise.race([ | ||
| state.completion.then((value) => ({ type: "completion", value })), | ||
| client.exitPromise.then(() => ({ type: "exit" })) | ||
| ]); | ||
|
Comment on lines
+724
to
+727
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
When the app-server or broker connection closes after a Useful? React with 👍 / 👎. |
||
|
|
||
| if (outcome.type === "exit") { | ||
| if (!state.completed) { | ||
| completeTurn(state, null, { inferred: true, timedOut: true }); | ||
| } | ||
| return state; | ||
| } | ||
|
|
||
| return outcome.value; | ||
| } finally { | ||
| clearCompletionTimer(state); | ||
| clearIdleTimer(state); | ||
| client.setNotificationHandler(previousHandler ?? null); | ||
| } | ||
| } | ||
|
|
@@ -755,6 +886,28 @@ function buildResultStatus(turnState) { | |
| return turnState.finalTurn?.status === "completed" ? 0 : 1; | ||
| } | ||
|
|
||
| const SALVAGE_CAPTURED_NOTE = | ||
| "Note: Codex stopped emitting events before confirming completion; returning the captured-so-far output, which may be incomplete."; | ||
| const SALVAGE_EMPTY_NOTE = | ||
| "No verdict was salvageable - Codex went silent before producing output; re-run or inspect the thread."; | ||
|
|
||
| /** | ||
| * Prefix a one-line salvage note onto a timed-out turn's body so the surface never | ||
| * renders a bare "failed". Two cases: captured-then-silence keeps the partial body, | ||
| * empty-then-silence replaces an empty body with an explicit no-verdict message. | ||
| * Non-timed-out bodies pass through untouched. | ||
| */ | ||
| function annotateSalvagedBody(body, timedOut) { | ||
| if (!timedOut) { | ||
| return body; | ||
| } | ||
| const text = typeof body === "string" ? body.trim() : ""; | ||
| if (text) { | ||
| return `${SALVAGE_CAPTURED_NOTE}\n\n${body}`; | ||
| } | ||
| return SALVAGE_EMPTY_NOTE; | ||
| } | ||
|
|
||
| const BUILTIN_PROVIDER_LABELS = new Map([ | ||
| ["openai", "OpenAI"], | ||
| ["ollama", "Ollama"], | ||
|
|
@@ -1030,6 +1183,8 @@ export async function runAppServerReview(cwd, options = {}) { | |
| }), | ||
| { | ||
| onProgress: options.onProgress, | ||
| turnIdleMs: options.turnIdleMs, | ||
| env: options.env, | ||
| onResponse(response, state) { | ||
| if (response.reviewThreadId) { | ||
| state.threadIds.add(response.reviewThreadId); | ||
|
|
@@ -1046,9 +1201,10 @@ export async function runAppServerReview(cwd, options = {}) { | |
| threadId: turnState.threadId, | ||
| sourceThreadId, | ||
| turnId: turnState.turnId, | ||
| reviewText: turnState.reviewText, | ||
| reviewText: annotateSalvagedBody(turnState.reviewText, turnState.timedOut), | ||
| reasoningSummary: turnState.reasoningSummary, | ||
| turn: turnState.finalTurn, | ||
| timedOut: turnState.timedOut, | ||
| error: turnState.error, | ||
| stderr: cleanCodexStderr(client.stderr) | ||
| }; | ||
|
|
@@ -1140,16 +1296,21 @@ export async function runAppServerTurn(cwd, options = {}) { | |
| effort: options.effort ?? null, | ||
| outputSchema: options.outputSchema ?? null | ||
| }), | ||
| { onProgress: options.onProgress } | ||
| { | ||
| onProgress: options.onProgress, | ||
| turnIdleMs: options.turnIdleMs, | ||
| env: options.env | ||
| } | ||
| ); | ||
|
|
||
| return { | ||
| status: buildResultStatus(turnState), | ||
| threadId, | ||
| turnId: turnState.turnId, | ||
| finalMessage: turnState.lastAgentMessage, | ||
| finalMessage: annotateSalvagedBody(turnState.lastAgentMessage, turnState.timedOut), | ||
| reasoningSummary: turnState.reasoningSummary, | ||
| turn: turnState.finalTurn, | ||
| timedOut: turnState.timedOut, | ||
| error: turnState.error, | ||
| stderr: cleanCodexStderr(client.stderr), | ||
| fileChanges: turnState.fileChanges, | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
When the shared broker is in use and Codex is silent but still running, this timeout path only resolves the local capture as failed. The subsequent
BrokerCodexAppServerClient.close()just ends the per-command socket, andapp-server-broker.mjsclears ownership while keeping its app-server client alive, so the underlying turn is never sentturn/interrupt; that can leave a model turn consuming quota or leaking late notifications after the job has already been marked failed. Send an interrupt for the capturedthreadId/turnIdbefore salvaging brokered turns.Useful? React with 👍 / 👎.