「输出超时,已自动结束」。用户看到这个提示,肯定以为失败了。但检查客户机的文件系统发现:~/.skillhub/config.json 和 ~/.local/bin/skillhub.cmd 都已落地,时间戳是 17:51:16 和 17:51:19。文件装好了。错位了。
现象
某客户机(Windows),用户让 deepseek-v4-flash 帮忙手动安装 SkillHub CLI,在无 bash 环境下。AI 开始顺利执行:先 web_fetch 拉取安装文档,提示「先检查是否已安装 SkillHub CLI」,随后进入连续工具循环——exec / read / write 轮流调用,手工解包 tarball、复制 .py 文件、写 skillhub.cmd、修改 PATH。
约 90 秒后,聊天框直接弹出系统消息:「输出超时,已自动结束」。AI 的输出被截断,会话强制结束。
看起来失败了。但检查客户机发现:~/.skillhub/config.json 和 ~/.local/bin/skillhub.cmd 都已落地,时间戳分别是 17:51:16 和 17:51:19。文件装好了。
这就是那个典型的"前端保护机制掩盖后端真实状态"的现象——超时提示完全错误,但用户根本看不到真相。
排查过程
第一步:找到超时提示的源头
grep 整个 wakou-full 仓库搜「输出超时,已自动结束」,定位到两个位置:src/locales/zh-CN.json:1655 的多语言文本,以及 src/pages/chat.js:1909 的调用点。
第二步:看计时器的逻辑
打开 chat.js:1907-1917,这是一个 90 秒的安全计时器。每次收到 text delta 事件就调用 clearTimeout() 重置,超时后就执行 appendSystemMessage(t('chat.streamTimeout')) 加上强制 reset 流式状态。
逻辑看起来合理,但 reset 的触发条件很关键:
if (state === 'delta') {
...
if (c?.text && c.text.length > _currentAiText.length) {
...
clearTimeout(_streamSafetyTimer)
_streamSafetyTimer = setTimeout(() => { ... 90s 后强切 ... }, 90000)
}
}
只有在 state === 'delta' 且 text 长度增长 时才会 reset。这是关键漏洞。
第三步:找会话记录验证
进客户机的本地数据目录,找到 data/openclaw/agents/main/sessions/ 下的会话日志文件(JSONL 格式),时间范围 17:50:32 → 17:51:22,约 50 秒跨度。逐行解析事件流:
17:50:32 - state: 'delta', text: '先检查是否已安装 SkillHub CLI。'
17:50:35 - state: 'delta', text: '正在检查...' (这是最后一个 text 输出)
17:50:37 - state: 'thinking', reasoning_content: [...]
17:50:43 - state: 'toolCall', tool: 'exec', args: {...}
17:50:45 - state: 'toolResult', result: {...}
17:50:46 - state: 'thinking', reasoning_content: [...]
... (重复的 thinking + toolCall + toolResult 循环)
17:51:15 - state: 'toolResult', result: '文件已写入 ~/.local/bin/skillhub.cmd'
共 10+ 轮 thinking + toolCall 事件。期间没有任何新的 text 块。最后一次 text 输出发生在 17:50:35,然后就是工具循环。
90 秒的计时器从 17:50:35 开始计数(此时最后一次 reset),约 17:52:05 时触发(距离最后的活动已经 90+ 秒)。
第四步:发现被吞掉的真实错误
同时期的后端日志 profile/Temp/openclaw/openclaw-2026-05-02.log,17:51:41 记录了一条 deepseek API 返回 400:
error: The reasoning_content in the thinking mode must be passed back to the API.
code: 400
这是 deepseek 的 thinking 模式协议要求——当模型产出 reasoning_content 时,agent runtime 必须在下一轮请求里回传这段内容,否则 API 会拒绝。wakou 的 agent runtime 在多轮对话中没有正确回传,导致了这个 400 错误。
但这条错误被前端 watchdog 抢先吞掉了。用户只看到「输出超时」,工程师也看不到真实的 API 错误。排障线索完全丢失。
根因
两层问题叠加:
一级问题:超时判据不完整
计时器只把 text delta 当作"模型仍在工作"的信号。但当下 agent 的常态是长工具链和长思考链:
thinking事件只是模型的 reasoning_content,不增加c.text长度,不会 reset 计时器;toolCall/toolResult事件走的是另一条消息路径(payload.message.tools),同样不触发state === 'delta'的分支;- 实际的工具执行(比如 web_fetch、exec 在 Windows 上跑 Invoke-WebRequest 拉 tarball)可能耗时 30s+。
只要"两次连续 text 输出之间的间隔 > 90s",watchdog 就会误杀。而这种间隔在「先报告思路 → 进入长工具循环 → 工具执行完成后汇报结果」的对话模式里是完全正常的,不是异常。
二级问题:错误被覆盖
watchdog 误杀后,前端把 state:'error' 的事件处理路径也覆盖掉了。后端返回的真实错误(比如这次的 deepseek 400)无法被用户和工程师看到。排障难度上升,因为现象看起来就是"超时",导致团队去排查网络、延迟、模型响应,而不是去看 API 协议是否实现正确。
修复
根治方案:让超时判据覆盖所有"活着"的信号
需要前后端配合。前端不能只看 text delta,而是只要后端还在工作就持续 reset;超时只在"真的什么都没发生"时才触发。
后端侧修改(gateway / agent runtime)
在 SSE/事件发送处,在工具调用、reasoning、思考阶段持续推送 keepalive 事件。两个等价做法:
推荐方案:新增独立事件
每隔约 10 秒推一个 state:'progress' 事件,payload 带当前阶段标签和进度信息。这样前端在收到任意非 final|error 事件时都能 reset 计时器。事件语义清晰,后续 UI 也能基于 progress 显示"正在执行 xxx 工具"。
备选方案:复用 delta 承载
在 thinking / tool 阶段把当前阶段名、工具名、进度作为非空 payload 的 delta 推出来(不一定要写到 text 字段),前端在收到任何 delta(含 thinking、tools 字段更新)时统一 reset。这个方案改动小但语义不如第一种清晰。
前端侧修改(src/pages/chat.js)
把 reset 触发条件从"只看 text 长度增长"放宽到"收到任何 state ≠ final|error 的事件":
if (state === 'delta' || state === 'progress' || state === 'tool_running' || state === 'thinking') {
clearTimeout(_streamSafetyTimer)
_streamSafetyTimer = setTimeout(() => { ... }, STREAM_TIMEOUT_MS)
}
同时把 STREAM_TIMEOUT_MS 从 90 秒调整到 180 秒作为兜底。即便 keepalive 事件因为网络或其他原因没按时来,也给后端、网络、模型多留一点容错空间。建议把 STREAM_TIMEOUT_MS 常量提到文件顶部,方便后续按不同客户场景调整。
顺手修的二级问题
watchdog 触发后不要清空 runId 状态,给后端一个继续把 final / error 事件推上来的窗口。这样真实错误(包括 deepseek 的 API 400、超时、业务逻辑错误)仍能展示给用户和工程师,便于排障。
修改建议:
if (timeout triggered) {
appendSystemMessage(t('chat.streamTimeout'))
// 不调用 resetStreamState(),保留 runId
// 让后端继续推送 final / error 事件
}
deepseek thinking 模式 reasoning_content 必须回传是另一个独立 bug(已单独跟进),不在本次范围内。
防回归
任何"前端拿超时 watchdog 守后端流"的场景都要明确"在工作"的最小信号集。只盯 text delta 是天然脆弱的,因为 LLM 工具循环里 text 本来就会出现长间隔。需要在 SSE/WS 事件规范中明确约定:后端在长任务(tool / 网络拉取 / reasoning)阶段必须有 ≤ 30 秒心跳。
测试层应构造一个"AI 执行 10+ 轮工具调用但中间没有 text 输出"的测试用例,验证 watchdog 不会误杀。监控层则需要关联前端 watchdog 触发频率与后端 error 日志,如果超时提示频繁出现但没有对应的真实错误,说明 watchdog 在误杀。
■