7.4 KiB
WorkBuddy daemon 异常终止导致会话中断 · 取证报告
取证时间:2026-10-09 06:2x–06:4x(本地 UTC+8) 环境:win32 x64 / WorkBuddy 5.7.6 / Electron 37.10.3 / Node 22.21.1 / V8 13.8.258.32-electron.0 现象:后台自动化会话运行中途被判
terminated,未正常收尾,并遗留域锁未被释放 本报告全部结论取自日志与崩溃报告原文,可复现;未坐实的推断已单独标注
一、结论(三句)
1、daemon 进程内存在一分钟内涨近三倍(160MB → 444MB → 957MB,rss 1162MB)后被强制终止,日志里没有任何优雅退出或崩溃堆栈。
2、父进程随即拉起新一代 daemon(ppid 可证);旧 daemon 托管的 cli 子进程随之以退出码 1 结束,正在其上运行的会话被判 terminated。
3、本应拦截这一关的内存守护(guardian)全程失效 —— 它靠 wmic 采集进程指标,而本机 wmic 不存在,每 10 秒失败一次。
二、时间线(本地时间,取自 daemon.log 原文)
- 16:50:33(=本地次日 00:50:33)——
[DaemonMemWatch] pid=53940 heapUsed=160MB heapTotal=202MB rss=340MB。 - 16:51:33 ——
pid=53940 heapUsed=444MB heapTotal=509MB rss=618MB。 - 16:52:33 ——
pid=53940 heapUsed=957MB heapTotal=1030MB rss=1162MB。三分钟三倍,斜率外推下一分钟破 2GB。 - 16:53:22 —— 旧 daemon 最后一条正常业务日志(
[skills-fetch] response)。 - 16:53:38.273 —— 新进程首个标记:
[CodeCache] enabled {"processName":"daemon"}。 - 16:53:38.288 ——
[DaemonLog] session started {"pid":73936,"ppid":72748,...}。 - 16:53:39.584 —— 会话
a257d30f被状态同步器置为terminated。 - 16:53:54.262 —— 新 daemon 记下第一条:
ChildProcessCrash: Child process gone (cli): reason=exit:1, exitCode=1。
关键间距:16:53:22 到 16:53:38 之间有 16 秒空白 —— 旧进程没有留下任何 shutdown/exit/error 记录,属被直接终止。
二之二、内存暴涨的形态(关键:两轮暴涨,一轮被救回、一轮没赶上)
[DaemonMemWatch] 每分钟一读,逐条摘录:
- 第一轮:
16:20 heap=309MB→16:21 526MB→16:22 551MB→16:23 592MB→16:24 **609MB**(峰)→16:25 掉回 132MB。 - 平稳期:
16:26–16:41稳定在 132–135MB,17 分钟几乎不动。 - 第二轮:
16:42 149MB→16:44 185MB→16:48 143MB→16:50 160MB→16:51 **444MB**→16:52 **957MB**→16:53:38被杀。
要点一:不是缓慢泄漏。 16:25 从 609MB 掉回 132MB,说明 V8 能回收 —— 它是突发分配,只是第二次没来得及回收进程就被终止了。
要点二:与「会话活跃」严格同步。 事件计数(Conversation event push summary 的 received)在 16:45/16:46/16:47 三条完全相同(1622136),即该时段零事件,同期内存 175–185MB 平稳;16:48 起事件转为递增(+1117 → +3323 → +9097 → +16869 → +18727 每分钟),内存同步起飞。16:48:08 正是一个后台会话的启动时刻。
要点三:不是队列积压。 pendingEvents: 0、maxPendingEvents: 112 全程不变,事件并没有堆在推送队列里。
换算比例:16:51 段约 31KB/事件、16:52 段约 27KB/事件 —— 两段一致,但这是相关关系,不是已证因果(见第六节)。
三、证据与复现命令
1、内存暴涨
grep "DaemonMemWatch" <logs>/daemon.log | tail -30
2、守护失效(每 10 秒一次)
grep "guardian:sample" <logs>/daemon.log | tail -20
原文:[guardian:sample] batch pidusage failed: Error: spawn wmic ENOENT
频次:旧进程最后 46 行日志里出现 11 次,即持续失败、无一成功。
3、进程换代与父子关系
grep "DaemonLog] session started" <logs>/daemon.log
原文:[DaemonLog] session started {"pid":73936,"ppid":72748,"nodeVersion":"v22.21.1","electron":...}
4、崩溃报告(换代是常态的直接证据)
目录:<logs>/Crash-Log/
命名规则:crash-report-<进程名>-<pid>-<launchedAt 本地时刻>.json
(时间戳取报告内 launchedAt 字段,不是崩溃时刻)
现有 14 份,daemon 的跨 09-28 / 10-01×2 / 10-02×2 / 10-06×2 / 10-08 / 10-09 —— 至少 6 个日子发生过换代。另有 crash-report-main-* 5 份、crash-report-sidecar-* 1 份。
每份报告体例一致(示例为 10-09 那次),条目形如:
{
"timestamp": "2026-10-09T00:53:54.262+08:00",
"type": "child_process_crash",
"errorMessage": "Child process gone (cli): reason=exit:1, exitCode=1",
"childProcess": { "name": "cli", "exitCode": 1, "disposition": "unexpected_crash" }
}
.processed-crashes.json 里的数字是已处理条数(53940=12、73936=4),不是崩溃次数。
5、连带关系
53940 名下 12 条崩溃条目,时间点全部落在会话起止附近(其中 23:32:00 那条,正好等于一次执行会话排期的触发时刻)。
四、影响面
- 任何正在跑的会话都可能被换代打断,形态是"跑着跑着变 terminated",且来不及做收尾动作。
- 本次实际损失:一个四步目标的第 4 步执行会话在做完界面产物后 1 秒被终止,产物虽已落盘,但验证与上报全部丢失;更严重的是它持有的域锁无人释放,形成孤儿锁,导致后续 10 棒检查会话连续空转(01:29–05:59)。
- 崩溃报告中
cli exit:1是结果不是原因 —— 它是随 daemon 一起被带走的,排查时不要被这一行带偏。
五、建议
1、修 guardian 的采样方式 —— 把 wmic 依赖换掉(Windows 11 已弃用/移除 wmic,改用 PowerShell CIM 或 Node 原生接口)。这是本次事件中唯一明确、可修、且与现象直接相关的缺陷。
2、daemon 被杀前留痕 —— 现在从"最后一条业务日志"到"新进程启动"之间是 16 秒真空,外部无法判断是 OOM、被父进程杀、还是 native crash,建议补一条落盘的退出原因。
3、daemon 内存上限与自愈 —— 内存从 76MB 涨到 1GB+ 无任何预警;建议在阈值处先落日志、再重启,并且重启前给在跑的会话留收尾窗口(或至少在重启后主动标记受影响的会话,而不是让它们静默停在 terminated)。
六、未坐实项(如实标注)
「到底是谁占了那些内存」我没有坐实。
- 会话自己的 SDK 日志(
logs/<日期>/sdk/conversations/<sessionId>.log)只有 499 行、约 199 条事件(覆盖该会话全部 331 秒),解释不了 4.9 万条的received增量 ⇒ 说明存在一条不进会话 SDK 日志的事件通道,我没能定位它的落点。 - 因此第二节末尾那个「27–31KB/事件」只能算相关,不能算因果 —— 内存里完全可能有其它占用与事件速率同步起伏。
- 要定这个因,唯一可靠的办法是复现 + 抓 V8 堆快照(heap snapshot),看增长集中在哪个对象类型。本报告不对此下结论。
- 另注:
toolThrottleFramesByTool里Bash32206 /Write30346 /Edit13162 是个有界指标(反映被节流的工具帧数),不要把它当内存占用读。