讀一個檔，Cursor 自己量到的時間是 11 毫秒。從第一支 hook 開始跑，到最後一支 hook 開始跑，中間隔了 1.8 秒。

昨天量到：Cursor 會等 hook 跑完。今天把帳攤開，模型還沒放進去，現在這幾支 hook 已經讓每一步多花多少時間。

兩個欄位，就能把時間拆開

資料還是昨天那個 Agent 對話。到我開始量的時候，一共 331 筆 hook 紀錄、91 次工具呼叫。

一筆 postToolUse 的 payload，欄位長這樣：

conversation_id, generation_id, model, tool_name, tool_input, tool_output,
duration, tool_use_id, session_id, hook_event_name, cursor_version,
workspace_roots, user_email, transcript_path

要用的是兩個：

• tool_use_id：同一次工具呼叫，preToolUse 和 postToolUse 帶的是同一個值，可以串起來。
• duration：Cursor 自己量的工具執行時間。

算法很簡單：postToolUse 開始的時間，減掉 preToolUse 開始的時間，再扣掉 duration，剩下的就是「工具以外」花掉的時間。91 次呼叫裡，有 74 次前後都串得起來。

順帶一提，payload 裡有 user_email。hook 紀錄本身就是敏感資料，Day 3 講過的「日誌自己變成外洩點」，這裡又是一例。

四種工具，一張表

工具越輕，hook 的比重越大。讀檔本身只佔整段的百分之一不到；Shell 本身就要 10 秒，hook 那 2 秒相對小。而且這還沒算 postToolUse 自己那一段，昨天量到 Agent 也會等它。

看 p90 也差不多。全部 74 次的 p90 是 2,397 ms，也就是十次裡有九次，工具以外的時間在 2.4 秒以內；最慢的一次是 4,564 ms。

換成整個對話來看：72 次呼叫（不含 WebFetch），工具本身加起來 263 秒，工具以外多出來的加起來 129 秒，約 2 分鐘，而這段紀錄從頭到尾是 48 分鐘。有些呼叫是同時跑的，重疊的部分不會多等兩次，所以真正多等的時間比 2 分鐘少一些。工具本身那 263 秒裡，Shell 指令每次約 10 秒的收尾就佔了大半，那筆帳後面再算。

表上少了一種工具：WebFetch。它算出來是負的，中位數 -249 ms（只有 2 次），代表它的 duration 跟本機 hook 的時間不在同一條線上。Day 1 發現 WebFetch 在 Cursor 的雲端跑、本機看不到，我猜跟這件事有關，但沒有驗證。

拆成段：每一段 hook 大約 0.7 秒

把 Shell 的四個事件兩兩相減：

preToolUse → beforeShellExecution            p50     672 ms
beforeShellExecution → afterShellExecution   p50  10,887 ms（指令本身 10,456 ms）
afterShellExecution → postToolUse            p50     714 ms

每一段 hook 大約 0.7 秒。一次工具呼叫要經過幾段，就要付幾次：

• Read：preToolUse、beforeReadFile、postToolUse，三段。
• Shell：preToolUse、beforeShellExecution、afterShellExecution、postToolUse，四段。
• Write：preToolUse、afterFileEdit、postToolUse，三段。

postToolUse 和 afterFileEdit 各掛了兩支 hook，但同一個事件的兩支是一起跑的，audit_edit 只比 hook_diag 晚 18 ms 開始。所以算時間要算段數，不是算支數。

那 0.7 秒是誰花的？

我把兩支 hook 拿出來，照 Cursor 的方式單獨跑 20 次：開一個新的 python、從 stdin 餵一份 payload、跑完結束。

空的 python（只開行程）   p50  67 ms
hook_diag.py             p50  92 ms
audit_edit.py            p50 117 ms

我的腳本大約 0.1 秒。每一段 0.7 秒裡，剩下約 0.6 秒發生在我的腳本外面。

那 0.6 秒可能是 Cursor 叫起 hook 的方式，可能是行程之間傳資料，也可能是 Cursor 在兩個步驟之間本來就要花的時間。要分清楚，最直接的辦法是把 hook 全部關掉再量一次；可是 hook 一關，時間線就沒了，我就什麼都量不到。

量測工具本身就在被量的那條路上，今天這一題解不開。比較可行的下一步，是只拿掉一個事件的 hook，例如 beforeReadFile，看 Read 會不會剛好少掉一段 0.7 秒。

