故障档案

一次 sessions.list,23 秒

Gateway 启动首阶段 event loop 长期阻塞,sessions.list 慢到 23 秒;根因是 plugin staging 跑主线程,结合 auth 同步等待被卡 22 秒。

sessions.list 23293 毫秒。单次 tick 延迟 21944.6 毫秒。eventLoopUtilization 是 1。这三个数字同时出现,说明的不是网络问题,是主线程被完全占满。

现象

liveness 告警显示 event loop 延迟峰值达到 22 秒,单核占用率 0.93+,event loop 实际利用率接近 1(无空闲时间):

[diagnostic] liveness warning: reasons=event_loop_delay,event_loop_utilization,cpu interval=34s
  eventLoopDelayP99Ms=14822.7 eventLoopDelayMaxMs=14822.7 eventLoopUtilization=0.994 cpuCoreRatio=0.977
  active=1 waiting=0 queued=1
[diagnostic] liveness warning: reasons=event_loop_delay,event_loop_utilization,cpu interval=38s
  eventLoopDelayP99Ms=21944.6 eventLoopDelayMaxMs=21944.6 eventLoopUtilization=1 cpuCoreRatio=0.969
  active=2 waiting=0 queued=5
[diagnostic] liveness warning: reasons=event_loop_delay,cpu interval=36s
  eventLoopDelayP99Ms=12977.2 eventLoopDelayMaxMs=19394.5 eventLoopUtilization=0.943 cpuCoreRatio=0.929

并发处理能力完全坍塌:

[ws] ←res ↓sessions.list 23293ms
[ws] ←res ↓sessions.list 13868ms

正常情况 sessions.list 响应在几十毫秒,这里到了 23 秒。同一时间窗口里 embedded agent 首次启动的阶段拆解显示:

[agent/embedded] [trace:embedded-run] startup stages:
  runId=...
  phase=attempt-dispatch totalMs=32433
  stages=workspace:1ms@1ms,
         runtime-plugins:5ms@6ms,
         hooks:0ms@6ms,
         model-resolution:2974ms@2980ms,
         auth:14045ms@17025ms,
         context-engine:1ms@17026ms,
         attempt-dispatch:15407ms@32433ms

auth 阶段独占 14 秒,attempt-dispatch 又花 15 秒,鉴权和派发两步合计 29 秒。用户的核心感受就是"打开面板就卡,发消息也卡"。

排查过程

从 liveness 告警时间戳倒推启动序列。Gateway 起来后立刻开始 plugin staging——这个阶段在 err.log 里有清晰的 trace:

[plugins] file-transfer staging bundled runtime deps
[plugins] runway staging bundled runtime deps

plugin staging 的工作是从 npm 仓库抽取 plugin 的 runtime dependencies,解包、提取,是典型的 CPU 密集 + IO 密集操作。同时前端 ws 连接可以立刻建立(端口已监听),一旦有调用(例如 sessions.list)就会被 event loop delay 阻塞。

embedded agent 首次启动时 auth 阶段 14 秒是突出的瓶颈。这一段按 stage 拆分来看,从 model-resolution(2974ms)到 auth 开始还要再花 45ms,auth 本身占了 14045ms。auth 阶段的常见操作是 token 校验或 OAuth 刷新,如果这一步走了同步 HTTP 路径(而非异步),就会把整个 event loop 卡住。

时序完全吻合:

  • 重启 Gateway → launcher 拉起 Gateway 进程
  • Gateway 进入 plugin staging(npm 包解压,CPU 拉满)
  • 同时前端 ws 连接进来,调 sessions.list(被 event loop delay 阻塞 → 耗时 23 秒)
  • 用户在面板上 send 消息 → embedded agent 触发 auth(卡 14 秒)+ dispatch(卡 15 秒)
  • 用户感觉"系统完全冻住了"

第二次启动明显变快的原因是 plugin staging 的结果有缓存(不需要重新拉 npm 包),token 也有缓存(不需要重新走 OAuth 流程)。所以这个问题严格限定在"首次启动 / 升级后第一次启动"这个窗口。

根因

未完全定位,但根据阶段耗时和 CPU 占用率,两个怀疑点都指向同一时间窗口:

  1. plugin staging 跑在主线程:npm 包的抽取是 CPU + IO 密集操作,如果不 fork 子进程而是在主线程处理,会直接阻塞 event loop。从 cpuCoreRatio 0.93+ 看,至少有一个核心被打得很满。
  2. embedded agent auth 阶段是同步阻塞:14 秒的 auth 很可能是某个云端 token 校验或 OAuth 刷新走了同步 HTTP 路径,socket 读写未超时的情况下会永远等下去,此间 event loop 毫无机会让出来。

两个问题叠加的后果是客户感受到的 22 秒冻结:plugin staging 把 CPU 占满,auth 同步等待把 event loop 卡死,任何其他操作都排队等待。

修复方案

应急处理:客户首次打开面板时等待 2 分钟再使用,或重启 Gateway 后手动刷新两次。问题会逐渐缓解,因为 plugin 缓存和 token 都会落地。这不是长期方案,但能缓解首次体验。

工程改进(三个方向):

1. plugin staging 从主线程移出

改造 staging 过程使用 worker_threadschild_process 运行,主线程只等结果信号。参考 npm/yarn 的做法:安装依赖时 fork 出一个子进程跑 install,主进程保持响应。对应修改点是 plugin 管理器的 staging 入口,把同步的文件操作改成非阻塞的 spawn/fork 调用。

2. embedded agent auth 加超时并预热

OAuth 刷新或 token 校验加超时,超时走降级路径。更激进的做法是启动时就发起 auth 预热,不等用户第一次 send 才触发,这样用户真正交互时 token 已经热了。

3. 分离 /health/ready 端点

现在 Gateway 只要端口能监听就被认为"健康",但实际工作状态是"正在初始化"。建议:

  • /health 保持轻量级,返回存活状态
  • /ready 检查真实就绪条件(plugin staging 完成、token 预热完成)
  • ws 连接在收到 401 或 503 时附带 Retry-After header 让前端等待

这比让用户等一秒感受到的卡顿好得多。"假就绪 + 真卡顿"的体验等于欺骗,"真就绪 + 明确告诉你还要等"的体验是可控的。

防回归

构建期应增加代码静态检查,确保 plugin staging 的实现确实 fork 了子进程而不是在主线程同步运行。liveness 告警的精细度也要提升,eventLoopDelayMaxMs 达到一定阈值时向前端报警,而非仅作后台日志。冷启动时的性能验证目前还没有明确目标,需要补充。

结论

单一的性能问题往往由多个原因叠加触发。这里是 plugin staging 的 CPU 密集操作 + auth 同步等待 + 缺乏就绪状态隔离,三层一起压向用户。解决任何一层都能改善,但完整修复需要同时改三个地方:把 CPU 工作从主线程移走,把网络等待加超时,把"我能接请求"和"我真的准备好"分开。

星野的头像

星野 XINGYE

一个人维护 AI 平台的工程师。这里记录 63 篇复盘:18 份故障档案、OTA、架构演进与工作流。