Explorar el Código

chore(codex): 桥接补请求级诊断,用于定位 15 秒 request timed out

每 ~15 秒一条 "stream disconnected - retrying sampling request" 加 sampling_error
"request timed out",5 次后 falling back to HTTP,那一轮最终仍完成 —— 症状是重试放大,
不是端点不可达。但四个可能的超时来源全部实测排除:桥接层没有任何超时常量;
构造「首事件前静默 26 秒」「首事件后静默 30 秒」两种场景,默认与 stream_idle_timeout_ms=120s
都是单次请求零重试;旁路嗅探 TCP 首包确认 Codex 不发 WebSocket upgrade;
复刻 100 秒单槽排队也是 100.5 秒正常完成。

所以 15 秒只能来自那一轮真实请求,而桥接此前只记过「已启动」一行,判不出是谁先放手。
本轮只加日志、不改行为:起请求时记录 model/stream/tools/messages/输入字数与目标 URL,
结束时记录耗时与「上游字节数→事件数」,另外单列两种决定性情况 ——
「Codex 提前断开(耗时,已发 N 个事件)」与「上游 HTTP xxx(耗时)」,全部走既有诊断出口落 ee.log。

下一轮真实提问即可定死归属:出现提前断开 = Codex 侧阈值;出现上游 HTTP/不可达 = 端点侧。
未做也先记一笔:Codex 挂断后桥接不取消上游生成,被放弃的请求继续占唯一的槽,
这是重试互相排队的放大器(待加 AbortController)。

验证:tsc --noEmit 0 报错;vitest 109 passed;诊断行样例由真 codex.exe + 真桥接 + mock 上游实跑取得。
cc hace 2 semanas
padre
commit
ff80af944f

+ 36 - 0
.workbuddy/memory/2026-09-24.md