我一開始怪錯了對象

這個對話裡，每一條 Shell 指令都要 10 秒左右，連查一個檔案大小都是。我第一個懷疑的就是 hook：掛了 15 個事件，一定是它們拖的。

拆開才看到，那 10 秒落在 Cursor 自己量的指令 duration 裡，中位數 10,456 ms；hook 那幾段加起來約 2 秒。還有一個旁證：有一條指令因為引號寫錯，在 PowerShell 解析階段就失敗了，整趟只花 1.2 秒。

所以那 10 秒是指令工具自己的成本，很可能是它每次跑完要做的收尾，跟 hook 無關。這是 Day 9 那個教訓的小號版本：看到慢，先拆開再怪。

今天的成果，你可以直接拿去用

只要你的 hook 有記開始時間、也把 payload 存下來，下面這段就能算出每次工具呼叫「工具本身」跟「hook 多出來」的時間：

import json
import re
from datetime import datetime


def grab(pattern, text):
    m = re.search(pattern, text)
    return m.group(1) if m else None


calls, broken = {}, 0
for line in open("hook-diag.jsonl", encoding="utf-8"):
    try:
        rec = json.loads(line)
    except json.JSONDecodeError:
        broken += 1                                  # 壞掉的行跳過，但要數出來
        continue
    text = rec.get("stdin_text") or ""
    event = grab(r'"hook_event_name"\s*:\s*"([^"]+)"', text)
    tuid = grab(r'"tool_use_id"\s*:\s*"([^"]+)"', text)
    if not tuid or event not in ("preToolUse", "postToolUse"):
        continue
    c = calls.setdefault(tuid, {"tool": grab(r'"tool_name"\s*:\s*"([^"]+)"', text)})
    c[event] = datetime.fromisoformat(rec["ts"]).timestamp()
    dur = grab(r'"duration"\s*:\s*([0-9.]+)', text)
    if event == "postToolUse" and dur:               # payload 被截斷時 duration 會不見
        c["tool_ms"] = float(dur)

print(f"壞掉的行：{broken}")
for c in calls.values():
    if "preToolUse" in c and "postToolUse" in c and "tool_ms" in c:
        wall = (c["postToolUse"] - c["preToolUse"]) * 1000
        print(f"{c['tool']:<8} 工具本身 {c['tool_ms']:6.0f} ms　hook 多出來 {wall - c['tool_ms']:6.0f} ms")

我在自己的紀錄上跑，Read 大多是「工具本身幾十毫秒，hook 多出來一秒多」。

想知道自己的 hook 單獨跑一次要多久，照 day10-lab/bench_hooks.py 的做法：用 subprocess.run 開新行程、從 stdin 餵 payload、量 20 次取中位數。記得把 hook 的輸出導到暫存檔，不然量測本身會寫進真的紀錄。

誠實欄

• 一個對話、一台機器。 Windows、Cursor 3.21.9。這個對話在整理流量數據，工具組合偏向讀檔和跑指令，跟一般寫程式的對話不一樣。
• Write 只有 2 次。 那一列的數字不能當準。
• 0.6 秒是誰花的，我不知道。 我只能說不是我的腳本。
• ts 是腳本開始跑的時間，不是 Cursor 叫起它的時間。 中間還隔著 python 自己開起來的 60 多毫秒。
• 有 93 筆紀錄沒辦法歸類。 它們連事件名稱都沒留下，原因是明天要講的另一個問題。

明天看另一個代價。同一時間常常有好幾支 hook 一起跑，而它們都往同一個檔寫。我的稽核紀錄裡有 3 行只剩尾巴；照同樣的寫法在自己電腦上重現，1,000 筆紀錄少了兩成上下。

今天對應的威脅： T3（藉 Agent 之手規避控制）。稽核的成本如果沒有人量，就會以「好像變慢了」的形式被感覺到，最後被關掉。量清楚，才有辦法決定哪一段該留。

實驗與程式： 2026-09-24 跑。day10-lab/hotpath_timeline.py（時間線，排除探針時段）、bench_hooks.py（單支 hook 的成本）、timeline_min.py（上面那段精簡版）。資料是這個專案的 hook-diag.jsonl。Cursor 3.21.9。本篇沒有引用外部來源。