⌛️Identify the cause of slow Claude Code hooks

⌛️Identify the cause of slow Claude Code hooks | Tsukutta

Following the previous work プロジェクト台帳とsymlinkツリーの話, this is part of the Claude Code environment series.

As you add more hooks, you start to feel "something got slower." There are mysterious gaps between turns, and it takes a long time from typing a prompt to when the response starts. But "which hook is causing it" is hard to pinpoint. Hooks are called from inside Claude Code, and if there's no error, nothing gets logged. In this article, I'll introduce a single wrapper that writes hook execution times to JSONL, and a script to aggregate them. I'll also show all the actual measurements.

The Problem: I Know Hooks Are Slow, But I Don't Know Which One

My Claude Code environment currently has 10+ types of hooks installed.

UserPromptSubmit: Cost guard, model routing notification, context loading
PreToolUse(Edit|Write): Secret scanning, .env protection
PreToolUse(Bash): Git command guard
SessionStart: Skill auto-update, Obsidian context loading
MessageDisplay: Filtering

When hooks run synchronously, Claude Code blocks until they complete. There's no way to manually track whether "cost_guard.sh is slow every time" or "it's obsidian_context.sh instead."

The Measurement Mechanism: A Single $EPOCHREALTIME Wrapper

~/.claude/scripts/hook-latency-wrap.sh is the actual wrapper implementation.

bash

#!/usr/bin/env bash
# hook-latency-wrap.sh — 任意の hook をラップして実行時間を JSONL に記録
# 使い方: settings.json の command を以下に置き換える
#   "command": "~/.claude/scripts/hook-latency-wrap.sh /path/to/hook.sh"

set -uo pipefail

HOOK_BIN="${1:-}"
[ -z "$HOOK_BIN" ] && { echo "usage: $0 <hook-binary> [args...]" >&2; exit 64; }
shift || true

LOG_DIR="$HOME/.claude/logs"
mkdir -p "$LOG_DIR"
JSONL="$LOG_DIR/hook-latency.jsonl"

# EPOCHREALTIME = bash 5+ で SS.NNNNNN 形式（秒.マイクロ秒）
start_us=$(printf '%s' "${EPOCHREALTIME//./}" | sed 's/^0*//')
# 万一 EPOCHREALTIME が空(bash <5)なら python フォールバック
[ -z "$start_us" ] && start_us=$(python3 -c 'import time;print(int(time.time()*1000000))')

"$HOOK_BIN" "$@"
exit_code=$?

end_us=$(printf '%s' "${EPOCHREALTIME//./}" | sed 's/^0*//')
[ -z "$end_us" ] && end_us=$(python3 -c 'import time;print(int(time.time()*1000000))')

elapsed_ms=$(( (end_us - start_us) / 1000 ))
hook_name=$(basename "$HOOK_BIN")
ts=$(date -u +%Y-%m-%dT%H:%M:%S)

printf '{"ts":"%s","hook":"%s","elapsed_ms":%d,"exit_code":%d}\n' 

  "$ts" "$hook_name" "$elapsed_ms" "$exit_code" >> "$JSONL"

exit "$exit_code"

There are two key design points.

① Don't call python in $EPOCHREALTIME. date +%s%N only runs on Linux, and macOS's date doesn't support nanoseconds. The bash 5+ built-in variable $EPOCHREALTIME returns seconds + microseconds in 1716912345.678901 format. On macOS Ventura and later, /bin/bash --version is 5.x, so it's available by default.

② Transparently pass through the original exit code in exit "$exit_code". If a hook returns exit 2, Claude Code should block and show an error, but if the wrapper always returns 0, that information disappears. Since this is a measurement-only wrapper, I don't modify the hook's behavior at all.

How to Insert into settings.json

Just pass the existing hook command directly to the wrapper. Don't change the surrounding structure.

json

// 変更前
{
  "type": "command",
  "command": "~/.claude/hooks/cost_guard.sh"
}

