RUNBOOK：工具执行埋点（tool-timing）¶
读者：接手本机 Trae 环境的人、事后分析时间去向的人。 实现体：
tool-timing-hook/tool-timing.py｜本次变更档案：tool-timing-20261007/SOP.md
1. 服务概览¶
| 项 | 内容 |
|---|---|
| 是什么 | 一个 Hook 脚本，无守护进程、无端口、无常驻内存 |
| 干什么 | 每次工具调用前后各跑一次：Pre 记开始时刻，Post 算时长并追加一行日志 |
| 由谁触发 | Trae 客户端的 PreToolUse 与 PostToolUse（hooks.json 中 matcher: "*" 各一条） |
| 依赖 | python3（系统自带）、~/.trae-cn/hooks.json、可写的 logs/ 与脚本目录 |
| 产出 | logs/tool_timing.jsonl（append-only）、tool-timing-hook/state/（临时态，1 h 回收） |
| 业务影响 | 无。它失败只损失度量数据，不影响代理服务、不影响工具调用本身 |
| 重要性 | 低（观测类）。可作为「时间分析」的唯一工具侧数据源，但不可用于生产决策链路 |
它解决什么：此前只有 logs/usage.jsonl（ts + token），步间隔 = 生成 + 工具执行 + 往返，三者不可分；
本埋点把工具执行时长单独量出来。
2. 路径与位置¶
| 用途 | 路径 |
|---|---|
| 实现体 | ~/Documents/services/token_proxy/tool-timing-hook/tool-timing.py |
| 数据日志 | ~/Documents/services/token_proxy/logs/tool_timing.jsonl |
| 临时状态 | ~/Documents/services/token_proxy/tool-timing-hook/state/（k-* 开始时刻、d-* 完成墓碑、prune.log 删除留痕） |
| 挂载配置 | ~/.trae-cn/hooks.json（PreToolUse / PostToolUse 各一条 matcher: "*"） |
| 离线自测 | ~/Documents/services/token_proxy/tool-timing-20261007/verify_tool_timing.py |
无凭据：本组件不连任何服务、不持有任何口令。
3. 日常速查表¶
# ① 最近 5 条埋点（确认在跑）
tail -n 5 ~/Documents/services/token_proxy/logs/tool_timing.jsonl
# ② 总行数（累计工具调用数）
wc -l ~/Documents/services/token_proxy/logs/tool_timing.jsonl
# ③ 漏挂检测：miss_pre 为真的条数（应为 0）
grep -c '"miss_pre": true' ~/Documents/services/token_proxy/logs/tool_timing.jsonl
# ④ 按工具聚合耗时（中位 / p90 / 合计占比）
cd ~/Documents/services/token_proxy && python3 - <<'PY'
import json, statistics as st
from collections import defaultdict
g = defaultdict(list)
for ln in open("logs/tool_timing.jsonl", encoding="utf-8"):
try:
d = json.loads(ln)
except ValueError:
continue
if isinstance(d.get("dur_ms"), (int, float)):
g[d.get("tool") or "?"].append(d["dur_ms"])
tot = sum(sum(v) for v in g.values()) or 1
for k, v in sorted(g.items(), key=lambda kv: -sum(kv[1])):
v = sorted(v)
print("%-16s n=%-6d 中位=%9.0fms p90=%9.0fms 合计=%8.2fmin 占=%5.1f%%"
% (k, len(v), st.median(v), v[min(len(v) - 1, int(len(v) * 0.9))], sum(v) / 60000, 100 * sum(v) / tot))
PY
# ⑤ 挂载是否完整（预期输出 2）
python3 -c "import json,os;d=json.load(open(os.path.expanduser('~/.trae-cn/hooks.json')));print(sum(1 for ev in ('PreToolUse','PostToolUse') for it in d['hooks'][ev] for h in it['hooks'] if 'tool-timing' in h['command']))"
4. 日常操作¶
启用 / 停用：本组件由 hooks.json 挂载控制，没有开关文件。
# 停用（两条一起摘除；临时停用可只摘 PostToolUse——Pre 仍写 state，由 1 h 回收清理）
python3 - <<'PY'
import json, os
P = os.path.expanduser("~/.trae-cn/hooks.json")
d = json.load(open(P, encoding="utf-8"))
for ev in ("PreToolUse", "PostToolUse"):
d["hooks"][ev] = [it for it in d["hooks"][ev]
if not any("tool-timing.py" in h.get("command", "") for h in it.get("hooks", []))]
json.dump(d, open(P, "w", encoding="utf-8"), ensure_ascii=False, indent=1)
print("已摘除")
PY
# 启用：见 SOP.md 第 5 章步骤 2 的幂等挂载脚本（重复执行安全）
两种操作均即时生效，无需重启（2026-10-07 实测：改 hooks.json 后下一次工具调用即落盘）；
若观察到不生效，再重启 Trae 兜底。
清空状态目录（不影响日志；高危删除，先确认路径）：
ls -1 ~/Documents/services/token_proxy/tool-timing-hook/state/ # 先看
find ~/Documents/services/token_proxy/tool-timing-hook/state/ -type f -name '[kdt]-*' -delete # 只删本组件产物
5. 配置项（脚本内常量）¶
| 常量 | 现值 | 含义与调整时机 |
|---|---|---|
STALE_SECONDS |
3600 | state / 墓碑文件的保留期。调小 → state 目录更干净，但「Pre 到了 Post 没到」的错配窗口变短 |
STATE_PREFIX / TMP_PREFIX / DONE_PREFIX |
k- / t- / d- |
状态文件名前缀，用于回收时区分「本组件产物」与其它文件 |
LOG_FILE |
<脚本目录>/../logs/tool_timing.jsonl |
由脚本位置推导，移动脚本会同时改变日志落点 |
修改后无需重启 Trae（脚本每次调用重新加载；hooks.json 才需要重启）。
6. 备份与恢复¶
- 挂载配置的备份：
tool-timing-20261007/backup/home/rain/.trae-cn/hooks.json.bak.20261007-071701； - 数据日志没有自动备份——它是 append-only 且不可再生（与
usage.jsonl同级）， 需要留档时手工cp：bash cp -p ~/Documents/services/token_proxy/logs/tool_timing.jsonl ~/tool_timing.$(date +%Y%m%d).jsonl - 恢复配置：见 SOP.md 第 7 章。
7. 监控与告警¶
| 指标 | 健康值 | 查看 |
|---|---|---|
| 日志是否在增长 | 每次工具调用 +1 | 速查表 ①② |
miss_pre 占比 |
0（>0 说明 Pre 未挂载或 state 被提前清理） | 速查表 ③ |
id_src 分布 |
应全为 tool_use_id；出现 fallback 说明事件缺 tool_use_id |
grep -c fallback logs/tool_timing.jsonl |
dur_ms 量级 |
常规工具 10~5000 ms；持续 >30 s 需关注（可能是远端操作或大命令） | 速查表 ④ |
| state 目录文件数 | 应保持在一小时内的调用量级（数十个） | ls -1 tool-timing-hook/state/ \| wc -l |
8. 故障处置¶
场景 1：日志完全不增长¶
症状：触发多次工具调用后 wc -l logs/tool_timing.jsonl 仍不变。
诊断
python3 -c "import json,os;json.load(open(os.path.expanduser('~/.trae-cn/hooks.json')));print('JSON 合法')" # 预期：JSON 合法
python3 -c "import json,os;d=json.load(open(os.path.expanduser('~/.trae-cn/hooks.json')));print(sum(1 for ev in ('PreToolUse','PostToolUse') for it in d['hooks'][ev] for h in it['hooks'] if 'tool-timing' in h['command']))" # 预期：2
ls -l ~/Documents/services/token_proxy/tool-timing-hook/tool-timing.py # 预期：存在
处置：JSON 非法 → 用 SOP 第 7 章方式 A 还原备份；挂载数 <2 → 重跑 SOP 步骤 2； 脚本缺失 → 从版本库/备份恢复。处置后重启 Trae 兜底（正常情况即时生效）。
验证：再触发一次工具调用，tail -n 1 应见新行。
场景 2：miss_pre 大量为真¶
症状：grep -c '"miss_pre": true' 随时间线性增长。
诊断：说明 Post 在跑而 Pre 没跑。检查 hooks.json 的 PreToolUse 是否被别的工具覆写、
或某次编辑把 PreToolUse 数组结构改坏。
处置：重跑 SOP 步骤 2 的幂等挂载脚本（会补齐缺失的一条）；仍不生效再重启 Trae 兜底。
验证：新产生的行 miss_pre 应为 false。历史 true 行不必清理——它们本身就是证据。
场景 3：state 目录膨胀¶
症状：ls -1 tool-timing-hook/state/ | wc -l 远超一小时的调用量级。
诊断：ls -lt tool-timing-hook/state/ | head 看时间分布；
若大量文件 mtime 超过 1 h 仍在，说明回收未生效（可能 Pre/Post 均未运行）。
处置：按第 4 章「清空状态目录」（只删 [kdt]-*）；然后确认挂载是否完整。
验证：再触发若干次调用后，目录内文件数回到小时量级；state/prune.log 会出现 [PRUNE][高危] 行（回收生效的证据）。
场景 4：埋点拖慢了工具调用¶
症状：感觉工具调用变慢。
诊断：单对 Hook 实测约 125 ms（含两次 python3 启动），与 p50 11 s 的步间隔相比可忽略。
若确实变慢，先按第 3 章速查表 ④ 看 dur_ms 是否异常——dur_ms 量的是工具自身，不含 Hook 开销。
处置：确认为 Hook 开销过大时，摘除 PostToolUse 一条（保留 Pre），或整体停用。
验证：停用后 hooks.json 挂载数为 0，日志停止增长。
9. 安全与权限¶
- 不持有任何凭据，不联网，不连远端主机；
- 日志内容不含工具参数（只记工具名、时长、会话 id、
tool_use_id）——不会带出文件内容或命令正文； - 唯一的高危动作是回收过期文件，已限定前缀白名单 + 普通文件 + 不跟随符号链接，并写
prune.log留痕； - 日志与状态文件的权限沿用本机默认（
logs/现有文件为664，属主rain）。
10. 容量与性能¶
- 单行日志约 200 B；按历史调用量级（约 300 次/天）估算，约 60 KB/天、20 MB/年，无需轮转；
- state 目录稳态：一小时内调用量级（数十个空文件）；
- 写入为纯 append，无锁、无并发冲突（每行 < PIPE_BUF 一次写）；
- 已知瓶颈：无。
11. 附录¶
日志字段说明¶
| 字段 | 含义 |
|---|---|
ts |
记录时刻（工具执行完成时刻，本地时间） |
dur_ms |
工具执行时长（毫秒）；null 表示 Pre 未记录到开始时刻 |
tool |
Hook 侧工具名 |
llm_tool |
请求体侧工具名（两者偶有差异，如请求体 SearchReplace → Hook 侧 Edit） |
session / agent |
会话与子智能体标识，用于按会话切分 |
id_src |
配对键来源：tool_use_id（正常）/ fallback（事件缺唯一 id） |
miss_pre |
是否「只收到 Post」——恒为 true 即为挂载缺失的信号 |
相关文档¶
- 变更档案：
SOP.md - 时间侧全景分析：
efficiency-sides-20261007/profile_time_sides.py - 系统侧（远端命令）口径：skill
deployment-tool-engineering的remote_cmd_profile.py
修订记录¶
| 日期 | 变更 |
|---|---|
| 2026-10-07 | 首次建立 |
来源：
/home/rain/Documents/services/token_proxy/tool-timing-20261007/RUNBOOK.md｜ 最后更新：2026-10-07 07:29（由build/sync.py同步，请勿在站点侧修改）