Repository navigation
fix(ai): Codex todo_write turn still ends prompt_failed on request_timeout error event after complete function call #6301
Description
Codex turns still end prompt_failed (-32603, phase post_start, retryability: terminal) when the relay sends a request_timeout error event about 900 s after the model emitted a complete todo_write function call. The salvage paths from #6256, #6274, #6284 and #6291 are all present in the build that fails, and the turn is still persisted as stopReason: "error".
Observed shape (production session, dev 03c88bb12 source)
Persisted assistant message (openai-codex / gpt-6.1-sol, SSE transport, openaiWebsockets: "off"):
content: [ {type:"thinking", thinking:"", thinkingSignature:<present>},
{type:"toolCall", name:"todo_write", arguments:{ops:[{op:"init", list:[...complete...]}]}} ]
stopReason: "error"
duration: 902222
usage: all zero
errorMessage: "Codex error event: stream error: stream disconnected before completion: stream closed before response.completed (code=request_timeout)"
Next entries: toolResult todo_write isError=true -> todo-write-error-reminder -> sdk_prompt_terminal_failed (provenance: agent_failed, assistantStopReason: error).
- It happens on the first planning call of a session, right after 4-5 parallel
read/bashresults. durationis always 900-908 s, which means the client idle watchdog (120 s default) never fired. The stream was not silent long enough for it. The error event is what ends the turn.- 7 occurrences between 21:45Z and 23:10Z on 2026-10-03, all after the host's SDK broker restarted at 21:03Z on
packages/coding-agent/src/cli.tsfrom a checkout at 03c88bb12 (contains fix(ai): salvage complete Codex calls after reasoning opens #6256, fix(ai): salvage Codex calls past empty message items #6274, fix(ai): salvage finalized Codex calls on EOF #6284 and fix(ai): salvage first-turn Codex tool call after request_timeout stall (G6) #6291). About 23 turns per 6 h across our runners. Every one ended with zero commits.
Why the existing salvage does not catch it (code reading only, not reproduced)
processCodexResponseStream -> handleCodexStreamEvent throws createCodexProviderStreamError(rawEvent) for the error event. trySalvageCodexFinalizedToolCalls then gets an error for which isCodexTransientStreamClose should be true (code=request_timeout + "stream disconnected before completion"). The tool-call arguments are a complete JSON object. So one of the other guards must be refusing:
runtime.toolArgumentCorrelationFailed(argument events whoseitem_iddoes not match the active item)argumentsComplete !== trueor missingsourceItemId/sourceCallIdon the blockruntime.currentBlock/currentItemin a state not covered (for example a new item opened after the function call)
Which one it is cannot be determined from the persisted session, because the raw event sequence is not recorded and there is no debug log on the refusal path.
Proposal
- Add a replay test in
packages/ai/test/openai-codex-stream.test.tsthat feeds the production order over SSE: reasoning item (empty summary, encrypted content) ->function_calltodo_writewith argument deltas -> (variants: with/withoutfunction_call_arguments.done, with/withoutoutput_item.done, with an extra item opened after the call) ->{type:"error", error:{code:"request_timeout", message:"stream error: stream disconnected before completion: stream closed before response.completed"}}. Find which variant endserroron current dev. - Fix the guard that refuses that variant, and keep existing fail-closed cases (partial arguments, non-empty text, non-transient codes) as
error. - If every variant already salvages on dev, report that and add a
GJC_OPENAI_CODE_DEBUGlog on the refusal branch with the guard inputs, so the next field occurrence shows which guard refused.
Timeouts, retry counts and model/preset defaults stay unchanged.
Activity
probepark commentedon Oct 3, 2026
Triage: A (handing to a coder) · bug · P1
Evidence: a production session on a runner whose session host runs dev 03c88bb12 (includes #6256, #6274, #6284 and #6291) persisted
[thinking(signed, empty), toolCall todo_write(complete args)]withstopReason: "error",duration902 s and arequest_timeouterror event. There were 7 such turns between 21:45Z and 23:10Z. All of them endedprompt_failedwith zero commits.Root-cause candidates (from reading the dev source; not reproduced yet):
packages/ai/src/providers/openai-codex-responses.ts:1294trySalvageCodexFinalizedToolCallsguardscanSalvageCompleteArguments(L1341-1353):toolArgumentCorrelationFailed,argumentsComplete/sourceItemId/sourceCallIdon the block (set increateOutputBlockForItemL1647-1677 andhandleToolCallArgumentsDeltaL1848-1870), and thecurrentBlock/currentItemstate check.isActiveToolArgumentEventL1875: anitem_idmismatch here setstoolArgumentCorrelationFailed, and after that every salvage path is refused.Next step: a replay test over SSE that finds the variant that still ends in
erroron dev, then a fix for that guard only. No timeout, retry or preset changes. If no variant fails on dev, add a debug log on the refusal branch so the next field occurrence shows which guard refused.probepark commentedon Oct 4, 2026
Two more production turns on home2 show the same shape after #6291 was installed. One of them also ran after #6302 was installed.
thinking("" , signed rs_…),toolCall todo_write(complete args, 316 B)thinking("" , signed rs_…),toolCall todo_write(complete args, 509 B)Both turns:
stopReason: "error",errorMessage: "Codex error event: stream error: stream disconnected before completion: stream closed before response.completed (code=request_timeout)", SSE transport (openai-codex-responses).request_timeout.todo_writetoolResult isisError: truewith the same Codex error text, followed by atodo-write-error-reminder. The SDK reconciliation record isprompt_failed,phase: post_start.salvage refusedline. On these builds the refusal goes throughlogCodexDebug, which needsCODEX_DEBUG. That is why the refusal fields were not captured.Conclusion: by persisted shape this is salvageable, because the content is a signed reasoning item plus a complete function call. The salvage did not fire, and this is a salvage miss, not a server-side timeout on an unfinished call. The reason for the refusal needs the
logger.warnoutput from #6308, which merged at 2026-10-04 07:57Z (39f68549). The next measurement on home2 will capture the refusal fields from a build that includes 39f68549.Volume on the mac runner side: 40 of the 74
NO_COMMITSruns since 2026-10-03 05:35Z start with[Think] Failed: todo_writeandprompt_failed/post_start. Source: pod-side copies in/tmp/mac-agent-out-*.txt.probepark commentedon Oct 4, 2026
Recurrence count after #6302 (merged 2026-10-04 02:06Z as 61f2e172).
Metric: agent runs that ended
NO_COMMITSwithtodo_writefailed andprompt_failed/phase: post_start, counted across all runners.logCodexDebug, which only writes whenGJC_OPENAI_CODE_DEBUG/PI_CODEX_DEBUGis set. It was not set on the runners.logger.warn. As of 08:45Z, no runner build includes it. The newest one is 0e761bcc, which is 3 commits behind.Status: the root cause is still pending. The refusal fields will come from the first failing turn on a build that includes #6308.
probepark commentedon Oct 5, 2026
#6308(39f68549) 이후 바이너리로
[codex] codex stream close salvage refusedwarn 을 측정했다. home2 에서 7건이 나왔고 work 와 studio 는 0건이다. 측정 구간은 각 맥~/.gjc/logs/gjc.2026-10-05.log의 처음부터 2026-10-05T01:48Z 까지다.7건 모두 toolArgumentCorrelationFailed=false, sourceItemId/sourceCallId 는 있다.
판정:
request_timeouterror 이벤트로 스트림을 닫았다. 인자가 완성되지 않았으므로trySalvageCodexFinalizedToolCalls의 거부는 맞다. salvage 조건을 풀면 안 된다.recoverCodexStreamError→tryRetryCodexProviderError는context.output.content.length > 0이면 재시도하지 않는다. 그래서 실행되지 않은 미완성 tool call 하나 때문에 턴이 prompt_failed 로 끝난다.후속: 미완성 인자 + request_timeout 일 때 부분 출력을 버리고 1회 재시도하는 수정을 별도 PR 로 낸다.
probepark commentedon Oct 6, 2026
New data from one linux host (tank) on 2026-10-06, gjc/0.18.7 built from dev d66256dd1. This answers the open question in the proposal: which guard refuses.
[codex] codex stream close salvage refusedlines today. Every sampled one hasargumentsComplete:[false],toolArgumentCorrelationFailed:false,currentItemType:"function_call",finalizedToolCallIds:0,errorCode:"request_timeout".recentEventsis a run ofresponse.function_call_arguments.deltawithdeltaLength: 1(one byte per event) for the samefc_…item. The stream is never idle, so the 120 s idle watchdog (GJC_OPENAI_STREAM_IDLE_TIMEOUT_MS) never fires. The turn ends only when the relay closes it withrequest_timeout, about 900 s later. The arguments are truncated, so refusing salvage is correct here.f1a64daf-a115-4336-8c5e-c824bd019b70:acp_prompt_watchdog_expired(silenceMs 640001,lastFrameType:"agent_start"). No frame reached ACP while the call streamed.request_timeout)gpt-6.1-sol, todo_write) after the retry. The retry worked right away.lastFrameType:"agent_start". Eachagent_startexpiry is followed by asalvage refusedabout 4 m 20 s later. The ACP client gives up first. Our runner then records the run as "no commits" while the session is still working.Suggestion, in addition to the proposal: add a total-duration or progress bound for a single function-call argument stream, so a 1-byte trickle cannot hold a turn for 900 s. Also emit an ACP frame (tool-call start/progress) while arguments stream, so
agent_startis not the last frame for 10+ minutes. Timeouts and retry counts on our side are unchanged.Yeachan-Heo commentedon Oct 7, 2026
Resolved on dev by PR #6348, merged as ba4c77657208. It adds a bounded one-shot retry for transient
request_timeoutwhen Codex tool-call arguments are still incomplete, rather than ending the turn asprompt_failedwith an unexecuted partial call.The post-merge reproduction in the latest report confirms
argumentsComplete: falseand shows the retry followed by a successfultodo_writeassistant response. CI on exact PR head433b01197f45d99039c5ced08b267a61def20b11passed, including both affected AI test jobs. No additional patch is needed.—
[repo owner's gaebal-gajae (clawdbot) 🦞]