// 変更後（1行変えるだけ）
{
  "type": "command",
  "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/cost_guard.sh"
}

The relevant part of the actual ~/.claude/settings.json looks like this. All 3 hooks plugged into UserPromptSubmit are wrapped.

json

"UserPromptSubmit": [
  {
    "hooks": [
      {
        "type": "command",
        "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/user_prompt_submit.sh"
      },
      {
        "type": "command",
        "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/cost_guard.sh"
      },
      {
        "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/model_routing_reminder.sh",
        "type": "command"
      }
    ]
  }
]

This appends one line to ~/.claude/logs/hook-latency.jsonl for each hook invocation.

jsonl

{"ts":"2026-06-21T20:10:41","hook":"cost_guard.sh","elapsed_ms":5196,"exit_code":0}
{"ts":"2026-06-21T20:10:33","hook":"obsidian_context.sh","elapsed_ms":827,"exit_code":0}
{"ts":"2026-06-21T20:11:18","hook":"skills-auto-update.sh","elapsed_ms":45705,"exit_code":0}

Aggregation Script: hook-latency-report.sh

~/.claude/scripts/hook-latency-report.sh [days] produces the aggregation. The default is the last 7 days.

bash

python3 - "$JSONL" "$DAYS" <<'PY'
import sys, json, datetime, collections
log, days = sys.argv[1], int(sys.argv[2])
cutoff = datetime.datetime.now() - datetime.timedelta(days=days)

stats = collections.defaultdict(list)
fail = collections.Counter()
total_records = 0
with open(log) as f:
    for line in f:
        try:
            r = json.loads(line)
            ts = datetime.datetime.fromisoformat(r["ts"])
            if ts < cutoff:
                continue
            total_records += 1
            stats[r["hook"]].append(r["elapsed_ms"])
            if r.get("exit_code", 0) not in (0, ):
                fail[r["hook"]] += 1
        except Exception:
            continue

