oh-my-openagent 故障排查实录：Windows 全分片 CI 下 DAG happy-path 超时（6454ms）的根因分析与修复范围界定-平芜编程栈

oh-my-openagent 故障排查实录：Windows 全分片 CI 下 DAG happy-path 超时（6454ms）的根因分析与修复范围界定

【免费下载链接】oh-my-openagentOmO: Just type "mass ulw" keyword with your prompt. Now you are the master of graph engineering.项目地址: https://gitcode.com/gh_mirrors/oh/oh-my-openagent

导读

本文基于 oh-my-openagent 仓库.omo/evidence/20260817-windows-dag-happy-timeout/目录下的一份完整故障证据档案（root-cause-and-scope.md 及配套 QA、运行日志），完整还原一次"Windows 全分片 CI 下 DAG happy-path 测试超时"的排查过程：从 CI 上报的6454ms超时失败出发，逐一排除"死锁 / 事件投递缺陷"假设，最终确认根因是真实文件系统存储 + 全分片 I/O 争用放大了测试耗时，撞上了 Bun 测试运行器的5000ms默认超时，并给出一个"有界、平台限定、零行为变更"的精确修复。读完本文，你将掌握：如何用"超时突变（timeout mutation）"实验区分引擎缺陷与测试运行器预算不足；如何用历史分片耗时对比识别全分片 I/O 争用；以及如何把 CI 偶发超时修复收敛到"单个测试、单个平台、不增加任何重试与断言"的最小范围。

一、故障现场：唯一的失败是"超时"，不是"断言"

1.1 涉及对象

本次失败发生在 PR #6937 的 CI 中（Actions run32030280199，原始 Windows job95388592225），失败用例位于 packages/senpi-task/src/dag/e2e-happy.test.ts：

DAG happy-path end to end > #given eight mixed-route nodes across four waves #when the real engine runs #then routes, membership, events, and outputs stay intact

即"mixed-eight / four-wave happy path"——8 个混合路由节点、4 个严格 wave 的端到端全链路测试。它通过 e2eFixture 把真实的 DAG manager、scheduler、task manager、wait surface、SDK 与 crash-safe 持久化存储全部串起来运行。

1.2 权威 RED 数据

QA.md 中记录的 CI 原始输出（.omo/evidence/20260817-windows-dag-happy-timeout/QA.md）：

(fail) DAG happy-path end to end > #given eight mixed-route nodes across four waves #when the real engine runs #then routes, membership, events, and outputs stay intact [6454.00ms] ^ this test timed out after 5000ms. 15678 pass 73 skip 1 fail

三个关键事实：

没有产生任何断言失败——测试只是被 Bun 的运行器在5000ms处标记超时；
同进程的后续两个测试正常通过（耗时984ms与2031ms），说明进程本身没有挂死；
这是全量15678通过、73跳过中的唯一失败，属于典型的偶发 flake，而非确定性崩溃。

二、引擎完成机制：为什么"死锁假设"首先被驳斥

2.1 wait 面与调度器的完成契约

要判断是不是引擎缺陷，必须先弄清"测试何时能收到完成信号"。证据目录中的completion-seam.txt精确刻画了完成缝（completion seam）：

wait 面（packages/senpi-task/src/dag/handle.ts）：createDagWaitSurface的register会同时订阅两条通道——durable journal（subscribeDagJournal）与live scheduler 事件订阅（options.subscribe），随后重新读取 checkpoint以关闭"所有权读取 → 订阅建立"之间的竞态窗口：
```
addSubscription(runId, entry, subscribeDagJournal(store, runId, onJournalEvent)) addSubscription(runId, entry, options.subscribe(runId, onJournalEvent)) // The run may have gone terminal between the ownership read and the subscription. const now = store.readCheckpoint<DagRunRecordV1>(runId) if (now !== null && TERMINAL_RUN_STATUSES.has(now.status)) { settleWaiters(runId, projectResult(now, store, readOutput)) }
```
也就是说，即使订阅建立前运行已经完成，第二次 checkpoint 重读也能兜底触发settleWaiters，不存在"事件漏投递导致永久等待"的路径。
调度器（completion-seam.txt引用的runWaves）：dag.run.completed事件只会在所有 wave 都完成结算（settle）之后才追加——先逐 wavedag.wave.started → admitAndSettleWave → dag.wave.completed，全部结束后才dagRunCompletedEvent。

结论：完成事件只可能在"全部断言所依赖的节点输出都已落盘"之后发出。结合 CI 中"超时后同进程后续测试全部通过、且无断言失败"，真正的死锁或事件投递缺陷被驳斥。