@@ -468,3 +468,39 @@ Codex 只在**成功跑完一轮**后才落盘(`state_5.sqlite` 的 `threads`
 验证:tsc 0 报错;vitest 108 passed;vue-tsc 93 存量、src/codex 与 aiPlugin 命中 0
 (中途一次「0 报错」是我拆掉前端 junction 造成的假数,已重跑取实数)。
 未跑 itest(会写 data/codex-home 与 provider.json)、build、真实界面点击。
+
+## 「request timed out」排查:四个假设全被实测否掉 + 桥接补请求级诊断
+
+现场:codex stderr 每 ~15.0 秒一条 `stream disconnected - retrying sampling request (n/5)`、
+`sampling_error: "request timed out"`,5 次之后 `falling back to HTTP`;那一轮 21:34 完成、
+`ee.log` 里没有 `turnRun failed` —— 不是连不上,是被重试拖死。
+
+逐个否掉(全部真 codex.exe + 真桥接 + 受控 mock 上游):
+
+| 假设 | 实测 |
+| --- | --- |
+| 桥接有超时 | `chatBridgeService`/`chatBridgeTranslate` 无任何 timeout 常量 |
+| `stream_idle_timeout_ms` 默认 15s | 首事件前静默 26s、首事件后静默 30s,默认与 `=120000` 均 1 次请求、零重试 |
+| Codex 走 WebSocket、桥接无 `upgrade` 监听导致挂起 | 旁路嗅探 TCP 首包:零 upgrade,只有 `POST /v1/responses` |
+| 单槽排队堵死 | 复刻 100 秒排队:1 请求、同时在飞 1、100.5s 成功、零重试 |
+
+端点侧事实(`GET /props`):`total_slots: 1`、`n_ctx: 262144`、build b1005;
+流式 600 token 实测首字节 98.8 秒(生成只 10.5 秒、prefill 268ms)→ 那 98.8 秒是排队。
+
+结论:**15 秒只能来自那一轮真实请求**,而桥接此前只记过三行「已启动」,无法判断谁先放手。
+本轮只加日志(不改行为):`chat-bridge: #N 起 round model/stream/tools/messages/输入字数 → url`、
+`转发完成(耗时,上游字节→事件数)`、`Codex 提前断开(耗时,已发 N 个事件)`、
+`上游 HTTP xxx(耗时)`。下次真实提问即可定死:出现「Codex 提前断开 @15s」= Codex 侧阈值;
+出现「上游 HTTP/不可达」= 端点侧。
+
+顺带记下与 cc-switch「路由」的对照:那类开关做的是「声明上游接口格式 + 本地代理转协议」,
+我们的对应物就是内置桥接(应用模型时自动开,Codex 侧 `wire_api="responses"`)。
+差距在可配面:0.155.1 的 provider 认 `request_max_retries / stream_max_retries /
+stream_idle_timeout_ms / websocket_connect_timeout_ms / supports_websockets / query_params /
+http_headers …`,我们白名单只放行 4 个,所以「关 websocket」这类操作现在配不出来 —— 
+等 15 秒归属确认后再决定要不要放开,别提前改。
+
+另记 F1(未做):Codex 挂断后桥接不取消上游生成,会一路读到 `[DONE]`,
+被放弃的请求继续占唯一的槽 —— 这是重试互相排队的放大器,加 AbortController 绑 `res` 关闭即可。
+
+验证:tsc 0 报错;vitest 109 passed;诊断行样例由受控 mock 实跑取得。未跑 build / itest。

+ 37 - 7
ai-electron/electron/service/codex/chatBridgeService.ts

@@ -53,6 +53,9 @@ export class ChatBridgeService {
 
   #options: ChatBridgeOptions | null = null;
 
+  /** 诊断里区分同一轮里的多次上游请求 */
+  #seq = 0;
+
   /** 装配层(index.ts)注入的诊断出口;start 时的 onDiagnostic 优先 */
   #diagnostic: DiagnosticFn | null = null;
 
@@ -140,6 +143,15 @@ export class ChatBridgeService {
 
     const chatReq = responsesRequestToChat(responsesReq, (line) => this.#diag(line));
     const upstream = `${options.upstreamBaseUrl.replace(/\/+$/u, '')}/chat/completions`;
+    const id = ++this.#seq;
+    const t0 = Date.now();
+    const secs = (at: number = Date.now()): string => `${((at - t0) / 1000).toFixed(1)}s`;
+    const inputText = typeof responsesReq.input === 'string' ? responsesReq.input : JSON.stringify(responsesReq.input ?? '');
+    const messages = Array.isArray(chatReq.messages) ? chatReq.messages : [];
+    this.#diag(
+      `chat-bridge: #${id} 起 round model=${responsesReq.model ?? '?'} stream=${chatReq.stream ? 'Y' : 'N'} ` +
+        `tools=${Array.isArray(chatReq.tools) ? chatReq.tools.length : 0} messages=${messages.length} 输入≈${inputText.length}字 → ${upstream}`,
+    );
 
     let upstreamRes: Response;
     try {
@@ -150,14 +162,14 @@ export class ChatBridgeService {
       });
     } catch (error) {
       const message = error instanceof Error ? error.message : String(error);
-      this.#diag(`chat-bridge: 上游不可达:${message}`);
+      this.#diag(`chat-bridge: #${id} 上游不可达(${secs()}):${message}`);
       this.#failJson(res, 502, `桥接上游不可达:${message}`);
       return;
     }
 
     if (!upstreamRes.ok) {
       const text = await upstreamRes.text().catch(() => '');
-      this.#diag(`chat-bridge: 上游 HTTP ${upstreamRes.status}:${text.slice(0, 300)}`);
+      this.#diag(`chat-bridge: #${id} 上游 HTTP ${upstreamRes.status}(${secs()}):${text.slice(0, 300)}`);
       this.#failJson(res, upstreamRes.status, `桥接上游返回 HTTP ${upstreamRes.status}:${text.slice(0, 500)}`);
       return;
     }
@@ -167,7 +179,9 @@ export class ChatBridgeService {
         const chatJson = (await upstreamRes.json()) as Parameters<typeof chatResponseToResponses>[0];
         res.writeHead(200, { 'content-type': 'application/json' });
         res.end(JSON.stringify(chatResponseToResponses(chatJson, responsesReq)));
+        this.#diag(`chat-bridge: #${id} 非流式完成(${secs()})`);
       } catch (error) {
+        this.#diag(`chat-bridge: #${id} 非流式解析失败(${secs()})`);
         this.#failJson(res, 502, `桥接解析上游响应失败:${error instanceof Error ? error.message : String(error)}`);
       }
       return;
@@ -180,6 +194,20 @@ export class ChatBridgeService {
       connection: 'keep-alive',
     });
     const translator = new ResponsesSseTranslator(responsesReq, (line) => this.#diag(line));
+    let bytes = 0;
+    let events = 0;
+    let aborted = false;
+    const write = (items: BridgeSseEvent[]): void => {
+      events += items.length;
+      writeSseEvents(res, items);
+    };
+    // Codex 提前挂断是这次排查的关键信号:没有这行就是上游自己停了
+    res.once('close', () => {
+      if (!res.writableEnded) {
+        aborted = true;
+        this.#diag(`chat-bridge: #${id} Codex 提前断开(${secs()},已发 ${events} 个事件)`);
+      }
+    });
     try {
       if (!upstreamRes.body) throw new Error('上游响应没有 body');
       const reader = upstreamRes.body.getReader();
@@ -187,14 +215,16 @@ export class ChatBridgeService {
       for (;;) {
         const { done, value } = await reader.read();
         if (done) break;
-        writeSseEvents(res, translator.push(decoder.decode(value, { stream: true })));
+        bytes += value?.byteLength ?? 0;
+        write(translator.push(decoder.decode(value, { stream: true })));
       }
-      writeSseEvents(res, translator.push(decoder.decode()));
-      writeSseEvents(res, translator.finish());
+      write(translator.push(decoder.decode()));
+      write(translator.finish());
+      this.#diag(`chat-bridge: #${id} 转发完成(${secs()},上游 ${bytes}B → ${events} 个事件)`);
     } catch (error) {
       const message = error instanceof Error ? error.message : String(error);
-      this.#diag(`chat-bridge: 流式转发中断:${message}`);
-      writeSseEvents(res, translator.fail(message));
+      this.#diag(`chat-bridge: #${id} 流式转发中断(${secs()}):${message}`);
+      write(translator.fail(message));
     }
     res.end();
   }