diff --git a/.workbuddy/memory/2026-10-09.md b/.workbuddy/memory/2026-10-09.md index 34948de..5d50096 100644 --- a/.workbuddy/memory/2026-10-09.md +++ b/.workbuddy/memory/2026-10-09.md @@ -171,3 +171,50 @@ - 释放:`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`。 - ⛔ 未删他人锁;⛔ 未动 `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-<进程名>--<启动时刻>.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)⇒ 若出现,本目标四步可收口。 diff --git a/daemon-异常终止取证-20261009.md b/daemon-异常终止取证-20261009.md new file mode 100644 index 0000000..66b58c5 --- /dev/null +++ b/daemon-异常终止取证-20261009.md @@ -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" /daemon.log | tail -30 +``` + +### 2、守护失效(每 10 秒一次) + +``` +grep "guardian:sample" /daemon.log | tail -20 +``` + +原文:`[guardian:sample] batch pidusage failed: Error: spawn wmic ENOENT` +频次:旧进程最后 46 行日志里出现 **11 次**,即持续失败、无一成功。 + +### 3、进程换代与父子关系 + +``` +grep "DaemonLog] session started" /daemon.log +``` + +原文:`[DaemonLog] session started {"pid":73936,"ppid":72748,"nodeVersion":"v22.21.1","electron":...}` + +### 4、崩溃报告(换代是常态的直接证据) + +目录:`/Crash-Log/` +命名规则:`crash-report-<进程名>--.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}`(累计事件百万级),但这**不足以断定是事件积压所致**。要定这个因,需另做一次带堆快照的复现。本报告不对此下结论。