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.tsDAG 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 seamwait 面packages/senpi-task/src/dag/handle.tscreateDagWaitSurface的register会同时订阅两条通道——durable journalsubscribeDagJournal与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.readCheckpointDagRunRecordV1(runId) if (now ! null TERMINAL_RUN_STATUSES.has(now.status)) { settleWaiters(runId, projectResult(now, store, readOutput)) }也就是说即使订阅建立前运行已经完成第二次 checkpoint 重读也能兜底触发settleWaiters不存在事件漏投递导致永久等待的路径。调度器completion-seam.txt引用的runWavesdag.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() calls81 expect()调用数与 GREEN 运行完全一致——事件驱动运行与全部断言真实执行完毕只是运行器先报了超时。这与 CI 的失败形状6454ms处超时、无断言失败逐项吻合事件与断言都正确只有运行器截止时间太小。三、第二个假设Windows 文件系统延迟但完成正确已确认3.1 为什么这个 E2E 天生重 IO本测试有意使用真实的 crash-safe 文件系统存储createDagFileStorepackages/senpi-task/src/dag/store.ts其 IO 特征包括事件日志appendEventfs.openSync(path, a)fs.writeSyncfs.fsyncSyncstore.tscheckpoint / key / result 写入走writeFileAtomic临时文件wx独占创建 → 写入 → fsync →renameSync原子替换 → 目录 fsyncstore.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 jobmixed-eight 耗时结果951479178621672ms通过951915048993297ms通过953885922256454ms超时失败5000ms而同一测试在 Bun1.3.12、macOS 上隔离运行仅需82.57msbaseline-focused-bun-1.3.12.txt。近 4 倍的跨 run 波动说明这是环境级延迟放大而非逻辑缺陷。四、第三个假设全分片争用撞上单元测试默认值已确认4.1 相邻 DAG 测试的同步膨胀如果只是文件系统慢相邻用例应该不受影响但证据显示同一 Windows 分片上的相邻 DAG 测试同样被整体抬高linear/diamond从859/985ms膨胀到1671/2000msmixed-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 preloads // 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 倍以上留足余量但不至于掩盖真正的引擎退化作用域最小只针对这个唯一的文件系统重负载 outliermixed-eight其余用例预算不变零行为变更不引入重试、sleep、轮询、跳过、断言修改不触碰任何生产代码——纯测试运行器预算调整。5.2 仓库中的最终落地形态当前仓库实际采用的形态是文件级setDefaultTimeout见上文 4.2 节第 29 行Windows60_000、其余平台20_000并在头部注释中记录了比本文故障更晚的一次 Windows job96304719047run32328567654把 diamond 用例也推到5759ms的实测。这可以理解为同一策略的演进从单个用例的 per-test 预算演进为该文件所有用例共享的、按平台区分的文件级下限——两者都满足平台区分 有界 不动断言/生产行为的约束。5.3 为什么不抽 helper对是否应把超时参数抽取为辅助函数的问题证据档案给出了明确结论修复替换的是现有结尾行而非新增行文件纯 LOC 数保持344不变见下节抽取 helper 只会增加审查面review surface却不会改变单测试计时契约的实质——因此不值得。六、超大文件规则与 QA 验收6.1 SIZE_OK 与 344 纯 LOCe2e-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 E2EGREENnpm exec --yes --packagebun1.3.12 -- bun test packages/senpi-task/src/dag/e2e-happy.test.ts5 pass / 0 fail / 81 expectmixed-eight78.77mspost-rebase-focused-bun-1.3.12.txt受影响包全量bun test packages/senpi-task1612 pass / 1 skip / 0 fail234 文件23.20s根类型检查bun run typechecktsgo --noEmit script packagesexit code 0根构建bun run build所有步骤完成静态检查纯 LOC 344、git diff --checkclean、no-excuse audit 无违规6.3 根分片本地验证的局限与远程 QA 必过纪律QA.md 还诚实记录了本地验证的边界--shard2/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 倍时正确的工程动作是校准计时器而不是动摇已验证的完成契约。相关证据与源码索引根因与范围文档.omo/evidence/20260817-windows-dag-happy-timeout/root-cause-and-scope.mdQA 验证矩阵.omo/evidence/20260817-windows-dag-happy-timeout/QA.md完成缝刻画.omo/evidence/20260817-windows-dag-happy-timeout/completion-seam.txt超时突变 RED 日志red-timeout-mutation-bun-1.3.12.txtmacOS 基线 / rebase 后 GREEN 日志baseline-focused-bun-1.3.12.txt、post-rebase-focused-bun-1.3.12.txt被测 E2Epackages/senpi-task/src/dag/e2e-happy.test.tswait 面实现packages/senpi-task/src/dag/handle.ts文件存储实现packages/senpi-task/src/dag/store.ts【免费下载链接】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创作声明：本文部分内容由AI辅助生成（AIGC），仅供参考