第 18 章 事故复盘

第 18 章 事故复盘
MoE 大模型低成本部署框架第 18 章 事故复盘
CHAPTER 18

第 18 章 事故复盘

16 分钟阅读 · 4,239 字

六次真实事故，统一格式：现象 → 定位过程 → 根因 → 修复 → 教训。
这一章不是故事集，是判据库：下次出现类似症状时，先在这里对号入座，
因为六次事故里有四次的第一反应都是错的。

时间一律北京时间；进程事件时间以 ~/deploy/logs/supervisord.log（UTC，+8）为准。

18.1 六次事故一览

# 事故 发生 第一反应 真根因 现状
1 每卡一实例 solo 9.3 tok/s 2026-10-07 “单卡装不下专家” 两个引擎的 CPU 专家池抢核 已解决（钉核）
2 八并发 TTFT ~2 分钟（驱逐风暴） 2026-10-07 晚 “引擎 prefill 有 bug” 停车快照 4.7 GB > 预算 8 GiB → 驱逐 2508 次 → 每轮重读 238k 已定位，旋钮未调
3 Claude 会话"只有 thinking 没有正文" 2026-10-17 晚 “上下文太长就坏” prompt 里的特殊 token 字面量被模型复述 → 生成真 EOS 快道已修，普道 10-19 才跟上
4 会话 bd7e62ed 反复只读排查 + 误报"目录被删" 2026-10-18 晚 “又是早停” 模型路径幻觉 + 计划-执行断裂（不是截断） 无代码修复，加 agent 规则
5 写书会话 848a12ed 说要写却没写 2026-10-19 中午 “tool schema 丢了 / max_tokens 截断” 原始任务前缀被 RAG 组装挤掉 + B 模式 plan-then-EOS 无代码修复，任务卡实验有效
6 同一请求三方 token 数字打架 + 盲重试 2026-10-19 12:49–14:15 “中继算错了” 四层计数口径不同 + 网关上界估算英文高估 3.3× + 400 后压 max_tokens 盲重试 当日修复（网关侧）

18.2 事故 1：9.3 tok/s —— 容量解释不了数量级

现象（2026-10-07，Strata-双卡部署全景.md §3 方案 2）：把单实例拆成每卡一个独立实例后，
solo 解码从 76.8 tok/s 崩到 9.3；2 路 16.1、4 路 24.0、8 路 17.2 且有 6/8 拿不到 token。

定位过程：

  1. 第一版解释：单卡装不下全部专家（专家 arena 只有一半），所以命中率崩 → 落盘 → 慢。
  2. 第二轮实验：把 --pool-workers 从 24 降到 13（仍然共享同一批核）→ 仍然 6–17 tok/s，没救回来。
  3. 第三轮：给两个实例钉核（A taskset 0-15、B 38-53），worker 数不变 → 98–107 tok/s。

根因：两个引擎各自的 CPU 专家池（各 24 worker）在 32 核 cgroup 里互相抢核，
CFS 节流把两边一起压死。容量假设是错的——它解释不了"数量级"级别的崩塌，
也解释不了"降 worker 数无效但钉核有效"。

修复：run-iq3_xxs-a.sh / -b.sh 里的 taskset（15 章 §15.3），并把钉核写进硬约束 3。

教训（三条）：

  • 排除法要选能区分假设的实验。“降 worker 数"区分不了"抢核"与"容量”，"钉核"能。
  • 数字量级是线索：容量不足通常是 2–3 倍退化，数量级退化多半是调度/资源争抢。
  • 这条结论后来被写进"已否决方案翻案"：早期"同型号单卡实例扩吞吐"曾因 9.3 被否决，钉核后翻案为现生产（11 章）。

18.3 事故 2：驱逐风暴 —— 机制没错，容量与密度配错了

现象（2026-10-07 晚，10-08 定位）：普道 strata-b 八并发 TTFT 约 2 分钟（问题 #1 的 4.7 分钟口径同源）。

