我的稽核紀錄裡有 3 行只剩尾巴。我照同樣的寫法在自己電腦上重現:20 個行程同時寫,1,000 筆紀錄少了 195 到 250 筆,壞掉的行卻只有 6 到 48 行。
看得到的壞行,只是下限。
前兩天量的是時間:Cursor 會等 hook,而 hook 已經讓每一步多花 1 到 2 秒。今天量另一個代價:紀錄本身還完不完整。對一份要拿來當證據的稽核紀錄,這一題比快慢更要緊。
Agent 在同一則回覆裡一次送出好幾個工具時,這些工具是一起開始的。Day 10 用的那個 Agent 對話裡,有 24 批這種情況,同一批工具的 preToolUse 彼此多半只差 0 到 10 ms。
同一個事件掛的兩支 hook 也是一起跑的:postToolUse 上的 audit_edit.py 比 hook_diag.py 晚 18 ms 開始(73 對的中位數),九成二在 50 ms 以內。
這兩支寫的是不同的檔,彼此不會打架。會打架的是同一支 hook 的好幾個分身:三個工具同時開始,就有三個 hook_diag.py 行程,同時往 hook-diag.jsonl 的結尾寫。
hook-diag.jsonl 目前 2,954 行,有 3 行不是合法的 JSON:
第 395 行 123 字 9/18 22:41 前一行完整
第 1442 行 192 字 9/20 22:38 前一行完整
第 1560 行 32 字 9/20 23:03 前一行完整
三行都是某一筆紀錄的結尾,最後都是紀錄正常收尾的那幾個字;前一行都是另一筆完整的紀錄;原本那筆的開頭,不見了。
我會發現它們,是因為 Day 10 那天,我的第一支分析腳本一跑就當掉,錯誤訊息是 JSONDecodeError: Extra data。而且我一開始還讀錯了:只印出每行前 160 個字,就以為第 1442 行和第 1560 行是同一筆被拆成兩半。把整行攤開才看清楚,三行彼此無關,各自發生在不同時間。讀證據要讀完整,這一條我自己也差點沒做到。
我的推測是:兩個行程幾乎同時 append,後寫的蓋掉了先寫的;先寫的那筆比較長,就剩下一截尾巴。
推測要驗。我寫了一支小程式,照抄 hook_diag.py 的寫法:每次 open("a")、寫一行 JSON、關檔。然後讓很多個行程同時跑,只寫暫存檔,不碰真的紀錄。
紀錄內容用「é」填滿。它在 UTF-8 是 2 個位元組,跟 hook 紀錄裡那些被重新編碼過的中文一樣(Day 5 量過,220 筆裡有 201 筆是這樣)。每種情境跑兩次:
| 情境 | 每筆大小 | 預期 | 完整 | 壞掉的行 | 消失 |
|---|---|---|---|---|---|
| 200 個行程,各寫 1 筆 | 1.8 KB | 200 | 198/200 | 0/0 | 2/0 |
| 20 個行程,各寫 50 筆 | 1.8 KB | 1,000 | 750/805 | 48/6 | 250/195 |
| 20 個行程,各寫 50 筆 | 9.8 KB | 1,000 | 讀不進來/746 | —/7 | —/254 |
看出三件事:
回到我的真實紀錄:3 行只剩尾巴,是看得到的下限。到底少了幾筆,我不知道,因為被整筆蓋掉的紀錄什麼都不會留下。
找候選有一個辦法:每個 preToolUse 都應該有一個同 tool_use_id 的 postToolUse。那個對話的 91 個 tool_use_id 裡,串得起來的有 74 個。剩下 17 個配不起來,原因可能是 payload 被截斷、duration 不見,也可能是紀錄被蓋掉,目前分不出來。
時間線裡還有一群紀錄根本用不上:那個對話的 331 筆裡,有 93 筆連事件名稱都沒有,將近三成。
原因在 hook_diag.py 自己。它只存 payload 的前 4,000 個字,而 Cursor 把 hook_event_name 放在 payload 的後段。beforeReadFile 的 payload 一開頭就是整份檔案內容,檔案一大,事件名稱就被切掉了。
改法很簡單:截斷之前,先把要用的欄位抽出來,放在紀錄的最上層。
# text 是從 stdin 讀進來、已經解碼的原始字串
record["stdin_text"] = text[:4000]
try:
data = json.loads(text.lstrip("\ufeff")) # Day 1 那 3 個看不見的位元組還在,要先拿掉
record["meta"] = {k: data.get(k) for k in ("hook_event_name", "tool_name", "tool_use_id", "duration")}
except json.JSONDecodeError as exc:
record["meta_error"] = repr(exc) # 解析不了也要留下原因,不要靜靜略過
我用一份照 beforeReadFile 欄位順序造的 payload 試,全長 14,224 字:原本的寫法存下 4,000 字,裡面找不到事件名稱;改法存一樣的 4,000 字,事件名稱留住了。
對了,我看到的每一筆 payload,最前面都還是那個 \ufeff。Day 1 讓 hook 十一天零筆的那 3 個位元組,到今天都還在。
蓋掉的問題,我試了加鎖:寫入之前,先鎖住旁邊一個 .lock 檔,一次只讓一個行程 append。
import msvcrt
import time
def append_locked(path, line):
with open(str(path) + ".lock", "a+b") as lk:
lk.seek(0)
while True:
try:
msvcrt.locking(lk.fileno(), msvcrt.LK_NBLCK, 1)
break
except OSError:
time.sleep(0.005)
try:
with open(path, "a", encoding="utf-8") as f:
f.write(line)
finally:
lk.seek(0)
msvcrt.locking(lk.fileno(), msvcrt.LK_UNLCK, 1)
同樣 20 個行程、各寫 50 筆的壓力,1.8 KB 和 9.8 KB 各跑一次:1,000 筆全部完整,0 行壞掉,0 筆消失。
msvcrt 只有 Windows 有,macOS、Linux 要換成 fcntl.flock,我沒有測。另一條路是每筆寫成一個獨立的小檔、事後再合併,根本不用搶;這條我也還沒測。
一、數一下你的紀錄檔有沒有壞行。 幾行就夠:
import json
bad = 0
for line in open("hook-diag.jsonl", encoding="utf-8", errors="replace"):
try:
json.loads(line)
except json.JSONDecodeError:
bad += 1
print("壞掉的行:", bad)
errors="replace" 不能省,不然遇到不合法的 UTF-8,整支程式會跟我一樣當掉。另外記得:沒有壞行,不代表沒有少。
二、做配對檢查。 每個 preToolUse 都該有同一個 tool_use_id 的 postToolUse。配不起來的,就是要回頭看的候選。
三、在 hook 寫檔的地方加鎖,截斷之前先把事件名稱抽出來。 兩段程式都在上面。
audit-findings.jsonl 1,000 行沒有壞行。 但照這次重現的結果,這不代表它沒有少。明天回到原本的問題:把 Jev 放進 hook,每一次要多等多久?Day 9 那個「只問確定性層判不出來的」判斷式,在真實紀錄上又要問幾次?
今天對應的威脅: T3(藉 Agent 之手規避控制)。Day 5 談過監管鏈:證據從現場到法庭之間不能掉包。一份會自己少掉紀錄、又不報錯的軌跡,連「沒有掉包」都證明不了。
實驗與程式: 2026-09-24 跑。day10-lab/broken_lines.py(攤開壞掉的行)、append_race.py(同時寫入的重現與加鎖修法)、truncation_fix_demo.py(先解析再截斷)。資料是這個專案的 hook-diag.jsonl 與 audit-findings.jsonl。本篇沒有引用外部來源。