Commit d8b4346d1b9a693b6325855e89eeb3aa871157cd

Authored by yibo
1 parent 60095724

docs: 常驻 CLI 子进程泄漏排查手册 —— 记下「有两个会话池」这件没人写过的事

泄漏被修过一次(310a2b2 / 3e718aa),修完照样漏。第二次排查发现原因不是修错了,而是:

    系统里有两个互相独立的会话池,上一次只修了其中一个;而被修的那个,还漏了一条分支。

    池 A  routes/agent-chat.js 的 sessions       ← /api/agent/:id/chat,含两路心跳
    池 B  src/core/session-pool.js 的 SessionPool ← AgentManager.callAgent,图执行 / DevLoop

两者没有任何共享代码,回收逻辑各写各的。这个结构性事实此前没有任何一处记着,
所以第二个人查到同一个症状时会重走一遍全程 —— 这份文档就是为了让第三个人不必再走。

正文八节,除了两个洞各自的成因与修法(b0b2b62 / 2092a2e),有三处是排查方法而非结论:

§三 按 cwd 第三层判断孤儿归属的对照表。两个池子都把 cwd 下沉到运行态目录,
     `_global` / `_no-task` 是 agent-locator 的保留缺省值、两边都会出现,不能靠它区分。

§四 为什么上一版守卫是瞎的。dropSession 和 closeSession 都会让会话从池子里消失,
     黑盒探针两种情况都返回 false —— 差别只在子进程死没死,而那是探针看不见的维度。
     选探针要问的不是「能不能测出正确行为」,而是「能不能区分正确行为和这个具体的错误行为」。

§八 三步定位脚本,外加一条:先确认跑着的服务器进程是什么时候启动的,再去看代码。
     本次排查中,正在跑的实例比修复 commit 早 18 秒启动,代码里有的修复它并没有。

线上验证(PID 63099,13 分钟窗口两轮心跳):触发 5 / 完成 5 / 回收 5,峰值子进程 3、稳态 0。
17:13:32 那个 3 正是泄漏时代的签名(cto+coo+qa-judge 同秒触发),清理前那批孤儿一个都不回收,
现在 30 秒内全部释放。窗口内没有失败心跳,所以 2092a2e 那条 catch 路径是靠单测的变异检验
保证的、不是靠线上观察 —— 文档 §六 里写明了,没算成已验证。

docs/README.md 同步加索引条目(no-dead-path-references 守卫 4 条全绿)。

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
docs/README.md
... ... @@ -17,6 +17,7 @@
17 17 | [LEMONBOSS-SYSTEM-DESIGN.md](./done/LEMONBOSS-SYSTEM-DESIGN.md) | 系统设计主索引 v2.0,含 27 章 `system-design/` 的总目录 |
18 18 | [architecture-v5.md](./done/architecture-v5.md) | v5.3 架构方案,Phase 1-6 已完成(Phase 7 认知架构条目单独见 todo/) |
19 19 | [claude-code-cron.md](./done/claude-code-cron.md) | Claude Code 原生 Cron 调度功能参考手册 |
  20 +| [claude-cli-session-leak.md](./done/claude-cli-session-leak.md) | **常驻 CLI 子进程泄漏排查手册** — ✅ 已修复(`b0b2b62` + `2092a2e`):系统里有**两个互不相干的会话池**(`routes/agent-chat.js` 的 `sessions` / `src/core/session-pool.js`),各漏各的。含按 cwd 判断孤儿归属的方法、变异检验为什么必要、三步定位脚本 |