定位过程（memory: strata-ttft-prefill-queue，解析 ~/Strata/strata-iq3_xxs-b.log）：
先确认引擎本身能复用——同一会话逐轮增量时
prompt 253214 = 251787 reused + 1427 read in 2196 ms（2.2 秒）。
再看停车明细行：

证据 数字
一条 254k 会话的快照 parked=1 bytes=4716362992 ≈ 4.7 GB
预算 --conversation-cache-mib 8192 / slots 20
全天驱逐 evictions 2508
194 条 ≥200k 提示词 123 条只复用 16384 token（= prompt-cache-every 默认步长）

根因链：快照 4.7 GB > 预算 8 GiB → 装两三条就驱逐 → 被驱逐的会话下一轮只能靠检查点 →
检查点密度 16384 → 只救回 16384，其余 ~238k 整段重读 → 重读走全局串行 prefill → 八并发排队叠加。
放大因素：当晚 15:21–19:40 的 1M 精度全量套件刻意全部打到 strata-b（快道留给真实用户），
压测流量与真实用户在同一队列里。

修复：四个旋钮已列未做（conversation-cache-mib 8192→24000+、prompt-cache-every 16384→4096、
普道准入、组装预算封顶），都要停服窗口；候选修复"按快照大小跳过 park"已记入待办。

教训：

  • "引擎有 bug"与"引擎被配置坑了"要用反例区分：同一会话的 2.2 秒反例直接排除了机制问题。
  • 观测缺失会让这类事故反复发生——evictions= 只在引擎日志里，/health 没有（盲区清单 §6.2）。
  • 红线"压测只打普道"有另一面：普道被打满时，真实用户就在同一队列里。

18.4 事故 3：特殊 token 早停 —— 58 / 295 的对照

现象（2026-10-17 22:00–23:53）：Claude Code 走本地模型时反复出现"只有 thinking、没有正文"，
客户端注入 [Your previous response had no visible output...] 自动续写；另有工具调用 JSON 被截断。

