# 12 Pitfalls I Hit Auto-Logging Claude Code Subagents with a Stop Hook (and How the Numbers Cut My Weekly Cost 15–20%)

> Source: <https://dev.to/bokuwalily/12-pitfalls-i-hit-auto-logging-claude-code-subagents-with-a-stop-hook-and-how-the-numbers-cut-my-n81>
> Published: 2026-09-11 00:00:06+00:00

I had a gut feeling that my `general-purpose` subagent was the slow one. Then I measured it: 18 seconds on average, faster than `Explore` at 22. The real drag was `code-reviewer` at 37 seconds. Changing one habit based on that number dropped my weekly Claude Code spend by roughly 15–20%.

I made a couple hundred thousand yen a month as a student juggling side gigs, got laid off and went back to zero, and spent six months building an autonomous Claude Code setup that now runs at about ¥1.2M in monthly revenue. The foundation of that setup is post-session log collection driven by a Stop hook. This post covers the implementation, the 12 pitfalls I hit along the way, and the `jq` recipes I use every week.

After using Claude Code for a while, a nagging feeling sets in: "I have no idea where the cost is going." You mix Explore agents, code-reviewer agents, general-purpose agents, and before you know it a session has been running for tens of minutes. But which agent is slow? Which one errors most often? I had never seen a number.

Saying "that agent feels heavy" is not data. Without data, you can't tell what to fix. For someone shipping systems solo at volume, that's a fatal blind spot. Optimizing a workflow starts with measuring it.

Claude Code ships with a mechanism that lets you automate that measurement: the **Stop hook**.

A Stop hook is a shell script that runs every time a Claude Code session ends. The hook receives a `transcript_path` — the path to the raw JSONL conversation log for the entire session, including tool calls, agent launches, and response timestamps. In other words, every time a session ends, you automatically get a chance to read "everything that happened in this session."

Once I noticed that, my thinking changed. There's no need to keep records by hand. Trigger a script on session end, parse `transcript_path`, and write a list of subagent invocations out to JSONL. That alone accumulates "which agent took how many seconds, and did it succeed or fail."

Then aggregate the ledger with `jq`, and you move from gut feelings to a conversation about numbers.

One more important point: this approach touches nothing in Claude Code itself. A Stop hook is enabled by adding a single line to `~/.claude/settings.json`. It doesn't change the original behavior; it just piggybacks on an existing event, session end. Near-zero side effects is a big advantage when you're maintaining a high-volume environment.

Of the JSON the Stop hook receives, two fields matter.

```
{
  "session_id": "...",
  "transcript_path": "/path/to/transcript.jsonl"
}
```

The file at `transcript_path` contains every message exchanged in the session in JSONL format (one JSON object per line). Inside each line's `message.content`, you'll find `"type": "tool_use"` blocks representing tool calls.

Subagent launches are recorded here as `"name": "Agent"`. Note that even though Claude Code's UI displays "Task", the tool name in the transcript is `"Agent"` (the script's comment spells this out: "In Claude Code transcripts, the 'Task' tool is recorded as name="Agent""). The `subagent_type` lives in `input.subagent_type`.

The result of an agent call appears on a separate line as `"type": "tool_result"`, linked to the call via `tool_use_id`. If `is_error: true` is present, it ended in error; otherwise, it succeeded.

Once you understand this structure, a two-pass Python script is all it takes to extract subagent execution records.

Here's the whole system as a diagram.