20 21 | [open-api-manual.md](./done/open-api-manual.md) | ArenaSK Open API 外部调用手册 |
21 22 | [qa_judge_req.md](./done/qa_judge_req.md) | QA Judge Agent 需求文档 — 已在 `system/agents/qa-judge/` 落地 |
22 23 | [task_timeline_design.md](./done/task_timeline_design.md) | Task Timeline View 设计文档 — 已实现(`server/routes/tasks.js`、`server/services/task-service.js`、`web/src/views/TaskTimeline.vue`) |
... ...
docs/done/claude-cli-session-leak.md 0 → 100644
  1 +# Claude CLI 子进程泄漏 —— 两个会话池,两个洞
  2 +
  3 +**状态**:✅ 已修复(`b0b2b62` + `2092a2e`,2026-08-19)
  4 +**适用范围**:任何往会话池里塞常驻 CLI 子进程的代码路径
  5 +
  6 +---
  7 +
  8 +## 一、这份文档要解决的问题
  9 +
  10 +泄漏被修过一次(`310a2b2` / `3e718aa`,2026-08-18),修完之后**照样漏**。
  11 +第二次排查发现原因不是修错了,而是:
  12 +
  13 +> **系统里有两个互相独立的会话池,上一次只修了其中一个;而被修的那个,还漏了一条分支。**
  14 +
  15 +这个结构性事实没有任何一处文档记着,所以第二个人查到同一个症状时会重走一遍全程。
  16 +
  17 +---
  18 +
  19 +## 二、症状:它是静默的
  20 +
  21 +一个连续跑了 23 小时的 `server/index.js` 实例(PID 40255,8-18 17:29 启动):
  22 +
  23 +| | |
  24 +|---|---|
  25 +| 遗留 claude CLI 子进程 | **45 个** |
  26 +| 这些子进程占用 RSS | **9.6 GB** |
  27 +| 全机 claude 进程总 RSS | 12.3 GB → 清理后 2.3 GB |
  28 +| CPU | 全部 0%(早已跑完,只是不死) |
  29 +
  30 +**不报错、不写日志、`git status` 干净、接口全部正常**。唯一的外部表现是内存一路涨,
  31 +以及跑全量测试时被这些进程写出来的运行态目录打出偶发假失败。
  32 +
  33 +> 上一次的记录是「2h43m 攒到 82 个进程 / 17.5 GB」。量级对得上,说明这是同一类问题的复发,
  34 +> 不是新 bug。
  35 +
  36 +---
  37 +
  38 +## 三、先分清楚:两个会话池
  39 +
  40 +这是排查这类问题的**第一步**,也是上次修复漏掉一半的根本原因。
  41 +
  42 +| | 池 A | 池 B |
  43 +|---|---|---|
  44 +| 位置 | `server/routes/agent-chat.js` 的 `sessions` Map | `server/src/core/session-pool.js` 的 `SessionPool` |
  45 +| 谁在用 | `/api/agent/:id/chat`(含两路心跳) | `AgentManager.callAgent` → 图执行 / DevLoop |
  46 +| 会话 key | `${agentId}:${convId}` | `getKey()`:agent + client + deploy + **companyId/taskId** + workDir |
  47 +| 本次泄漏占比 | 38 个 | 7 个 |
  48 +
  49 +两个池子**没有任何共享代码**,回收逻辑各写各的。上一次的修复只动了池 A。
  50 +
  51 +### 怎么判断一个孤儿进程属于哪个池
  52 +
  53 +看它的 cwd —— 两个池子都把 cwd 下沉到运行态目录,但第三层不一样:
  54 +
  55 +```bash
  56 +lsof -p <pid> -a -d cwd | tail -1 | awk '{print $NF}'
  57 +```
  58 +
  59 +| cwd 形态 | 归属 |
  60 +|---|---|
  61 +| `system/agents/cto/_global/heartbeat-msywwyhf` | 池 A(`convId` 是 `heartbeat-` + `Date.now().toString(36)`) |
  62 +| `system/agents/brd-planning/e2e-demo/run_ee90c4e35f9f` | 池 B(第三层是图执行的 runId) |
  63 +
  64 +> 注意 `_global` / `_no-task` 是 `agent-locator` 的保留缺省值,两个池子都会用到,
  65 +> **不能靠它区分**。区分点是第三层的命名形态。
  66 +
  67 +一次性把全部孤儿归类:
  68 +
  69 +```bash
  70 +for p in $(pgrep -P <server-pid>); do
  71 + echo "$p $(ps -o lstart= -p $p | awk '{print $3,$4}') \
  72 + $(lsof -p $p -a -d cwd 2>/dev/null | tail -1 | awk '{print $NF}')"
  73 +done | sed 's|.*/system/agents/||'
  74 +```
  75 +
  76 +---
  77 +
  78 +## 四、池 A 的洞:catch 分支只摘不杀
  79 +
  80 +### 代码
  81 +
  82 +```js
  83 +} catch (err) {
  84 + ...
  85 + dropSession(`${agentId}:${convId}`); // ← 只摘出池子,不杀子进程
  86 +} finally {
  87 + const sessionKey = `${agentId}:${convId}`;
  88 + if (kind?.[2]) closeSession(sessionKey, ...); // ← 池子里已经没了,返回 false,空转
  89 + else armSessionIdle(sessionKey);
  90 +}
  91 +```
  92 +
  93 +`dropSession` 的注释写着「子进程已经自己死了的场景」。但这条 catch 覆盖的是**另一种**失败:
  94 +错的是 API 调用,CLI 子进程好端端地活着。于是会话先被摘出池子,`finally` 再也查不到它
  95 +—— 一个**既没有引用、也没有回收路径**的孤儿。
  96 +
  97 +### 证据
  98 +
  99 +抽查泄漏的 convId,`status` **无一例外**是 `failed`:
  100 +
  101 +```
  102 +heartbeat-mszk16qj -> failed | UNKNOWN_CERTIFICATE_VERIFICATION_ERROR
  103 +heartbeat-msznzjlx -> failed | Can't reach the API server (ENOTFOUND)
  104 +heartbeat-msywwyhf -> failed | API Error: 529 Overloaded
  105 +```
  106 +
  107 +对照 `cto` 最近 60 次心跳:**55 completed / 5 failed**。8% 的失败率、一次漏一个,
  108 +23 小时漏 38 个——数字对得上。**成功的心跳一个都没漏**,说明 `310a2b2` 本身是对的。
  109 +
  110 +### 修法(`2092a2e`)
  111 +
  112 +`dropSession` → `closeSession`。可观测行为完全不变(两者都把会话摘出池子、都让下一轮冷启动),
  113 +只是多杀一个本该死的进程。
  114 +
  115 +### 为什么上一版守卫拦不住 —— 这条最值得记
  116 +
  117 +`agent-chat-session-reclaim.test.js` 用 `/chat/:convId/stop` 当黑盒探针(查得到会话才返回
  118 +`success:true`)。这个探针**对本 bug 是瞎的**:
  119 +
  120 +> `dropSession` 和 `closeSession` 都会让会话从池子里消失,探针两种情况都返回 false。
  121 +> 两者的差别**只在子进程死没死**,而那是探针看不见的维度。
  122 +
  123 +所以新增用例破例 spy 了 `ClaudeCliProtocol.prototype.disconnect` —— 它是「进程被杀」唯一可观测的落点。
  124 +用 `vi.spyOn` 让 `sendPrompt` reject 来复现「CLI 活着、API 挂了」。
  125 +
  126 +**教训**:黑盒探针的覆盖面等于它能观测的维度。选探针时要问的不是「它能不能测出正确行为」,
  127 +而是「**它能不能区分正确行为和这个具体的错误行为**」。
  128 +
  129 +---
  130 +
  131 +## 五、池 B 的洞:压根没有回收路径
  132 +
  133 +### 代码
  134 +
  135 +`SessionPool` 修改前只有三条 disconnect 路径:
  136 +
  137 +1. `getOrCreate` 发现旧会话已断开 → 换新的
  138 +2. `reset(key)` 显式重置
  139 +3. `killActive()` 手动终止
  140 +
  141 +**「正常跑完」和「不可重试的报错」都不在其中。** 而 `getKey()` 里带了 `taskId`:
  142 +
  143 +```js
  144 +const runtime = `${agentConfig.companyId || '_global'}/${agentConfig.taskId || '_no-task'}`;
  145 +```
  146 +
  147 +每个图节点一个新 taskId = 一个新 key = 一个新 CLI 进程,跑完之后**再没人查得到那个会话**
  148 +(下一个节点用的是别的 key),也就再没人杀得掉它。一节点一进程,永不释放。
  149 +
  150 +> `taskId` 进 key 是必须的(28 §6 批次 3-12:两家公司调同一个本体,key 相同会串上下文)。
  151 +> 问题不在 key 的设计,在于加了这一维之后没有配套的回收。
  152 +
  153 +### 修法(`b0b2b62`)
  154 +
  155 +按池 A 已经定下的口径补空闲 TTL,复用 `src/engine/idle-timer` 和同一个旋钮
  156 +`AGENT_SESSION_IDLE_MS`(默认 30 分钟):
  157 +
  158 +- `session-pool.js` 新增 `armIdle(key)`;`getOrCreate` 命中复用时停表;`reset` / `killActive` 取消计时器
  159 +- `agent-manager.js` 的 `_runViaProtocol` 在**两个出口**各上一次弦:正常跑完、放弃重试
  160 +
  161 +计时器只在「没有在途请求」的间隙走,所以再长的单次生成也不会被 TTL 打断。
  162 +
  163 +`idleMs()` 故意做成每次读 env 而不是模块加载时读一次 —— 否则单测只能干等 30 分钟。
  164 +
  165 +### ponytail: 已知天花板
  166 +
  167 +TTL 是**兜底**不是精算。一次性 taskId(图节点跑完就不会再用)也要白占一个 TTL 周期的内存,
  168 +天花板是「并发会话数 × 单进程 RSS(实测约 300MB)× TTL」。
  169 +
  170 +升级路径:调用方在明知 taskId 一次性时直接 `reset(key)` 立刻释放。这里**不替它判断** ——
  171 +DevLoop 的 retry-with-reflection 复用同一个 taskId,一刀切关掉会砍掉复用能力。
  172 +
  173 +---
  174 +
  175 +## 六、验证
  176 +
  177 +线上观察(PID 63099,17:03 启动,心跳 `coo`/`cto` 各 5 分钟、`qa-judge` 10 分钟):
  178 +
  179 +```
  180 +17:08:01 子进程=0
  181 +17:08:31 子进程=2 ← cto + coo 心跳同时触发
  182 +17:09:01 子进程=0 ← 跑完即回收
  183 +```
  184 +
  185 +守卫测试:
  186 +
  187 +| 文件 | 用例 |
  188 +|---|---|
  189 +| `server/tests/unit/agent-chat-session-reclaim.test.js` | 13 条(本次 +1:跑挂的心跳同样要杀子进程) |
  190 +| `server/tests/unit/session-pool-idle-reclaim.test.js` | 3 条(新增,不起真 CLI) |
  191 +
  192 +**四条断言都做过变异检验**(把修复逐条改回去,确认对应用例转红)。其中一条第一版是假绿的:
  193 +「reset 后不再杀一次子进程」—— 会话那时已经不在池子里,超时回调本来就空转,
  194 +那条断言什么都没测。改成看 `IdleTimer.fired`(它答的是「这只表还在不在走」)之后才真的会红。
  195 +
  196 +---
  197 +
  198 +## 七、仍未解决的(不在本次范围)
  199 +
  200 +1. **心跳持续往 `system/agents/` 写运行态目录**。`locator.taskDir()` 的落点设计就是
  201 + `system/agents/<agent>/<companyId>/<taskId>`,属既定设计,不是 bug;但心跳每 5 分钟建一个新目录
  202 + (`cto/_global/` 已 260+ 子项且在涨),扫描 `system/agents/` 的守卫测试会被瞬时竞态打红。
  203 + 要跑干净的全量测试,得让测试隔离掉 `system/agents/`,或跑之前先停心跳。
  204 +2. **机器级闸门不存在**。`SessionPool` 没有 `maxSessions`,全靠 TTL 兜底。登记在 `28-followups`。
  205 +
  206 +---
  207 +
  208 +## 八、下次再遇到,三步定位
  209 +
  210 +```bash
  211 +# 1. 谁的孩子,多少个,占多少
  212 +SRV=$(lsof -nP -iTCP:3010 -sTCP:LISTEN -t | head -1)
  213 +pgrep -P $SRV | wc -l
  214 +ps -eo ppid,rss | awk -v s=$SRV '$1==s {n+=1; m+=$2} END {print n"个", m/1024"MB"}'
  215 +
  216 +# 2. 按 cwd 归类,判断是哪个池(对照第三节的表)
  217 +for p in $(pgrep -P $SRV); do lsof -p $p -a -d cwd 2>/dev/null | tail -1 | awk '{print $NF}'; done \
  218 + | sed 's|.*/system/agents/||' | sort | uniq -c
  219 +
  220 +# 3. 对池 A 的泄漏,查对应会话的 status —— 全是 failed 就是错误路径没回收
  221 +cat system/agents/<agent>/_global/conversations/<convId>/meta.json
  222 +```
  223 +
  224 +**一条经验**:先确认跑着的服务器进程**是什么时候启动的**,再去看代码。
  225 +本次排查中,正在跑的实例比修复 commit 早 18 秒启动,代码里有的修复它并没有。
  226 +
  227 +```bash
  228 +ps -o lstart= -p $SRV # 服务器启动时间
  229 +git log --format='%h %ad %s' --date=format:'%m-%d %H:%M' -5 -- <相关文件>
  230 +```
... ...