rows = []
for hook, vals in stats.items():
    vals_sorted = sorted(vals)
    n = len(vals_sorted)
    p95 = vals_sorted[min(n-1, int(n*0.95))]
    rows.append((hook, n, sum(vals_sorted)//n, p95, vals_sorted[-1], fail.get(hook, 0)))
rows.sort(key=lambda r: -r[3])  # p95 降順

for hook, n, mean, p95, mx, fl in rows:
    flag = " ⚠" if p95 > 1500 else ""
    print(f"{hook:<32} {n:>5} {mean:>6}ms {p95:>6}ms {mx:>6}ms {fl:>5}{flag}")
PY

The decision criterion is: if p95 exceeds 1,500ms, display ⚠. Synchronous hooks in Claude Code block the user for exactly this duration. If you have to wait 1.5 seconds every time you send a prompt, it crosses the threshold where you feel "slow."

:::message The reason for using p95 is "the average hides spikes, the maximum lies." The average gets pulled by the healthy majority of calls and hides spikes. The maximum jumps on a single outlier (post-sleep, timeout, zombie process) and diverges from daily experience. p95 means "95 out of 100 calls are within this time," so it honestly shows daily slowness. :::

Actual Measurements: Last 7 Days, 29,866 Records

text

=== hook latency (last 7d, 29866 records) ===
hook                                 n    mean     p95     max  fail
----------------------------------------------------------------------
skills-auto-update.sh              365  46659ms  46114ms 1073920ms     0 ⚠
cost_guard.sh                     1493    605ms   2518ms   5802ms     0 ⚠
obsidian_context.sh                728  27816ms    782ms 19636398ms     1
model_routing_reminder.sh           23    148ms    451ms    641ms     0
pre_secrets_check.sh              2642     90ms    235ms   5561ms     0
user_prompt_submit.sh             1494     73ms    210ms    997ms     0
pre_env_guard.sh                  2642     59ms    154ms   4754ms     0
pre_git_guard.sh                  5726     43ms    117ms   2665ms     2
message_display_filter.sh        14753     47ms     96ms   5859ms     0

Two have ⚠️ flags, but the underlying issues are different.

skills-auto-update.sh (p95: 46 seconds): Every SessionStart, it takes 45 seconds to git pull the skill list. It looks fatal at first glance, but settings.json has "async": true attached, so it doesn't block Claude Code. Hooks with the async flag start the session without waiting for results. No problem, but without the async flag, startup would freeze for 45 seconds every time.

cost_guard.sh (p95: 2,518ms): This is a synchronous hook in UserPromptSubmit. It calls ccusage every prompt to check the plan quota. p95 is 2.5 seconds, with maximum 5.8-second blocks occurring every turn. This matches the feeling ―― the mysterious 2-3 second gap from sending a prompt to when the response starts was this.

obsidian_context.sh has broken mean: The contradiction of mean being 27,816ms (27 seconds!) while p95 is 782ms is because the hook survived as a zombie during Mac sleep and records got batched when the Mac woke up. There's also one record with exit code 1, matching the post-sleep failure. Mean is unusable. p95 is 782ms, so async: false, and there is indeed a wait at SessionStart, but it's within tolerance.

Pitfalls I Hit

Leading zeros remain when removing the decimal point in $EPOCHREALTIME → Need to insert sed 's/^0*//' or the shell errors on integer conversion
On bash 4 (macOS default /bin/bash), $EPOCHREALTIME is empty → Either install 5.x with brew install bash or fall back to python3. Verify the fallback is working with echo "${BASH_VERSION}"
Can't measure async-flagged hooks even when wrapped → async: true hooks are forked by Claude Code without waiting, so elapsed_ms is correctly written to JSONL. But since that hook's block time is zero, even if ⚠️ appears in aggregation, it's harmless operationally
Mean breaks but p95 stays normal → Even if zombie records during sleep push up the mean, p95 won't move enough to be affected. Never trust mean, always watch p95
Not passing through exit code causes accidents → If the wrapper always returns exit 0, even if pre_git_guard.sh blocks, it passes through. Returning the original code with exit "$exit_code" is essential
JSONL grows to 5.8MB → 7 days, 29,866 records reach this size. Without rotation, it exceeds 100MB in half a year. Need logrotate or periodic trim with launchd

Summary

Wrap hooks with hook-latency-wrap.sh → Record execution time to ~/.claude/logs/hook-latency.jsonl
Aggregate count/mean/p95/max per hook with hook-latency-report.sh, show ⚠️ when p95 > 1500ms
What actual measurements revealed: skills-auto-update.sh takes 46 seconds but async: true so doesn't block. cost_guard.sh had p95 2.5-second synchronous blocks happening every turn
Mean breaks on outliers (zombie processes, post-sleep). p95 is closer to reality
The presence or absence of the async flag changes what "hook slowness" means. Check async/sync before measuring

Next time, based on this JSONL, the story of making cost_guard.sh asynchronous ―― the tradeoffs of switching synchronous hooks to async, and how to guarantee "things we must always check before blocking" even asynchronously.

Lily (@bokuwalily) ― Individual developer. Building automation infrastructure with Claude Code while mass-producing iOS apps and web services
◼︎ Apps I've made are summarized at **ポートフォリオ**📱
◼︎ New releases and development behind-the-scenes shared on X **@bokuwalily**🐦
◼︎ OSS: **github.com/bokuwalily**🐙
Your ❤️ and shares are my motivation!

前作のプロジェクト台帳とsymlinkツリーの話に続く、Claude Code環境シリーズです。

hookを増やしていくと「なんか重くなった」という感覚が出てきます。ターンとターンの間に謎の間がある、プロンプトを打ってから応答が始まるまでが長い。でも「どのhookが原因か」を突き止めるのが難しい。hookはClaude Codeの内部から呼ばれ、エラーでなければ何もログに出ないからです。この記事では、hookの実行時間をJSONLに書き出すラッパー1本と、それを集計するスクリプトを紹介します。実測値も全部出します。

困りごと：hookが重いのは分かるが、どのhookかが分からない

私のClaude Code環境には現時点で10種類以上のhookが刺さっています。

UserPromptSubmit: コストガード・モデルルーティング通知・コンテキスト読み込み
PreToolUse(Edit|Write): シークレットスキャン・.env保護
PreToolUse(Bash): gitコマンドガード
SessionStart: スキル自動更新・Obsidian文脈読み込み
MessageDisplay: フィルタリング

hookが同期実行の場合、完了するまでClaude Codeはブロックします。「cost_guard.sh が毎回重いのか」「それとも obsidian_context.sh か」を手で追うのは無理です。

計測の仕組み：$EPOCHREALTIME ラッパー1本

~/.claude/scripts/hook-latency-wrap.sh がラッパーの実体です。

bash

#!/usr/bin/env bash
# hook-latency-wrap.sh — 任意の hook をラップして実行時間を JSONL に記録
# 使い方: settings.json の command を以下に置き換える
#   "command": "~/.claude/scripts/hook-latency-wrap.sh /path/to/hook.sh"

set -uo pipefail

HOOK_BIN="${1:-}"
[ -z "$HOOK_BIN" ] && { echo "usage: $0 <hook-binary> [args...]" >&2; exit 64; }
shift || true

LOG_DIR="$HOME/.claude/logs"
mkdir -p "$LOG_DIR"
JSONL="$LOG_DIR/hook-latency.jsonl"

# EPOCHREALTIME = bash 5+ で SS.NNNNNN 形式（秒.マイクロ秒）
start_us=$(printf '%s' "${EPOCHREALTIME//./}" | sed 's/^0*//')
# 万一 EPOCHREALTIME が空(bash <5)なら python フォールバック
[ -z "$start_us" ] && start_us=$(python3 -c 'import time;print(int(time.time()*1000000))')

"$HOOK_BIN" "$@"
exit_code=$?

end_us=$(printf '%s' "${EPOCHREALTIME//./}" | sed 's/^0*//')
[ -z "$end_us" ] && end_us=$(python3 -c 'import time;print(int(time.time()*1000000))')

elapsed_ms=$(( (end_us - start_us) / 1000 ))
hook_name=$(basename "$HOOK_BIN")
ts=$(date -u +%Y-%m-%dT%H:%M:%S)

printf '{"ts":"%s","hook":"%s","elapsed_ms":%d,"exit_code":%d}\n' 

  "$ts" "$hook_name" "$elapsed_ms" "$exit_code" >> "$JSONL"

exit "$exit_code"

設計上のポイントが2つあります。

① $EPOCHREALTIME で python を呼ばない。date +%s%N はLinuxでしか動かず、macOSの date はナノ秒をサポートしません。bash 5以降の組み込み変数 $EPOCHREALTIME は 1716912345.678901 形式で秒＋マイクロ秒を返します。macOS Ventura以降なら /bin/bash --version が 5.x なので標準で使えます。

② exit "$exit_code" で元のexit codeを透過する。hookがexit 2を返せばClaude Codeがブロック・エラー表示するはずですが、ラッパーが常に0を返すとその情報が消えます。計測専用のラッパーなのでhook本体の動作には一切手を加えません。

settings.json への差し込み方

既存のhookコマンドをそのままラッパーに渡すだけです。前後の構造は変えません。

json

// 変更前
{
  "type": "command",
  "command": "~/.claude/hooks/cost_guard.sh"
}

// 変更後（1行変えるだけ）
{
  "type": "command",
  "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/cost_guard.sh"
}

実際の ~/.claude/settings.json の該当部分はこうなっています。UserPromptSubmit に刺さっている3本が全てラップされています。

json

"UserPromptSubmit": [
  {
    "hooks": [
      {
        "type": "command",
        "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/user_prompt_submit.sh"
      },
      {
        "type": "command",
        "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/cost_guard.sh"
      },
      {
        "command": "~/.claude/scripts/hook-latency-wrap.sh ~/.claude/hooks/model_routing_reminder.sh",
        "type": "command"
      }
    ]
  }
]

これで毎回のhook呼び出しが ~/.claude/logs/hook-latency.jsonl に1行ずつ追記されます。

jsonl

{"ts":"2026-06-21T20:10:41","hook":"cost_guard.sh","elapsed_ms":5196,"exit_code":0}
{"ts":"2026-06-21T20:10:33","hook":"obsidian_context.sh","elapsed_ms":827,"exit_code":0}
{"ts":"2026-06-21T20:11:18","hook":"skills-auto-update.sh","elapsed_ms":45705,"exit_code":0}

集計スクリプト：hook-latency-report.sh

~/.claude/scripts/hook-latency-report.sh [days] が集計を出します。デフォルトは直近7日分です。

bash

python3 - "$JSONL" "$DAYS" <<'PY'
import sys, json, datetime, collections
log, days = sys.argv[1], int(sys.argv[2])
cutoff = datetime.datetime.now() - datetime.timedelta(days=days)

stats = collections.defaultdict(list)
fail = collections.Counter()
total_records = 0
with open(log) as f:
    for line in f:
        try:
            r = json.loads(line)
            ts = datetime.datetime.fromisoformat(r["ts"])
            if ts < cutoff:
                continue
            total_records += 1
            stats[r["hook"]].append(r["elapsed_ms"])
            if r.get("exit_code", 0) not in (0, ):
                fail[r["hook"]] += 1
        except Exception:
            continue

rows = []
for hook, vals in stats.items():
    vals_sorted = sorted(vals)
    n = len(vals_sorted)
    p95 = vals_sorted[min(n-1, int(n*0.95))]
    rows.append((hook, n, sum(vals_sorted)//n, p95, vals_sorted[-1], fail.get(hook, 0)))
rows.sort(key=lambda r: -r[3])  # p95 降順

for hook, n, mean, p95, mx, fl in rows:
    flag = " ⚠" if p95 > 1500 else ""
    print(f"{hook:<32} {n:>5} {mean:>6}ms {p95:>6}ms {mx:>6}ms {fl:>5}{flag}")
PY

p95が 1,500ms を超えたら ⚠ を表示するのが判断基準です。Claude Codeの同期hookはこの時間だけユーザーをブロックします。プロンプトを打つたびに1.5秒待たされると、体感として「重い」と感じる閾値に入ります。

:::message p95を使う理由は「平均は隠す、最大は誤魔化す」からです。平均は健全な大多数の呼び出しに引っ張られてスパイクを隠します。最大は1回の外れ値（スリープ明け・タイムアウト・ゾンビプロセス）で跳ね上がり、日常の体感と乖離します。p95は「100回に95回がこの時間以内」なので、日常の遅さを正直に示します。 :::

実測値：直近7日・29,866レコードの結果

text

=== hook latency (last 7d, 29866 records) ===
hook                                 n    mean     p95     max  fail
----------------------------------------------------------------------
skills-auto-update.sh              365  46659ms  46114ms 1073920ms     0 ⚠
cost_guard.sh                     1493    605ms   2518ms   5802ms     0 ⚠
obsidian_context.sh                728  27816ms    782ms 19636398ms     1
model_routing_reminder.sh           23    148ms    451ms    641ms     0
pre_secrets_check.sh              2642     90ms    235ms   5561ms     0
user_prompt_submit.sh             1494     73ms    210ms    997ms     0
pre_env_guard.sh                  2642     59ms    154ms   4754ms     0
pre_git_guard.sh                  5726     43ms    117ms   2665ms     2
message_display_filter.sh        14753     47ms     96ms   5859ms     0

⚠️ が立っているのは2本です。実態はそれぞれ異なります。

skills-auto-update.sh (p95: 46秒)：SessionStartで毎回45秒かけてスキルリストをgit pullしています。一見致命的ですが、settings.json に "async": true を付けているため Claude Codeをブロックしません。非同期フラグが付いたhookは結果を待たずにセッションが開始します。問題はないが、asyncフラグがなければ起動のたびに45秒固まっていたはずです。

cost_guard.sh (p95: 2,518ms)：こちらは UserPromptSubmit の同期hookです。プロンプトを打つたびにccusageを呼んでプラン枠を確認しています。p95で2.5秒、最大5.8秒のブロックが毎ターン発生しています。感覚と一致します ―― プロンプトを送ってから応答が始まるまでの謎の2〜3秒の正体がこれでした。

obsidian_context.sh の平均が壊れている：meanが27,816ms（27秒！）なのにp95が782msという矛盾は、macのスリープ中にhookがゾンビとして生き残り、スリープ明けにまとめて記録されたレコードが混じっているためです。exitcodeが1になっているレコードも1件あり、スリープ明けの失敗と一致します。meanは使えません。p95が782msでasync: falseなので、SessionStart時に確かに待ちが入っていますが許容範囲です。

踏んだ落とし穴

$EPOCHREALTIME の小数点を除去するとき先頭ゼロが残る → sed 's/^0*//' を挟まないと整数変換でシェルがエラーになる
bash 4系（macOSのデフォルト /bin/bash）では $EPOCHREALTIME が空 → brew install bash で 5系を入れるか python3 フォールバックに任せる。フォールバックが効いているか echo "${BASH_VERSION}" で確認
asyncフラグ付きhookをラップしても計測できない → async: true のhookはClaude Codeが子プロセスとしてforkしたまま待たないため、elapsed_msはJSONLに正しく書かれる。ただしそのhookのブロック時間はゼロなので集計上⚠️が出ても運用上は無害
meanが壊れてもp95は正常 → スリープ中のゾンビレコードがmeanを押し上げても、p95は95パーセンタイル位置を動かすほどの量にはならない。meanを信じず常にp95を見る
exit codeを透過しないと事故る → ラッパーが常に exit 0 を返すと、pre_git_guard.sh がブロックしても通過してしまう。exit "$exit_code" で元のコードを返すのは必須
JSONLが5.8MBに育つ → 7日・29,866レコードでこのサイズ。ローテーションなしだと半年で100MB超になる。logrotateかlaunchdの定期trimが必要

まとめ

hook-latency-wrap.sh でhookをラップ → ~/.claude/logs/hook-latency.jsonl に実行時間を記録
hook-latency-report.sh でhook名ごとのcount/mean/p95/maxを集計、p95 > 1500ms で⚠️
実測で判明したこと：skills-auto-update.sh は46秒かかるが async: true なのでブロックしない。cost_guard.sh はp95 2.5秒の同期ブロックが毎ターン発生していた
meanは外れ値（ゾンビプロセス・スリープ明け）で壊れる。p95が実体に近い
asyncフラグの有無がhookの「重さの意味」を変える。計測の前にasync/syncを確認する

次回は、このJSONLをもとに cost_guard.sh を非同期化した話 ―― 同期hookを非同期に切り替えるトレードオフと、非同期でも「ブロック前に必ず確認したいこと」をどう担保するかを書きます。

Lily（@bokuwalily）― 個人開発者。Claude Code で自動化基盤を組みながら、iOSアプリやWebサービスを量産しています
◼︎作ったアプリは **ポートフォリオ** にまとめています📱
◼︎新着・開発の裏側は X **@bokuwalily** で発信しています🐦
◼︎OSS: **github.com/bokuwalily**🐙
皆さんの ❤️ やシェアが励みになります！