2.2 本地"超时突变"实验：复现 CI 失败形状

证据档案用一次刻意实验印证了上述结论（red-timeout-mutation-bun-1.3.12.txt）：在本地 Bun1.3.12上，仅把 mixed-eight 测试的超时预算突变为1ms：

(fail) ... eight mixed-route nodes across four waves ... [68.72ms] ^ this test timed out after 1ms. (pass) ... completed run key ... [16.42ms] (pass) ... shipped SDK builder ... [35.74ms] 4 pass 1 fail 81 expect() calls

81 expect()调用数与 GREEN 运行完全一致——事件驱动运行与全部断言真实执行完毕，只是运行器先报了超时。这与 CI 的失败形状（6454ms处超时、无断言失败）逐项吻合：事件与断言都正确，只有运行器截止时间太小。

三、第二个假设：Windows 文件系统延迟但完成正确（已确认）

3.1 为什么这个 E2E 天生"重 IO"

本测试有意使用真实的 crash-safe 文件系统存储（createDagFileStore，packages/senpi-task/src/dag/store.ts），其 IO 特征包括：

事件日志appendEvent：fs.openSync(path, "a")+fs.writeSync+fs.fsyncSync（store.ts）；
checkpoint / key / result 写入走writeFileAtomic：临时文件wx独占创建 → 写入 → fsync →renameSync原子替换 → 目录 fsync（store.ts）；
锁的获取、回收、清理也全部是真实文件操作，且专门处理了 Windows 语义（目录 fsync 在 Windows 会EPERM被跳过，store.ts；硬链在 NTFS ACL / ReFS / 网络共享上可能被拒绝，回退到wx独占发布，store.ts；刚关闭的锁句柄可能短暂残留，需要WINDOWS_CLEANUP_RETRIES重试清理，store.ts）。

mixed-eight 是该 happy-path 文件中工作量最大的用例：8 个节点跨 4 个严格 wave，涉及 8 份子任务记录与结果、关联的 checkpoint 与事件日志。文件数多，Windows 上的同步写 + 原子重命名成本就被成倍放大。

3.2 历史分片运行的耗时漂移

同一测试在历史 Windows 全分片运行中的表现（完成机制与断言完全未变）：

Actions job	mixed-eight 耗时	结果
`95147917862`	`1672ms`	通过
`95191504899`	`3297ms`	通过
`95388592225`	`6454ms`	超时失败（>5000ms）

而同一测试在 Bun1.3.12、macOS 上隔离运行仅需82.57ms（baseline-focused-bun-1.3.12.txt）。近 4 倍的跨 run 波动，说明这是环境级延迟放大，而非逻辑缺陷。

四、第三个假设：全分片争用撞上单元测试默认值（已确认）

4.1 相邻 DAG 测试的同步膨胀

如果只是文件系统慢，相邻用例应该不受影响；但证据显示同一 Windows 分片上的相邻 DAG 测试同样被整体抬高：

linear/diamond从859/985ms膨胀到1671/2000ms；
mixed-eight 从1672ms膨胀到3297ms，再到失败 job 中的6454ms。

这种**相关性膨胀（correlated inflation）**指向全分片 Windows I/O 争用，而非确定性图算法缺陷或泄漏的 fixture。

4.2 为什么 5000ms 会被"默认"生效

关键背景是 Bun 测试运行器的默认超时语义。当前 e2e-happy.test.ts 文件头部的注释记录了这一点：

// bunfig preloads test-setup.ts to raise the default timeout, but Bun honours a preload's // setDefaultTimeout only for the FIRST test file of a run; every later file silently reverts to // the built-in 5000ms. Windows job 96304719047 in run 32328567654 measured the diamond case at // 5759ms against that 5000ms floor. Set the floor here, where Bun does honour it. setDefaultTimeout(process.platform === "win32" ? 60_000 : 20_000)

即：bunfig preload 中test-setup.ts设置的默认超时只对一次运行的第一个测试文件生效，后续文件静默回退到内置5000ms。全分片运行下，本文件大概率处于"后续文件"位置，因此在重负载分片上撞上了5000ms下限。

五、精确修复：平台限定、有界、零行为变更

5.1 原始修复提案

根因文档给出的修复是只给 mixed-eight 一个 Windows 专用的15_000ms预算，Linux/macOS 保留5_000ms：

}, process.platform === "win32" ? 15_000 : 5_000)

该方案的边界约束（也是验收标准）：