定位过程（docs/reports/CLAUDE-EARLY-STOP-2026-10-18.md）：

  1. 分层取证：客户端（Claude 自己承认无可见输出）→ 网关留档（infer.db + infer-segs，
    请求里确实有特殊 token 字面量、响应确实停在那半句）→ 引擎层（EOS 是合法停止条件）。
  2. 最小复现：同一句解释任务，保留 <|endoftext|> / <|im_end|> 字面量 →
    finish=stop、content=None、reasoning 截断在 ... end-of-turn token (；
    把字面量换成纯数字 → 正常 176 tokens 正文。
  3. 关键细分：Repeat exactly: ABC<|im_end|>XYZ → 输出 ABC 后停止；
    而"user 里含该 token 但要求回答 2+2" → 正常答 4。
    → 触发点不是"prompt 里出现"，而是"模型在输出里复述了它"。
  4. 统计对照（2026-10-17 快道，同一天内）：
分组 请求数 thinking-only 工具 JSON 坏 有正文
含特殊 token 字面量 58 16 5 20
不含特殊 token 295 0 1 169

这组对照是本案的判决点："上下文长"是相关但不是根因——295 次里不少也是长上下文，0 次 thinking-only。

根因：generate.cpp 注释里含特殊 token 字面量 → 模型在 thinking / 工具参数里复述 →
tokenizer 以 parse_special=True 编码 → 生成真 EOS（248044 / 248046）→ 引擎按正常轮次结束停止。
与 10-17 20:34 的引擎切换无关：最小复现在普道 B（legacy）上同样成立，
Strata 与 SSEStraBed 的 generate.cpp 非注释行无差异。根因在共享的 serve 层 + 词表。

修复（2026-10-18，archive/patches/serve-special-token-escape-2026-10-18/）：
frontend.py 把 27 个 CONTROL 类字面量的首字符后插入 U+2063（INVISIBLE SEPARATOR），
Detokenizer.push 从输出里剥离 → 客户端仍看到原始字面量；/v1/status 新增
prompt_escapes / stops_while_reasoning 计数；STRATA_ESCAPE_SPECIAL=0 可关。
不改引擎 C++（EOS 语义本身正确），不改网关。
部署：14:15:36 重启 strata-a → 14:22:51 ready（7 分 15 秒），普道 B 未动；
原始 incident prompt 重放 → finish=tool_calls、1 个 Bash 调用、不再中途停止。
（B 直到 10-19 18:58 重启才吃上新代码。）

教训：

  • 别把"相关性"当根因：长度与早停相关，但 295 次对照把长度假设打死了。
  • 同一天的同通道对照是最便宜的判决工具。
  • 修复放在 serve 编码层而不是引擎：一处覆盖所有客户端，且可开关回滚。
  • 残余的 B 模式（无特殊 token、计划完就 EOS）当时未根因 → 事故 4/5 就是它的两次现身。

18.5 事故 4：bd7e62ed —— 路径幻觉、误报被删、计划-执行断裂

现象（2026-10-18 23:14 → 10-19 00:04）：让模型给 SSEStraBed/src/program/generate.cpp 加中文注释。
前半段正常（23:32:26 对正确文件 dry-run，56 个锚点命中）；后半段开始读
/home/cloud/dev/strata/...、/home/cloud/worker/StrataEngine/...、/home/cloud/work/engines/...
等不存在的路径，每次都是 File does not exist，然后在 23:58:02 报告"/home/cloud/worker 整个不见了，15:44 被删除"。

定位过程（docs/reports/SESSION-BD7E62ED-DIAGNOSIS-2026-10-19.md）：

  1. 先排除早停：84 个 assistant 响应，stop_reason = tool_use 83 / end_turn 1，
    thinking-only 0，自动续写注入 0 → 与事故 3 不是同一类。
  2. 核对"被删"主张：worker 路径的每一次 Read 都是 File does not exist；
    成功读取的从来是 SSEStraBed/src/program/generate.cpp（7862 行，mtime 2026-10-18 06:13，中文行数 0，完好）。
    没有 rm、没有源码写入、没有数据丢失——“被删"是把"读不到"误解释成"被删”。
  3. 量化重复动作：后半段 54 次 Bash，strata_generate 11 次、find / 9 次、/home/cloud/worker 7 次。
  4. 抓最后一轮：两个不同 message id（不是转录重复）——第二轮把上一轮的 thinking 与计划句
    逐字重复，然后 end_turn，既没执行承诺的检查也没给总结。
  5. 查原始留档排除技术原因：infer.db 里两轮分别是
    20261019-000029-de091a（101→98 messages、prompt 86,472、1 tool_call、finish=tool_calls）与
    20261019-000107-5c6c32（101 messages、prompt 87,890、completion 740、content 67 字符、finish=stop、0 tool_calls）。
    第二轮 prompt 变长了（含上一轮 tool result 与上一轮 assistant 文本）→ 不是客户端重试；
    原始 response 的 content 就是那句 67 字符计划句 → 不是 serve/网关截断。

根因：模型侧。错误前提（目录被删）没有停止条件 → 连续只读排查；
最后一轮复读上一轮计划句后正常 EOS。引擎/serve 被证据排除；
"模型内部为什么重复"只能推断，不能黑盒证明——报告自己写明了这条边界。

修复：没有代码修复。产出两条 agent 规则（已进 memory）：
① 用绝对路径前先 ls/realpath 验证；不要把从未成功读取过的路径当成"曾经存在"；
报告目录被删前必须给出该路径此前成功读取的工具结果；
② 同类只读检查连续两次没有新信息 → 停止排查先给总结；说"接下来要检查 X"就必须真的调工具。

教训：

  • “读不到” ≠ “被删”。这是最容易造成不可逆动作（去"恢复"一个不存在的目录）的一类误判。
  • 判断"是不是截断"的权威依据是 infer 原始留档：prompt 是否变长、content 原始长度、finish_reason、有无 tool_calls。
  • 长会话里重新给出绝对路径比指望模型记住更有效。

18.6 事故 5：848a12ed —— 任务锚点被组装挤掉

现象（2026-10-19 中午，写书会话）：模型 thinking 里写"Let me write 04 and 05 now"，
响应里 0 个 tool call、finish=stop、正文只有一句进度话。书没写完。

定位过程（docs/reports/SESSION-848A12ED-BOOK-EARLY-STOP-2026-10-19.md）——逐项排除用户怀疑：

怀疑 核对结果
特殊 token（A 模式）？ 四次早停的请求里特殊 token 计数 0；同会话 prompt_escapes={"calls":365,"literals":1603} 说明转义在别处正常工作
tool schema 丢了？ 没丢：request.sent.tools 有 55 个工具，Write 在列，system（6,019 字符）也在
max_tokens 截断？ 不是：max_tokens=32000，completion 只有 3,240 / 267；引擎日志 thinking: 3194 of max 32000 → done (stop)
开始写 tool call 被切？ 没有：done 之前没有 writing a tool call 行
前缀被丢？ 部分丢了，丢的不是 schema，是原始任务：mode=assembled，client_msgs=315 → sent_msgs=147，丢了 168 条旧消息，在 sent 里找不到"写一本教学书 / 持续工作 / 不要开子 agent"

判决实验（任务卡）：同一条 146,433-token 的 sent 请求末尾追加一条 TASK CARD（“现在调用 Write 写第 04 章”）：

请求 tool_calls finish 结果
原 assembled prompt 0 stop 输出计划句 / 事实摘录
同 prompt + 任务卡 1 tool_calls 10.1 s 内开始检查 04 章文件

根因：**任务锚点丢失 + B 模式（plan-then-EOS）**共同作用。
放大因素：上下文 146k/156k、单章 12–21 KB 的大 Write 负载、子 agent 的
Wasted call — file unchanged 提示不含"已读 range"、违反"不要开子 agent"（实际开了 3 个、Agent 调用 9 次）、
10-19 01:33 出现 429 · 模型并发已满（上限 2）。

修复：无代码修复（代理侧"组装保留任务锚点"需重启代理，未做）。有效做法：
按章拆任务、每章一个 Write 落盘动作、长会话过 100k 就开新会话、模型说"Let me write…“时直接回"现在调用 Write”。

教训：

  • 上下文里"有工具定义"不等于"有任务"。组装保住了 tools 与 system，丢的是用户目标与约束。
  • 做对照实验时只改一个变量：这条 146k 请求原样重放 + 一句任务卡，10 秒内翻转结论。
  • 这条对本书直接生效：本任务（11–19 章 + 附录）就是按"一章一个 Write"拆开的。

18.7 事故 6：四层计数互相打架 + 盲重试

现象（2026-10-19）：同一个请求四个数——
Claude Code 显示 157.9k、中继报 ~398,890 > 256,000、引擎报 372,066 > 262,144（#545）、
而网关自己的估算 516,561。14:14:58 / 14:15:04 / 14:15:10 连续三次 400。

定位过程（docs/reports/CONTEXT-COUNT-BILLING-2026-10-19.md）：

  1. 找留档：seg-124459-7aa82.jsonl.gz，会话 auto:15eb3770f7f979bf，12:49:00，
    请求体 1,075,447 字符（CJK 仅 5.3%），引擎记 154,796，代理估算 516,561（3.34×）。
  2. 追 400 文案归属：#545 由 serve/server.py:1760-1763 写；
    rag_proxy.py:1715-1720 的 retry_on_overfit 把 max_tokens 压到 1 盲重试并透传上游文案；
    中继那条文案不在本 Pod（git log -S 查无）。
  3. 查估算器：rag_proxy.py:106-108, 229-230 的系数（CJK 1.05 / 其他 0.70），
    注释自证实测英文 0.19、代码 0.39 → 英文高估 ~3.3×。危害不只是报错，
    而是 clamp_max_tokens（:265）与思考预算（:372）被虚高压缩。
  4. 定计费口径：引擎 usage 为真值（infer_store 记的就是引擎数），400 不占 GPU、不计费。

修复（当日下午落地，网关侧，重启 rag-proxy 即生效）：
窗口预检（调 serve 的 /v1/messages/count_tokens 精确计数）、
overfit_info()/overfit_error() 把 400 改写为 prompt is too long: N tokens > M maximum

  • prompt_tokens/max_context/max_output_tokens + 中文 hint、不再透传 #545、
    room<1 不再盲重试、no_rag 透传分支先精确计数、serve 未升级 404 自动降级。
    test_window_guard.py ALL PASS（6 s，顺带修了两处脱节：A6 stub 4→5 元组、B/C 组强制 rag_enabled=True）。
    探针：300,000 个「龘」→ 引擎 600,052 → 结构化 400（本地拒绝，不进引擎、不浪费 GPU）。

时间口径冲突（不静默选）：报告写"rag-proxy 已重启，pid 3426352，15:33 北京"，
而 supervisord.log 记录同一 pid 生成于 08:41:42 UTC = 16:41:42 北京（10-19 全天只有
13:07 / 13:56 / 16:41 三次 rag-proxy 重启，没有任何 15:33 前后的进程事件）；
rag_proxy.py 的 mtime 是 15:28 北京。进程事件以 supervisord 为准，报告的 15:33 更像改代码完成的时刻。

教训：

  • 计数必须声明"谁数的"：客户端 / 中继 / 网关估算 / 引擎四层各有各的口径，本书以引擎实测为权威（14 章）。
  • 估算器的危害不止于报错：它会静默压缩输出预算与思考预算。
  • 盲重试 + 文案透传 = 把上游的内部错误码变成用户看到的谜语文本。
  • 日志时区不统一：supervisord.log 与 rag-proxy 的 [HH:MM:SS] 前缀是 UTC
    （rag_proxy.py:169 用裸 time.strftime），switch-engine.log 与 infer_store 归档名是北京时间。
    跨日志对齐前先换算，否则差 8 小时。

18.8 六次事故的共同模式

模式 出现于 对策
第一版归因是错的 1（容量）、2（引擎 bug）、3（长度）、4（早停）、6（中继算错） 归因前先问"哪个实验能证伪它"
同一天同通道的对照组最便宜也最致命 3（58 vs 295）、5（有/无任务卡）、6（网关 200 vs 引擎 400） 写进测试台纪律（13 章 §13.7）
观测缺失让事故反复发生 2（evictions 只在引擎日志）、3（无 stop token 计数）、6（无权威计数） 补观测与修复同等重要（盲区清单 §6.2）
“文档/注释与现实不符” 15 章三处、16 章两处、14.11 的 15 条 引用前当场核实（行号、端口、mtime）
模型行为问题被误当成基础设施问题 4、5 用 infer.db 原始留档先排除截断/重试，再谈模型
修复尽量放在重启代价低的一层 3（serve 而非引擎）、6（网关而非引擎） 网关秒级、serve 分钟级、引擎 6–13 分钟（15 章 §15.9）

18.9 本章小结

  • 六次事故里，五次的第一反应是错的；每一次翻案都靠一个便宜的对照实验，而不是靠更强的推理。
  • 三条最可复用的判据：
    ① 数量级退化先查资源争抢，不查容量；
    ② “读不到"不等于"被删”，“没正文"不等于"被截断”——后者用 infer.db 判；
    ③ 数字必须带"谁数的、何时、何配置"，否则四层计数会把你带偏。
  • 六次里只有 1、2、3、6 产生了代码/配置修复；4、5 的产出是规则。
    规则也是修复，只是它落在 agent 身上而不是进程里。
全部章节