```
 Claude Codeセッション
 ┌─────────────────────────────────────────────────┐
 │ tool_use (name="Agent", subagent_type="Explore") │
 │     ...処理中...                                  │
 │ tool_result (tool_use_id=xxx, is_error=false)    │
 └─────────────────────────────────────────────────┘
              ↓ セッション終了 (Stop イベント)
 ┌─────────────────────────────────────────────────┐
 │ Stop hook: stop_agent_tracker.sh                 │
 │   stdin: {"session_id", "transcript_path", ...}  │
 └─────────────────────────────────────────────────┘
              ↓ transcript_path を読み込む
 ┌─────────────────────────────────────────────────┐
 │ Python: 2パス解析                                 │
 │   Pass1: uses{} / results{} を構築               │
 │   Pass2: tool_use_id で突き合わせ・duration算出   │
 └─────────────────────────────────────────────────┘
              ↓ 追記
 ~/.claude/logs/agent-invocations.jsonl
```

When the Stop hook fires, it receives JSON on `stdin`, and a Python script reads the transcript using the `transcript_path` inside it. The output destination is fixed: `~/.claude/logs/agent-invocations.jsonl`.

The script is almost entirely Python. The shell portion only handles passing environment variables.

```
INPUT=$(cat)           # stdin から Stop イベント JSON を受け取る
export STOP_INPUT="$INPUT"
export OUT_LOG_PATH="$OUT_LOG"    # ~/.claude/logs/agent-invocations.jsonl
```

The Python portion is split into three main blocks.

**Deduplication block**