有界：15000ms是观测到的最坏耗时6454ms的 2 倍以上，留足余量但不至于掩盖真正的引擎退化；
作用域最小：只针对这个唯一的文件系统重负载 outlier（mixed-eight），其余用例预算不变；
零行为变更：不引入重试、sleep、轮询、跳过、断言修改，不触碰任何生产代码——纯测试运行器预算调整。

5.2 仓库中的最终落地形态

当前仓库实际采用的形态是文件级setDefaultTimeout（见上文 4.2 节第 29 行）：Windows60_000、其余平台20_000，并在头部注释中记录了比本文故障更晚的一次 Windows job（96304719047，run32328567654）把 diamond 用例也推到5759ms的实测。这可以理解为同一策略的演进：从"单个用例的 per-test 预算"演进为"该文件所有用例共享的、按平台区分的文件级下限"——两者都满足"平台区分 + 有界 + 不动断言/生产行为"的约束。

5.3 为什么不抽 helper？

对"是否应把超时参数抽取为辅助函数"的问题，证据档案给出了明确结论：修复替换的是现有结尾行而非新增行，文件纯 LOC 数保持344不变（见下节）；抽取 helper 只会增加审查面（review surface），却不会改变"单测试计时契约"的实质——因此不值得。

六、超大文件规则与 QA 验收

6.1 SIZE_OK 与 344 纯 LOC

e2e-happy.test.ts 首行标注：

// allow: SIZE_OK - one end-to-end fixture proves the assembled manager, scheduler, task manager, // wait surface, SDK, and durable store agree across all happy-path graph shapes.

这是超大文件豁免（SIZE_OK）的自我辩护：一个文件承载全部 happy-path 形状的端到端契约证明。no-excuse-audit.txt给出静态检查结果：

No violations in 1 file(s).

修复后文件仍为344纯 LOC（替换行而非新增行），不违反规则。

6.2 本地与 CI 验证矩阵

QA.md 记录了完整验证链条（全部基于 Bun1.3.12）：

检查项	命令 / 结果
Focused E2E（GREEN）	`npm exec --yes --package=bun@1.3.12 -- bun test packages/senpi-task/src/dag/e2e-happy.test.ts`，5 pass / 0 fail / 81 expect，mixed-eight`78.77ms`（post-rebase-focused-bun-1.3.12.txt）
受影响包全量	`bun test packages/senpi-task`：1612 pass / 1 skip / 0 fail，234 文件，23.20s
根类型检查	`bun run typecheck`（tsgo --noEmit + script + packages），exit code 0
根构建	`bun run build`，所有步骤完成
静态检查	纯 LOC 344、`git diff --check`clean、no-excuse audit 无违规

6.3 根分片本地验证的局限与"远程 QA 必过"纪律

QA.md 还诚实记录了本地验证的边界：--shard=2/2本地运行出现20个失败，但全部来自与 senpi-task 无关的 materialized-package / install-dist 检查（缺少生成的 Codex/Senpi payload 与子模块物化），与本次改动无关。

更重要的是最后的发布纪律：PR 不得在自身test (windows-latest, 2/2)检查通过前合并——"PR #6937 的重跑结果不构成该修复的证据"。这条约束把"修复是否真正解决目标分片问题"的判断权完全交给了修复 PR 自己的 Windows 全分片检查，避免了用历史数据自我安慰。

七、方法论沉淀：从这次 flake 中学到什么

本次排查的三段式路径可以抽象成一套可复用的 CI 偶发超时诊断流程：

区分"引擎失败"与"预算不足"：看是否产生断言失败、同进程后续用例是否通过；再用"超时突变"（把预算压到1ms）在本地复现失败形状，对比 expect 调用数是否与 GREEN 一致——一致即证明事件与断言链路完好，问题只在运行器截止时间；
用历史数据量化环境漂移：收集同一用例在不同 job / 平台上的耗时序列（1672 → 3297 → 6454ms），结合相邻用例的相关性膨胀（linear/diamond 同步翻倍），把"文件系统延迟"与"全分片争用"从"引擎 bug"中分离出来；
让修复范围与证据范围严格相等：只调整唯一 outlier 的平台专属预算，不引入重试/sleep/跳过/断言变更，用SIZE_OK与 LOC 约束守护文件边界，并以"修复 PR 自己的目标分片检查"作为唯一的合并门禁。

对 oh-my-openagent 这类同时承载"真实 crash-safe 文件存储 + 跨平台 CI 全分片并行"的仓库而言，这条纪律的意义在于：偶发超时应当被当作数据点去量化，而不是被当作缺陷去重写引擎——当15,678个用例全部通过、唯一失败的耗时仅是预算下限的 1.29 倍时，正确的工程动作是校准计时器，而不是动摇已验证的完成契约。