A 方案落地:观察式复现单 + 采样器(第一组对照已拿到,且修正上一轮假设——事件速率不是充分因,嫌疑收窄到大文件写入)

This commit is contained in:
WorkBuddy committed 2026-10-09 06:39:21 +08:00
1 parent 0a5af434eb
commit add273fc22
4 files changed
+167

No files matched your search

+8
View File
@@ -241,6 +241,14 @@
**内存暴涨的模式是:会话活跃期(尤其大文件读写)触发事件洪峰,daemon 内存随事件速率同步倍增;而 V8 能否回收是随机的 —— 16:25 收回了、16:53 没来得及就被杀。** 所以问题不在「内存高」,在 **「一个会话周期就能把 daemon 推高 6 倍(160→957MB),且回收时机不可控」**。 **内存暴涨的模式是:会话活跃期(尤其大文件读写)触发事件洪峰,daemon 内存随事件速率同步倍增;而 V8 能否回收是随机的 —— 16:25 收回了、16:53 没来得及就被杀。** 所以问题不在「内存高」,在 **「一个会话周期就能把 daemon 推高 6 倍(160→957MB),且回收时机不可控」**。
## 06:42 · A 方案落地:观察式复现 + 意外拿到第一组对照(**修正了上一轮的假设**)
- **观察窗口正好开着**:我派的那棒(会话 `cc07347c`=`[执行]-[产品规划]-重做界面补闸门与上报(第二棒)`)**06:32:15 起跑、已抢到域锁** ⇒ 侧面证明 06:2x 的释放动作生效(释放后在册只剩 1 条他人锁,它成功 claim)。
- 🔴 **意外收获(第一组对照)**:这棒的**事件速率与暴涨组同量级**(`received` 每分钟 `+20758`/`+11422`),而内存只在 **116–202MB 之间锯齿**(GC 持续回收,rss 356–460MB)⇒ **事件速率不是内存暴涨的充分因** —— 上一轮那个「27–31KB/事件」的读数被这组对照**降级为伴随现象**。
- 两组唯一明显差别:暴涨组当时**一次写入 133KB 大文件**(`ui/mcn-workbench.html`)并连着出 5 条 `[ResourceReport] artifact observed`。⇒ **嫌疑收窄到「大文件写入/artifact 处理」这一侧**。
- 产出:`daemon-内存观察-复现单.md`(三样必采项 + 现成命令 + 判据 + 第一组记录);采样器 `mem_watch.py` 落**工作区根**(⛔ 不放 `tmp/`,那里会被清理),已起后台采样(5 分钟/20 秒一条 → `tmp/mem-watch-20261009.csv`)。
- ⛔ 未调 daemon 启动参数、未重启 daemon、未打断任何会话(候选 B 的代价已否掉)。
## 06:30 · 结果检查第 32 棒 —— 锁已释放,本轮零派活 ## 06:30 · 结果检查第 32 棒 —— 锁已释放,本轮零派活
- 本棒(自动化 `c9779455`,第 32 棒)现取五样:`state.py` 仍不存在、`taskgraph.json` 仍不存在、台账 16 条(15 done + 1 blocked)、`lifecycle`=进行中、`acceptance` 3 过 + 1 不过。 - 本棒(自动化 `c9779455`,第 32 棒)现取五样:`state.py` 仍不存在、`taskgraph.json` 仍不存在、台账 16 条(15 done + 1 blocked)、`lifecycle`=进行中、`acceptance` 3 过 + 1 不过。
+92
View File
@@ -0,0 +1,92 @@
# daemon 内存观察 · 复现单(A 方案)
> 用途:坐实「会话活跃 ⇒ 事件洪峰 ⇒ daemon 内存暴涨」这条链是否成立。
> 起因:2026-10-09 一次后台会话被终止,根因链为「daemon 内存 957MB 被杀 ⇒ 连带 cli exit:1 ⇒ 会话 terminated」。
> 完整背景见同目录 `daemon-异常终止取证-20261009.md`。
> 触发时机:**下次派「大文件产出」类执行会话时顺带做**,不专门安排。
---
## 一、第一组对照已经拿到(2026-10-09 06:4x,意外收获)
两次观测的**事件速率同量级,内存表现却差五倍** —— 这条直接推翻了我原来的半个假设。
**暴涨组**(daemon `53940`,2026-10-09 00:4x–00:5x,会话在写 133KB 的 HTML):
- 内存:`160MB → 444MB → 957MB`(三分钟近六倍,rss 1162MB),随后被杀。
- 事件增量:`+9097 → +16869 → +18727`(每分钟)。
**平稳组**(daemon `73936`,2026-10-09 06:32–06:38,会话在跑闸门、复制工具):
- 内存:`116MB → 157MB → 190MB → 202MB`,**呈锯齿**(95–202MB 来回,GC 一直在回收)。
- 事件增量:`+20758 → +11422`(每分钟)。
**结论一**:事件速率不是充分因 —— 平稳组的事件速率**不比暴涨组低**,内存却稳在 200MB 以内。
**结论二**:暴涨组的独有动作是**一次写入 133KB 大文件**(`ui/mcn-workbench.html`,133459 B),且当时连着出现 5 条 `[ResourceReport] artifact observed`。**这是当前唯一可疑的触发点。**
---
## 二、下一组要采什么(三样,缺一条就说不清)
1、**内存曲线** —— `[DaemonMemWatch]` 的 `heapUsed / heapTotal / rss`,一分钟一条。
2、**事件计数** —— `Conversation event push summary` 的 `received` 增量,一分钟一条。
3、**会话动作时间线** —— 该会话在什么时刻用了 `Write` / `Edit`、写了多大的文件。
第 3 样最关键:**没有它就无法判断"暴涨发生在写大文件的那一刻还是别处"**。
---
## 三、现成命令(可直接复制)
**实时盯内存与事件(采样器已备好)**:
```
E:/ProgramData/.workbuddy/binaries/python/versions/3.13.12/python.exe mem_watch.py
```
脚本在工作区根(`mem_watch.py`,与其它 py 脚本同级;⛔ 别放 `tmp/`,那里会被清理)。改时长与间隔就改脚本开头的 `DURATION` / `INTERVAL`;输出追加到 `tmp/mem-watch-<日期>.csv`。脚本**只读 `daemon.log`**,不碰任何进程。
**补第 3 样(会话动作时间线)**:
```
ls -la --time-style=+"%H:%M" <目标目录>/ui/
```
```
grep -E "<时间窗>" <logs>/daemon.log | grep "<sessionId>" | grep -oE '"message":\[[^]]{0,120}' | sort | uniq -c | sort -rn
```
**拉完整内存曲线**:
```
grep "DaemonMemWatch" <logs>/daemon.log | sed -E 's/.*timestamp":"([^"]+)".*heapUsed=([0-9]+MB).*rss=([0-9]+MB).*/\1 heap=\2 rss=\3/'
```
---
## 四、判据(怎么算"验证成立")
- **若成立**:内存暴涨的时刻应与某次 `Write` / `Edit` 大文件**同秒或紧随**,且该时段 `received` 增量同步跳升。
- **若不成立**:出现内存暴涨但当时**没有大文件写入** ⇒ 嫌疑转向 `artifact` 快照、`modify-backup` 或别的东西,需要抓堆快照才能继续。
- **无论成立与否都要记的**:这一轮内存峰值是否被 GC 收回(对照第一组:第一轮 609MB 收回了、第二轮 957MB 没赶上)。
---
## 五、落点
- 采样数据:`tmp/mem-watch-<日期>.csv`
- 观察结论:追加到本文件「六、观察记录」一节,并同步进 `daemon-异常终止取证-20261009.md`
- ⛔ 不做的事:不调 daemon 启动参数、不重启 daemon、不打断在跑的会话(那是候选 B 的代价,已否掉)
---
## 六、观察记录
### 第 1 组 · 2026-10-09 06:32–06:38(在执行会话 `cc07347c` 现场)
- 会话:`[执行]-[产品规划]-重做界面补闸门与上报(第二棒)`,06:32:15 起,observed 时在 `working`。
- daemon:`73936`(起于 2026-10-09 00:53:38)。
- 内存:`116MB → 157MB → 132MB → 190MB → 154MB → 202MB → 191MB`(锯齿,峰值缓升)。
- 事件:`received` 从 `420014`(06:35)涨到 `452194`(06:37),增量 `+20758` / `+11422`。
- 该时段会话动作:读旧工具目录、建 `ui/_tools`/`ui/_scratch`(06:37),**尚未写大文件**。
- 判定:**内存未失控**。与暴涨组形成有效对照 ⇒ 见第一节「结论一」。
+2
View File
@@ -48,6 +48,8 @@
**换算比例**:16:51 段约 **31KB/事件**、16:52 段约 **27KB/事件** —— 两段一致,但**这是相关关系,不是已证因果**(见第六节)。 **换算比例**:16:51 段约 **31KB/事件**、16:52 段约 **27KB/事件** —— 两段一致,但**这是相关关系,不是已证因果**(见第六节)。
**要点四(后续对照,2026-10-09 06:32–06:38 补测)**:另起一个后台会话(跑闸门、读工具目录,**没有写大文件**)时,事件速率**同样高**(`+20758`/`+11422` 每分钟),而内存只在 **116–202MB 之间锯齿**(GC 持续回收)。⇒ **事件速率不是内存暴涨的充分因**;两组的唯一明显差别是暴涨组当时**一次写入了 133KB 的大文件**。据此把嫌疑收窄到「大文件写入」这一侧,验证方法见 `daemon-内存观察-复现单.md`。
--- ---
## 三、证据与复现命令 ## 三、证据与复现命令
+65
View File
@@ -0,0 +1,65 @@
# -*- coding: utf-8 -*-
"""
临时采样器 · daemon 内存 + 事件计数(会话活跃期观察)
用途:复现「会话活跃 ⇒ 事件洪峰 ⇒ daemon 内存暴涨」是否成立(A 方案)
只读 daemon.log,不碰任何进程;输出追加到 tmp/mem-watch-<日期>.csv
"""
import re
import time
import os
import datetime
LOG = r"E:/ProgramData/.workbuddy/logs/daemon.log"
OUT = r"E:/ProgramData/AIProject/contentm_agent/tmp/mem-watch-20261009.csv"
DURATION = 300 # 总时长(秒)
INTERVAL = 20 # 采样间隔(秒)
MEM_RE = re.compile(r"\[DaemonMemWatch\] pid=(\d+) heapUsed=(\d+)MB heapTotal=(\d+)MB rss=(\d+)MB")
EV_RE = re.compile(r'Conversation event push summary",\{"received":(\d+),"immediateSent":(\d+)')
def tail_text(path, nbytes=500000):
size = os.path.getsize(path)
with open(path, "rb") as f:
if size > nbytes:
f.seek(size - nbytes)
return f.read().decode("utf-8", "ignore")
def main():
d = os.path.dirname(OUT)
if d and not os.path.exists(d):
os.makedirs(d, exist_ok=True)
with open(OUT, "a", encoding="utf-8") as fo:
fo.write("# sampling start %s\n" % datetime.datetime.now().strftime("%Y-%m-%d %H:%M:%S"))
fo.flush()
end = time.time() + DURATION
while time.time() < end:
lines = tail_text(LOG).splitlines()
mem = ev = None
for ln in reversed(lines):
if mem is None and "DaemonMemWatch" in ln:
m = MEM_RE.search(ln)
if m:
mem = m.groups()
if ev is None and "Conversation event push summary" in ln:
m = EV_RE.search(ln)
if m:
ev = m.groups()
if mem and ev:
break
now = datetime.datetime.now().strftime("%H:%M:%S")
if mem and ev:
pid, hu, ht, rss = mem
rec, sent = ev
fo.write("%s,pid=%s,heap=%sMB,heapTotal=%sMB,rss=%sMB,received=%s,immediateSent=%s\n"
% (now, pid, hu, ht, rss, rec, sent))
else:
fo.write("%s,(miss)\n" % now)
fo.flush()
time.sleep(INTERVAL)
fo.write("# sampling end %s\n" % datetime.datetime.now().strftime("%Y-%m-%d %H:%M:%S"))
if __name__ == "__main__":
main()