AGENT

token-pool-worker-crash-observability-2026-04-28

2026/04/28 17 min read AGENT AUTH TOKEN POOL WORKER CRASH OBSERVABILITY

Token Pool worker crash 观测补强记录（2026-04-28）

当前结论

这轮已经完成的是：

  • master / worker supervisor 问题已修，worker 不会再“退出后无人拉起”
  • worker 启动链、崩溃链、最近一次 crash 快照已经可观测
  • live runtime 已重启到新代码，3100 与 3301 当前健康

这轮还没完成的是：

  • 真正打挂 worker 的业务请求路径还没有锁死
  • 现在属于“已经拿到抓现场工具”，下一次复现时可以直接看 crash 快照，而不是继续黑盒猜

一句话区分：

  • “系统不会再一直死着” -> 已修
  • “为什么 worker 会死” -> 还在继续定位

这轮为什么继续改代码

不是为了继续兜底，也不是为了绕过根因，而是为了补 deterministic tracing：

  • 之前 /master/diagnose 只能告诉我们 workerAlive、lastExit
  • 但 worker 如果在启动中途或请求中途炸掉，仍然缺：
    • 炸在 boot 哪一段
    • 当时有没有活跃请求
    • 最后一个 requestId / model / provider / stopReason 是什么

所以这轮改动目标只有一个：

  • 把“worker 怎么死的”从日志猜测，变成结构化证据

本轮代码改动

1. src/observability/worker-crash.js

新增能力：

  • bootStage
  • bootTimeline
  • setWorkerBootStage(stage, extra)
  • readLastWorkerCrashSnapshot()

现在 last-worker-crash.json 会带上：

  • bootStage
  • bootTimeline
  • requestId
  • path
  • model
  • providerType
  • selectedProviderId
  • stopReason
  • lastEvent
  • lastErrorMessage

也就是说，worker 就算还没进正式请求处理，也能知道死在：

  • config_loaded
  • plugins_initialized
  • services_initialized
  • http_server_created
  • listen_pending
  • ready_to_serve

中的哪一段。

2. src/services/api-server.js

新增 worker boot stage 标记：

  • api_server_module_loaded
  • config_init_start
  • config_loaded
  • plugins_discovery_start
  • plugins_initialized
  • services_init_start
  • services_initialized
  • request_handler_created
  • http_server_created
  • listen_pending
  • listening
  • ready_to_serve
  • ready_sent_to_master

同时补了几类 fatal capture：

  • startup_failure
  • http_server_error
  • uncaught_exception
  • unhandled_rejection
  • process_exit

并保留 broken pipe 抑制：

  • EPIPE
  • ECONNRESET client socket 噪音不会再污染 fatal 结论

3. src/core/master.js

GET /master/diagnose 现在不只返回文件是否存在，还会直接带：

  • lastWorkerCrashSnapshot

这样下一次 worker 再挂，不用先 SSH/翻文件，直接打：

  • GET /master/diagnose

就能先看到最近一次 crash 的结构化摘要。

4. README.md

已同步补充：

  • logs/last-worker-crash.json
  • logs/worker-fatal.log
  • /master/diagnose 现在会返回最近 crash 摘要

本轮自测与证据

隔离端口自测

用隔离实例验证了新 boot-stage 日志链：

  • master: 3112
  • worker: 3312

结果：

  • GET http://127.0.0.1:3112/master/status 返回正常
  • master stdout 中能看到完整 boot stage：
    • config_loaded
    • plugins_initialized
    • services_initialized
    • listen_pending
    • listening
    • ready_to_serve
    • ready_sent_to_master

说明：

  • 新观测链已真实落盘，不是只写了代码没走到

受控 crash 验证

随后故意制造一个可重复 crash：

  • 直接起第二个 api-server
  • 端口仍用 3312
  • 结果触发 EADDRINUSE

新快照成功写出：

  • E:\My Project\Token Pool\logs\isolated-crash\last-worker-crash.json
  • E:\My Project\Token Pool\logs\isolated-crash\worker-fatal.log

快照关键字段：

  • reason = "http_server_error"
  • bootStage = "listen_pending"
  • lastErrorMessage = "listen EADDRINUSE: address already in use 0.0.0.0:3312"
  • bootTimeline 明确停在 listen 前

这证明：

  • 不是只有 request 内 crash 能记录
  • 启动期 crash 也已经能被结构化抓住

live runtime 已切到新代码

本地 live runtime 已重启：

  • 新 master pid: 18700
  • 新 worker pid: 30156

live 验证：

  • GET http://127.0.0.1:3100/master/status -> 200
  • GET http://127.0.0.1:3100/master/diagnose -> 200
  • GET http://127.0.0.1:3301/health -> 200

