取证:daemon 异常终止根因链(内存 160→444→957MB 被杀 ⇒ 连带 cli exit:1 ⇒ 会话 terminated;guardian 因 wmic 缺失全程失守;Crash-Log 14 份跨 6 天证明是常态)+ 可反馈报告

This commit is contained in:
WorkBuddy committed 2026-10-09 06:34:13 +08:00
1 parent 12f62a2c88
commit bcd882b9b2
2 files changed
+154

No files matched your search

+47
View File
@@ -171,3 +171,50 @@
- 释放:`ME="执行会话-重新生成产品界面" bash …/session-mechanism/scripts/lock/handoff-guard.sh --release-exec` ⇒ 返回「✓ 已释放域锁(执行会话-重新生成产品界面)」+「另有 1 把锁属**他人**,按 R9 未动」。在册域锁 **2 条 → 1 条**。 - 释放:`ME="执行会话-重新生成产品界面" bash …/session-mechanism/scripts/lock/handoff-guard.sh --release-exec` ⇒ 返回「✓ 已释放域锁(执行会话-重新生成产品界面)」+「另有 1 把锁属**他人**,按 R9 未动」。在册域锁 **2 条 → 1 条**。
- 重派:新建排期 `[执行]-[产品规划]-重做界面补闸门与上报(第二棒)`(id `58855437`,once 2026-10-09 **06:32**),prompt 自包含:说明产物已在盘、只补闸门与上报、⛔ 不要重做界面、域门禁块、工具可从旧目标 `…-d85687/ui/_tools/` 只读借用、收工必跑 `--release-exec`。 - 重派:新建排期 `[执行]-[产品规划]-重做界面补闸门与上报(第二棒)`(id `58855437`,once 2026-10-09 **06:32**),prompt 自包含:说明产物已在盘、只补闸门与上报、⛔ 不要重做界面、域门禁块、工具可从旧目标 `…-d85687/ui/_tools/` 只读借用、收工必跑 `--release-exec`。
- ⛔ 未删他人锁;⛔ 未动 `ui/` 任何文件;⛔ 未改 `lifecycle`/`acceptance_state`。 - ⛔ 未删他人锁;⛔ 未动 `ui/` 任何文件;⛔ 未改 `lifecycle`/`acceptance_state`。
## 06:38 · 🔴 会话异常终止的**完整根因链**(用户令「重点解决为什么会话会异常终止」)
### 五环因果链(每环都有日志原文)
1、**daemon 内存暴涨** —— `daemon.log` 的 `[DaemonMemWatch]`:`16:50:33 pid=53940 heapUsed=160MB` → `16:51:33 heapUsed=444MB` → `16:52:33 heapUsed=**957MB** heapTotal=1030MB rss=**1162MB**`。**一分钟近三倍**,斜率外推下一分钟破 2GB。
2、**内存守护失守** —— `[guardian:sample] batch pidusage failed: Error: spawn wmic ENOENT`,**每 10 秒失败一次**(旧进程最后 46 行里 11 次)。guardian 靠 `pidusage` 采进程指标、底层调 `wmic`,而**本机没有 `wmic`**(Windows 11 已弃用/移除)⇒ 守护全程采不到数据,等于形同虚设 ⇒ 内存从 76MB 涨到 1GB+ 无人拦。
3、**进程被强杀(无优雅退出)** —— 旧 daemon 最后一条正常日志 `16:53:22`,下一条直接是 `16:53:38.273 [CodeCache] enabled {"processName":"daemon"}`(新进程)。**中间 16 秒零 shutdown/exit/error 日志**。
4、**父进程拉起新一代** —— `16:53:38.288 [DaemonLog] session started {"pid":73936,"ppid":72748,...}` ⇒ **73936=daemon,72748=其父进程(主进程)**。会话被判 terminated 的时刻 `00:53:39.584` 就卡在这两秒里。
5、**会话被连带** —— 新 daemon 的崩溃报告第一条:`00:53:54.262 ChildProcessCrash: Child process gone (cli): reason=exit:1, exitCode=1` ⇒ 旧 daemon 一死,它托管的 cli 子进程 exit 1,会话判 terminated,**来不及跑 `--release-exec`** ⇒ 孤儿锁。
### 🔴 这不是偶发 —— daemon 换代是常态
- 崩溃报告目录 **`E:/ProgramData/.workbuddy/logs/Crash-Log/`**,共 **14 份**;命名规则 `crash-report-<进程名>-<pid>-<启动时刻>.json`(时间戳=报告内 `launchedAt`,⛔ 不是崩溃时刻)。
- 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 份)。
- 每份报告里的条目**清一色**是 `Child process gone (cli): reason=exit:1`,且时间点全落在会话起止附近(53940 的 12 条里 `23:32:00` 那条正好是我派第一步执行棒 `ac88f8b0` 的排期时刻)。
- `.processed-crashes.json` 记的是**已处理条数**(53940=12、73936=4),⛔ 不是"崩溃次数"。
- ⇒ **每次 daemon 换代都会连带打断当时在跑的会话**;这次只是恰好赶上有会话在写 133KB 大文件,损失被放大成"目标卡一整夜"。
### 排掉的三个误判(连同上一轮)
- ⛔ **不是超时**:会话 `timeoutMs`=90 分钟,实际只活 331 秒。
- ⛔ **不是整个 App 重启**:`AppStartup.log` 在 00:4x–01:0x 无记录,换代只发生在 daemon 层。
- ⛔ **不是用户操作、不是批量事件**:同一时间窗全库只有该会话被 terminated,隔壁第 20 棒检查会话是正常 `completed`。
### ⚠️ 仍未坐实的一项
- **daemon 内存为什么会涨到 1GB**:日志只看到 `Conversation event push summary {"received":1652542→1671269}`(累计事件百万级),**但这不足以断定就是事件积压所致**。要定这个因,需另做一次带堆快照的复现。⛔ 不编因果。
### 可操作的两个点
1、**guardian 的 `wmic` 依赖已断**(Windows 11 移除 wmic)—— 这是本次事故里**唯一明确、可修、且与现象直接相关**的缺陷,但属 WorkBuddy 产品本身(我方改不了,只能上报)。
2、**daemon 换代 ⇒ 孤儿域锁** 这条链路可以在本方兜底:加一条「换代后检查孤儿域锁」的自检。
### 本轮动作
- ⛔ 只读取证,**未动任何文件、未改任何配置**(`daemon.log`/`Crash-Log/`/宿主库均为只读访问)。
## 06:30 · 结果检查第 32 棒 —— 锁已释放,本轮零派活
- 本棒(自动化 `c9779455`,第 32 棒)现取五样:`state.py` 仍不存在、`taskgraph.json` 仍不存在、台账 16 条(15 done + 1 blocked)、`lifecycle`=进行中、`acceptance` 3 过 + 1 不过。
- 🔴 **判定翻转(对比 22~31 棒)**:孤儿域锁 **已释放** —— `--domain-check "执行会话"` ⇒ **✅ 可派|域空闲**(此前十棒均报「已被持有」);在册域锁 2 条 → **1 条**(只剩 `ai1net-dsh-anywhere ← [协作]N9复测-2248`);锁目录 `…3786297056` 已消失。
- 🔴 **已有接手排期**:`58855437`《[执行]-[产品规划]-重做界面补闸门与上报(第二棒)》ACTIVE/once/**06:32**,cwds 逐字同形 ⇒ 那 1 条 `blocked`(`7446f482`)的阻碍已解除且有棒在队 ⇒ **本轮零派活**(再派=重复)。
- ⚠️ 登记一处不符:本棒 prompt 称「本项目没有别的待执行排期」,而现取显示 `58855437` 在册未到点 ⇒ **以现取为准**。
- 6 条「不可核实的 done」仍属已归档旧目标 `5199a6`:`research/` 只剩 `1b-竞品分析.md`,6 份正文在 `证据附卷/`(5 份)+ `归档-1b旧口径/`(1 份)⇒ **登记路径失效、非产物丢失**,不构成本目标缺口。
- 本棒只写 `执行会话/目标-…-071c5b/结果检查-第32棒-20261009.md`;⛔ 未动 `ui/`、⛔ 未删锁/接管、⛔ 未改目标状态、⛔ 未新增排期。
- 观测点:**06:32 后**看台账是否出现第 4 步 `done`(带可读 artifact)⇒ 若出现,本目标四步可收口。
+107
View File
@@ -0,0 +1,107 @@
# 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 记录,属被直接终止。
---
## 三、证据与复现命令
### 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)。
---
## 六、未坐实项(如实标注)
**daemon 内存为什么会涨到 1GB** —— 日志只显示 `Conversation event push summary {"received":1652542 → 1671269}`(累计事件百万级),但这**不足以断定是事件积压所致**。要定这个因,需另做一次带堆快照的复现。本报告不对此下结论。