If the Stop hook runs multiple times for the same session (which can happen by Claude Code's design), we don't want to write the same entry twice. So we read the existing log and load `session_id` + `tool_use_id` combinations into a `seen_ids` set.

```
seen_ids = set()
if os.path.exists(out_path):
    with open(out_path, "r", ...) as f:
        for line in f:
            r = json.loads(line)
            if r.get("session_id") == sid and r.get("tool_use_id"):
                seen_ids.add(r["tool_use_id"])
```

**Pass 1: build the index**

Read the transcript line by line. `tool_use` blocks with `"name": "Agent"` and a `subagent_type` go into the `uses` dict; `tool_result` blocks go into the `results` dict.

``` php
uses = {}    # tool_use_id -> (ts, name, input, caller)
results = {} # tool_use_id -> (ts, is_error)

for b in content:
    if b.get("type") == "tool_use" and b.get("name") == "Agent":
        inp = b.get("input") or {}
        if "subagent_type" not in inp:
            continue
        uses[uid] = (ts, b.get("name"), inp, b.get("caller"))
    elif b.get("type") == "tool_result":
        results[rid] = (ts, bool(b.get("is_error")))
```

Agent calls without a `subagent_type` are skipped. This check exists to exclude invocations of the main Claude agent itself.

**Pass 2: match and write**

Iterate over `uses`, and if a matching `results` entry exists, compute `duration_ms` and write it out.

```
t0 = parse_ts(use_ts)    # tool_use のタイムスタンプ
t1 = parse_ts(res_ts)    # tool_result のタイムスタンプ
if t0 and t1:
    duration_ms = int((t1 - t0).total_seconds() * 1000)
```

Entries whose result hasn't come back yet are recorded with `"status": "pending"`.

The `description` field is truncated at 300 characters. This keeps the log file size under control even when the instructions given to an agent are long.

```
if len(description) > 300:
    description = description[:300] + "…"
```

A single line of the resulting JSONL looks like this.

```
{
  "ts": "2026-09-10T08:30:00Z",
  "session_id": "abc123",
  "cwd": "~/dev/my-project",
  "tool_use_id": "toolu_01Xyz...",
  "subagent_type": "Explore",
  "description": "Find all TypeScript files that reference the Auth module…",
  "duration_ms": 18420,
  "status": "ok",
  "caller": null
}
```

To summarize the fields: `subagent_type` is the agent kind, `duration_ms` is the execution time in milliseconds, and `status` is one of `"ok"` / `"error"` / `"pending"`. `caller` holds information about the caller, but it's `null` most of the time.

When you read a `tool_use` in a single pass, the matching `tool_result` may not have appeared yet. JSONL is in chronological order, but during a long agent run, other messages can be interleaved. Reading every line first to build an index and matching afterward — the two-pass structure — guarantees you get the pairs.

Also, when the `parse_ts` function converts ISO 8601 timestamps to `datetime` objects, it replaces the trailing `Z` with `+00:00` before passing to `fromisoformat`.

``` python
def parse_ts(s):
    try:
        return datetime.datetime.fromisoformat(s.replace("Z", "+00:00"))
    except Exception:
        return None
```

Python's `fromisoformat` can't parse the `Z` suffix directly before 3.11, so this conversion is required.

The script opens the file in `"a"` (append) mode. Each session adds new records to the end. If the file doesn't exist, it's created automatically (guaranteed by `mkdir -p` on `LOG_DIR`).

Because data accumulates across sessions, after days or weeks of use, patterns emerge: "the Explore agent always takes over 20 seconds," "the code-reviewer agent errors out occasionally."

Running alongside `stop_agent_tracker.sh` is `stop_cost_log.sh`. This one records the tokens consumed in a session and the estimated cost to `~/.claude/logs/cost-log.jsonl`. Alongside agent slowness, knowing "when, in which session, and how much it cost" is essential for keeping a high-volume environment running.

The rate table is implemented like this.

```
PRICING = {
    "claude-opus-4-7":   {"input": 15.0, "output": 75.0, "cache_read": 1.5,  "cache_create_5m": 18.75, "cache_create_1h": 30.0},
    "claude-sonnet-4-6": {"input": 3.0,  "output": 15.0, "cache_read": 0.3,  "cache_create_5m": 3.75,  "cache_create_1h": 6.0},
    "claude-haiku-4-5":  {"input": 1.0,  "output": 5.0,  "cache_read": 0.1,  "cache_create_5m": 1.25,  "cache_create_1h": 2.0},
}
DEFAULT_RATE = PRICING["claude-sonnet-4-6"]

def rate_for(model: str):
    for k, v in PRICING.items():
        if model.startswith(k):
            return v
    return DEFAULT_RATE
```

The key point is that dictionary keys are matched by prefix (`startswith`) rather than exact match. Model names Claude Code writes to the transcript can carry a release-date suffix, like `claude-sonnet-4-6-20250620`. With exact matching, you'd have to rewrite PRICING every time a minor version updates. Prefix matching absorbs suffix changes. Unknown models fall back to `DEFAULT_RATE` (Sonnet-equivalent), so aggregation doesn't stop when a model not in the table shows up.

The Anthropic API has two kinds of cache: a 5-minute ephemeral cache and a 1-hour cache, priced differently (roughly a 1:1.6 ratio). The script tallies them separately.

```
cc_5m = (usage.get("cache_creation", {}) or {}).get("ephemeral_5m_input_tokens", 0) or 0
cc_1h = (usage.get("cache_creation", {}) or {}).get("ephemeral_1h_input_tokens", 0) or 0
if cc_5m + cc_1h == 0 and cc_total > 0:
    cc_5m = cc_total
```

The last three lines are a consistency check. In older Claude Code versions or under certain conditions, the nested `cache_creation` object doesn't exist and only a flat `cache_creation_input_tokens` is returned. That yields `cc_5m + cc_1h == 0` with `cc_total > 0`, so the full amount is treated as the 5-minute tier. Since the 5-minute tier is cheaper, this biases toward underestimating cost. I decided that's easier to reason about than overestimating.

```
cost_usd += (
    inp / 1_000_000 * r["input"]
    + out / 1_000_000 * r["output"]
    + cr / 1_000_000 * r["cache_read"]
    + cc_5m / 1_000_000 * r["cache_create_5m"]
    + cc_1h / 1_000_000 * r["cache_create_1h"]
)
```

The unit is "$/MTok" (dollars per million tokens), so the token count is divided by `1_000_000` before multiplying. The `_`-separated numeric literals are for readability and work on Python 3.6+. The script walks every message in the session, accumulates `cost_usd`, and finally rounds to four decimal places with `round(cost_usd, 4)`.

Once the log builds up, you can ask it questions with `jq`. All of the following are real queries against `~/.claude/logs/agent-invocations.jsonl`.

**Average and max execution time per agent type**

```
jq -s '
  group_by(.subagent_type) |
  map({
    type: .[0].subagent_type,
    count: length,
    avg_ms: (map(select(.duration_ms != null) | .duration_ms) | add / length | round),
    max_ms: (map(select(.duration_ms != null) | .duration_ms) | max)
  }) | sort_by(-.avg_ms)
' ~/.claude/logs/agent-invocations.jsonl
```

`group_by` buckets by type, then `avg_ms` and `max_ms` are computed and sorted descending. When I actually ran this, my environment showed the Explore agent averaging around 22 seconds, code-reviewer averaging 37 seconds, and general-purpose averaging 18 seconds. code-reviewer is slow because it reads multiple files — and once that was confirmed by numbers, my hunch that "using code-reviewer for multi-file checks is heavy" finally had backing.

**Identify agents with high error rates**

```
jq -s '
  group_by(.subagent_type) |
  map({
    type: .[0].subagent_type,
    total: length,
    errors: map(select(.status == "error")) | length,
    error_rate: ((map(select(.status == "error")) | length) / length * 100 | round)
  }) | sort_by(-.error_rate)
' ~/.claude/logs/agent-invocations.jsonl
```

**Sum cost for a specific project (cwd)**

```
jq -s '
  map(select(.cwd | contains("my-project"))) |
  { total_cost: (map(.cost_usd) | add) }
' ~/.claude/logs/cost-log.jsonl
```

The cost log also has a `cwd` field, so you can filter by project path and get a total. Once you can see how much you've spent on which project at a glance, your sense of profitability changes.

I hit four concrete snags before the implementation was done. All of them were the "why doesn't this work?" kind of bug, where the symptom alone hides the cause.

In the first version, I wired shell and Python together like this.

```
cat | python3 - <<'PY'
data = json.load(sys.stdin)  # ← ここで空が返ってくる
PY
```

The misconception: "the heredoc Python script itself is passed via stdin, so I can read input from `sys.stdin`." In reality, `<<'PY'` occupies stdin as far as the shell is concerned, so by the time the script runs, `sys.stdin` is already at EOF. Even if `cat` receives the Stop hook JSON, there's no route for it to reach Python.

The fix is simple: "store it in a shell variable first, then pass it as an environment variable."

```
INPUT=$(cat)
export STOP_INPUT="$INPUT"

python3 - <<'PY'
data = json.loads(os.environ.get("STOP_INPUT", ""))
PY
```

`INPUT=$(cat)` reads the Stop hook JSON, and `export` turns it into an environment variable. Inside the heredoc Python, read it from `os.environ`. This detour avoids the stdin conflict. The real script takes this shape precisely because of this history.

`fromisoformat` chokes on Z
Transcript timestamps come in the form `"2026-09-10T08:30:00Z"`. At first I naively wrote `datetime.fromisoformat(ts)`.

```
# Python 3.10以前ではこれが ValueError になる
datetime.datetime.fromisoformat("2026-09-10T08:30:00Z")
```

macOS's system Python was 3.10, so this one line threw `ValueError` and the script died. I hadn't written a `try/except`, so the entire Stop hook exited with an error and no logs were written for several days. I had no idea why logs weren't being generated, and only found the cause after enabling debug logging with `CC_AGENT_TRACKER_DEBUG=1`.

The fix lives inside the `parse_ts` function.

``` python
def parse_ts(s):
    if not s:
        return None
    try:
        return datetime.datetime.fromisoformat(s.replace("Z", "+00:00"))
    except Exception:
        return None
```

Replace `Z` with `+00:00` before passing it in, and it works on Python 3.7+. It's also wrapped in `try/except`, so an unexpected format returns `None` instead of killing the script. The `duration_ms` computation only runs "when both t0 and t1 are not None," so entries that returned `None` are recorded with `duration_ms: null`. Give up on the calculation, but keep the record.

A few days after enabling the Stop hook, I found duplicate entries with the same `tool_use_id` in the log. For example, after a session that ran for three hours, `agent-invocations.jsonl` had two lines with the same ID.

Claude Code can emit the session end event more than once under certain conditions (such as when a subprocess's exit overlaps with the main session's exit). So the Stop hook ran twice for the same session, and the second run read the same transcript and wrote the same records.

The countermeasure was to add a dedup block at the top: "collect the tool_use_ids already written for this session into a set, and skip them next time."

```
seen_ids = set()
if os.path.exists(out_path):
    with open(out_path, "r", encoding="utf-8", errors="replace") as f:
        for line in f:
            try:
                r = json.loads(line)
                if r.get("session_id") == sid and r.get("tool_use_id"):
                    seen_ids.add(r["tool_use_id"])
            except Exception:
                continue
```

At write time, the check looks like this.

```
for uid, (use_ts, _, inp, caller) in uses.items():
    if uid in seen_ids:
        continue  # 既に記録済みならスキップ
```

Identity is determined by the `session_id` + `tool_use_id` combination because the probability of the same `tool_use_id` colliding across sessions isn't zero (they're UUIDs, so it's extremely low, but just in case). Reading only records with the same `session_id`, rather than the entire log, is a performance consideration.

`name="Task"` returns nothing
When I first investigated the transcript structure, the Claude Code interface showed "Task", so I wrote the script the same way.

```
if btype == "tool_use" and b.get("name") == "Task":
```

Running this logged nothing. When I removed the filter for debugging and dumped every `tool_use`, I discovered the actual transcript records it as `"name": "Agent"`.

The UI display name and the tool name in the transcript don't match. It's an internal naming asymmetry in Claude Code that isn't documented. The comment in the real script — "In Claude Code transcripts, the 'Task' tool is recorded as name="Agent"" — exists because of this experience. I left it in the first place anyone would look so nobody falls into the same trap.

The correct filter is a combination of two conditions.

```
if btype == "tool_use" and b.get("name") == "Agent":
    inp = b.get("input") or {}
    if "subagent_type" not in inp:
        continue
```

Only lines where `name == "Agent"` and `input` contains `subagent_type` are targeted. `Agent` calls without a `subagent_type` can be entries for the main Claude session itself, and the two-stage filter exists to exclude those.

`set -e` dies silently and no logs remain at all
The initial shell header was `set -euo pipefail`. `-e` makes the entire shell exit immediately when a command returns non-zero.

The problem arose when running in a "session with no transcript." Claude Code's lightweight sessions (ask a short question and exit) sometimes don't generate a transcript. In that case `os.path.exists(tp)` returns `False` and Python exits with `sys.exit(0)`, but there's also a path where the earlier `[ -z "$INPUT" ] && exit 0` exits the shell normally. With `-e` enabled, depending on how the `&&` evaluates, the script could stop unintentionally.

Also, calling `sys.exit(0)` inside the Python script is a normal exit (code 0) and fine, but in some environments the `python3` command itself can't be found (not on `PATH`), returning exit code 127, and `-e` would stop the shell and skip all subsequent processing.

The fix is to drop `-e` and use `-uo pipefail`.

```
set -uo pipefail
```

`-u` makes access to undefined variables an immediate error. `pipefail` makes the whole pipeline fail if any stage errors. `-e` is removed. The principle for a hook script is "even if I fall over, don't affect Claude Code's behavior," so bailing out proactively with `exit 0` is safer. Errors are written to `DEBUG_LOG` (`~/.claude/logs/stop_agent_tracker.log`), so I prioritized having the cause visible in the debug log over dying silently under `-e`.

That covers the implementation details and the record of failures. The next part deals with how to fold these logs into daily operations, concrete examples of numbers changing, and a practical collection of `jq` recipes.

The previous part covered five snags, but once you're in real operation, there are more. Listed in order of frequency.

**⑥ `python3` isn't found and the hook exits silently**

When Claude Code is launched from the GUI, it doesn't load the login shell and only has a minimal PATH, roughly `/usr/bin:/bin`. `~/.pyenv/shims/python3` and `~/.nvm/versions/.../bin/python3` aren't on it. The symptom: "the hook is registered but no log ever appears." With `set -uo pipefail` (no `-e`), the subsequent script keeps running after a 127, but the output file stays empty. Two countermeasures: write `export PATH="/usr/local/bin:/usr/bin:$HOME/.pyenv/shims:$PATH"` at the top of the script, or pin the full path `/usr/bin/python3` instead of `/usr/bin/env python3`. On macOS Ventura and later, Xcode Command Line Tools provide `/usr/bin/python3`, so if a system Python exists, the latter is the safest.

**⑦ Some messages have `content` as a `string` rather than a `list`**

Most messages in transcript.jsonl have `content` as a list, but a handful of system messages have `content` as a string. Trying `for b in content` on those iterates character by character. The real script has a guard, `if not isinstance(content, list): continue` (lines 94–96), but if you modify the script yourself and delete that line, it breaks. Checking whether `content` is a `list` on every line is an ironclad rule.

**⑧ `jq -s` on tens of thousands of JSONL lines runs out of memory**

`jq -s` reads the entire file into memory before processing. Once `agent-invocations.jsonl` exceeds tens of thousands of lines, a query eats several hundred MB of your Mac's memory. At a few hundred sessions a month, you get there in 3–4 months. The solution is the `--stream` option, or periodic archiving. I move logs monthly into `~/logs/archive/agent-YYYY-MM.jsonl` and keep only the last 30 days in `agent-invocations.jsonl`.

```
  # 月次ローテーション（launchdで自動実行）
  MONTH=$(date -v-1m +%Y-%m)
  jq -c 'select(.ts | startswith("'"$MONTH"'"))' \
      ~/.claude/logs/agent-invocations.jsonl \
      >> ~/.claude/logs/archive/agent-${MONTH}.jsonl
```

**⑨ `status: "pending"` entries pile up**

If Claude Code is force-quit while a subagent is running (⌘Q, OS shutdown, OOM kill), the transcript ends without a `tool_result` being written. When the Stop hook runs in this state, no matching `results` exist, so the entry is recorded with `status: "pending"`. That's correct behavior in itself, but once dozens of `pending` entries accumulate per month, average execution time aggregates get skewed (you need to filter `duration_ms: null` entries with `select(.duration_ms != null)`). Always adding `select(.status == "ok")` to monthly aggregate queries is the safe move.

**⑩ The dedup block gets slow on a huge log**

The dedup check at session start reads every line of the existing log looking for records whose `session_id` matches (lines 58–69). Once the log exceeds 100,000 lines, the hook takes several seconds per session. Two practical countermeasures. First, partition the JSONL by session date. Second, limit the `seen_ids` read to "only the last N lines" (entries from the same session aren't guaranteed to be contiguous, so it's not a complete fix, but it's a realistic compromise).

**⑪ Real paths land in `cwd` and you can't publish the script**

The JSONL `stop_agent_tracker.sh` outputs contains `"cwd": "/Users/realname/dev/my-project"`. Forget to add this log to `.gitignore`, commit it to a repository, and your home directory's absolute path leaks. `~/.claude/logs/` sits outside any repo, so that's fine, but when handing logs to an analysis script, people sometimes push the whole log file to a gist or a shared folder. Either process it with `jq 'del(.cwd)'` before sharing, or add a preprocessing step that reduces the `cwd` field to just the directory name (`basename`).

**⑫ Burning days without knowing how to enable debug logging**

`stop_agent_tracker.sh` implements an environment variable switch, `CC_AGENT_TRACKER_DEBUG=1` (line 31). Set it to `1` and detailed logs are written to `~/.claude/logs/stop_agent_tracker.log`. `stop_cost_log.sh` does the same with `CC_COST_DEBUG=1`, writing to `~/.claude/logs/stop_cost_log.log`. The first step to confirming whether a hook is running is `tail -f ~/.claude/logs/stop_agent_tracker.log`. I personally burned days in a "can't figure out why no logs appear" state without knowing this. After setting up hooks in a new environment, running one session in debug mode to confirm it works is a mandatory step.

Here are the rules that solidified through implementation and operation.

**1. Hook scripts always end with `exit 0`**

If a Stop hook exits non-zero, Claude Code may show a warning at the next session start. Even if something goes wrong inside the script, the ironclad design is: write it to the log and bail out with `exit 0`. Removing `set -e` is for the same reason. Keep hook failures from spilling into Claude Code's own behavior.

**2. Receive stdin on the first line with `INPUT=$(cat)` and repack it into an environment variable**

There's no way to pass stdin to a heredoc Python script. Always use the `INPUT=$(cat) → export STOP_INPUT → os.environ` route. This is the direct lesson from pitfall ①. As long as you keep this shape, input will arrive no matter how much you modify the Python code.

**3. Wrap the Python code in one big `try/except`, and write exceptions to the debug log instead of swallowing them**

```
try:
    # メイン処理
    ...
except Exception as e:
    log(f"unexpected_error: {e}")
sys.exit(0)
```

Even if an exception occurs, it exits normally via `sys.exit(0)`. It's in the log. Claude Code is unaffected. The structure above achieves all three at once.

**4. Confine timestamp handling to a `parse_ts` function that returns None**

As the `fromisoformat` `Z` problem (pitfall ②) illustrates, timestamp processing is full of environment-dependent edge cases. Always isolate conversion in a dedicated function and return `None` on failure. If the `duration_ms` computation is conditioned on "only when both t0 and t1 are not None," `None` never causes a TypeError.

**5. Add deduplication from the start. Add it later and you can't clean the existing log**

Pitfall ③ (multiple Stop hook invocations) shows up days later as "why are there two lines of the same entry?" By then duplicates are buried in the existing log, and `sort -u` won't work as-is because JSONL key order isn't deterministic. The rule is to include dedup logic from the initial implementation. The cost is just "one pass reading the existing log."

**6. Always include `select(.duration_ms != null)` and `select(.status == "ok")` in `jq` queries**

Averages that include `pending` entries (`duration_ms: null`) get pulled toward zero. Add those two conditions as the default in aggregate queries, and you get accurate numbers based only on valid data.

```
jq -s '
  map(select(.duration_ms != null and .status == "ok")) |
  group_by(.subagent_type) |
  map({type: .[0].subagent_type, avg_ms: (map(.duration_ms) | add / length | round)})
' ~/.claude/logs/agent-invocations.jsonl
```

**7. Archive log files monthly and keep the live file light**

When `agent-invocations.jsonl` grows, the dedup pass slows down (pitfall ⑩) and `jq -s` eats memory (pitfall ⑧). Set up a monthly launchd archive job from the start and these problems never occur. In practice, most people archive once they notice "the log got heavy," but putting it in from the beginning makes operation easier.

**8. Look up the PRICING table by prefix, not exact match**

The `rate_for` implementation in `stop_cost_log.sh` is the best practice as-is. Looking up keys with `model.startswith(k)` absorbs variation in model names with release-date suffixes, like `claude-sonnet-4-6-20250620`. Unknown models fall back to Sonnet-equivalent, so aggregation doesn't stop when a model not in the table appears.

**9. After configuring a hook, always run one full session in debug mode to confirm**

```
# ~/.claude/settings.json に追加（既存のhooksブロックに追記）
CC_AGENT_TRACKER_DEBUG=1 claude  # ← デバッグモードで起動
tail -f ~/.claude/logs/stop_agent_tracker.log  # 別ターミナルで監視
```

"Configured" and "working" are different things. Actually run a session and confirm the log appears before turning debug mode off.

**10. Don't filter on `subagent_type` alone; check for the existence of `input.subagent_type`**

This is the counterpart to pitfall ④ (the `name="Task"` problem). `name == "Agent"` alone may match entries other than subagent calls. Always include the second-stage filter `"subagent_type" in inp`. That's how the real script is designed.

**11. Use the `cwd` field to aggregate per project**

Both `cost-log.jsonl` and `agent-invocations.jsonl` contain `cwd`. To get time and cost per project, this jq is enough.

```
# プロジェクト別コスト
jq -rsc '
  group_by(.cwd) |
  map({cwd: .[0].cwd, cost_usd: (map(.cost_usd) | add | . * 10000 | round / 10000)}) |
  sort_by(-.cost_usd)[] |
  "\(.cost_usd) USD  \(.cwd)"
' ~/.claude/logs/cost-log.jsonl
```

Once you can see how much Claude Code you're using on which project, your sense of profitability changes.

**12. Multiple Stop hooks can be registered and run independently**

`hooks.Stop` in `~/.claude/settings.json` is an array and accepts multiple entries. That's why `stop_agent_tracker.sh` and `stop_cost_log.sh` are registered separately. If one fails, the other still runs. Splitting scripts by role lets you fix and swap them independently.

**13. Build the habit of looking at the numbers weekly**

Accumulated logs mean nothing if you don't look at them. I run the `ccstats` alias every Monday morning.

```
alias ccstats='
  echo "=== エージェント平均時間（直近7日） ===";
  jq -sc "map(select(.status==\"ok\" and .duration_ms != null)) |
    group_by(.subagent_type) |
    map({type:.[0].subagent_type, avg_ms:(map(.duration_ms)|add/length|round)}) |
    sort_by(-.avg_ms)[]" \
    ~/.claude/logs/agent-invocations.jsonl;
  echo "=== 週間コスト ===";
  jq -sc "map(.cost_usd) | add | . * 100 | round / 100" \
    ~/.claude/logs/cost-log.jsonl
'
```

After looking at these numbers, I can decide things like "cut back on code-reviewer calls this week" or "switch this project from Explore to Grep." Moving from gut feeling to number-based decisions is the real purpose of this system.

Claude Code's Stop hook lets you automate log collection just by piggybacking on an existing event: session end. Receive `transcript_path`, process it in two passes with Python, and append to `agent-invocations.jsonl`. The heart of this design is "change nothing in Claude Code itself." Even if the hook fails, it bails out with `exit 0`, so nothing spills into the main behavior. Because the side effects are near zero, you can leave it in a high-volume environment with confidence.

What the numbers actually showed me is that the agent I *felt* was heavy and the agent the *data* said was heavy weren't necessarily the same. In my environment, general-purpose felt heavy, but measured at an average of 18 seconds, it was faster than Explore (22 seconds). After seeing code-reviewer's 37 seconds, I developed the habit of "narrow down with Grep before reaching for code-reviewer on multi-file checks," and my weekly cost dropped by a felt 15–20%.

That change would not have happened without measurement.

A hook script quietly running at every session end keeps nudging up the precision of the autonomous environment behind ¥1.2M a month.

Which of your subagents do you *think* is the slow one — and have you ever actually measured it?

The full picture of the setup, the breakdown of the ¥1.2M/month, and a 30-day walkthrough are collected in a paid note (Japanese).

*Written by **Lily** — I ship iOS apps and automate my content stack with Claude Code.

Follow along: [Portfolio](https://bokuwalily.com) · [X](https://x.com/bokuwalily) · [GitHub](https://github.com/bokuwalily)*