同时 live master stdout 已看到新的 worker boot 日志：

  • stage=api_server_module_loaded
  • stage=config_loaded
  • stage=plugins_initialized
  • stage=services_initialized
  • stage=listen_pending
  • stage=listening
  • stage=ready_to_serve
  • stage=ready_sent_to_master

说明：

  • 不是只在隔离实例生效
  • live 3301 已经跑在这版 observability 代码上

现在怎么用这套观测

下次如果再出现“Codex 跑着跑着突然断，然后 worker 重启”：

第一步先打：

  • GET http://127.0.0.1:3100/master/diagnose

重点看：

  • lastExit
  • lastWorkerCrashSnapshot.reason
  • lastWorkerCrashSnapshot.bootStage
  • lastWorkerCrashSnapshot.requestId
  • lastWorkerCrashSnapshot.pathName
  • lastWorkerCrashSnapshot.model
  • lastWorkerCrashSnapshot.providerType
  • lastWorkerCrashSnapshot.stopReason
  • lastWorkerCrashSnapshot.lastErrorMessage

如果需要再下钻文件：

  • E:\My Project\Token Pool\logs\last-worker-crash.json
  • E:\My Project\Token Pool\logs\worker-fatal.log
  • E:\My Project\Token Pool\logs\app-2026-04-28.log

还没修的部分

目前还没有宣称“根因已锁定”，因为缺最后一跳证据：

  • 哪个真实请求
  • 哪个 provider / stream path
  • 在哪个 handler / common.js / adapter 里抛错

也就是说，这一轮的成果是：

  • 把下一次 crash 从黑盒变成可定位事件

而不是：

  • 已经修掉导致 crash 的业务 bug

当前已看到的历史线索

翻 E:\My Project\Token Pool\logs\app-2026-04-28.log 时，已经看到一条非常可疑的历史错误链：

  • 时间：2026-04-28 10:54:29
  • 请求 logger id：127.0.0.1:a22030ae
  • 现象：大量重复
    • [Server] Uncaught exception
    • code = EPIPE
    • 紧接着又被判为 Network error detected, continuing operation...

这说明旧版本里至少存在一条：

  • 客户端已经断开
  • worker 还在继续写
  • EPIPE 被重复打成 uncaught exception

的路径。

本轮 live 代码已经把 EPIPE / broken pipe 从 worker 全局 fatal 路径里单独抑制掉，所以后续如果再复现：

  • 若 crash 快照仍出现，说明已经不是这条旧 EPIPE 链
  • 若不再出现 worker crash，只剩 request abort，则说明这个历史 EPIPE storm 很可能就是先前“看起来像服务挂掉”的一条主因

新一轮 live 受控复现结果

这轮我又对当前 live 3301 做了一次更接近历史症状的本地受控复现：

  • 直接向 GET /openai/debug/requests 发请求
  • 客户端在发出请求后立刻用 reset 方式断开 socket
  • 连续复现 80 次

目的不是测业务正确性，而是验证：

  • 当前 worker 遇到“客户端突然断开”时
  • 会不会再次进入旧版本那种 EPIPE / uncaught storm
  • 甚至把 worker 打崩

结果

/master/diagnose 结果仍然是：

  • workerAlive = true
  • lastExit = null
  • lastWorkerCrashSnapshot = null

同时日志里已经不再出现旧版那种：

  • [Server] Uncaught exception
  • code = EPIPE
  • 无限刷屏

而是变成了可控的抑制日志：

  • Suppressed client socket error: ECONNRESET

并且这些日志已经带 request 关联，例如：

  • path=/openai/debug/requests
  • status=200
  • 随后记录 Suppressed client socket error: ECONNRESET

这一步说明什么

它说明：

  • 历史上那条“客户端断开 -> worker 继续写 -> EPIPE storm”链，在当前 live 代码上已经被成功摘掉了 fatal 属性

换句话说：

  • 现在就算客户端粗暴中断
  • live worker 也不会像旧版本那样进入 crash 候选态

这一步还不能说明什么

它还不能单独证明：

  • 所有 Codex “说到一半停住”的历史问题都只由 EPIPE 引起

因为：

  • 这次复现打的是 debug 路径
  • 不是完整的 provider stream / Codex 长输出链

但它已经足以证明两件事：

  1. 历史日志里的 EPIPE 风暴是真问题，不是噪音
  2. 当前 live runtime 对这类 client-abort 已经不再会被打崩

下一步

下一次只要再复现一次 worker crash，就应该按这个顺序收证据：

  1. GET /master/diagnose
  2. 取 lastWorkerCrashSnapshot.requestId
  3. 去 /openai/debug/requests 对应 requestId 对照
  4. 再回 app-*.log 找这个 requestId 的最后一条 [Request] START/ABORT/END/FATAL

如果这条链完整，下一步就能把 root cause 压到具体模块和具体异常，而不是继续只停在 “worker 会 crash” 这个层级。