Skip to content

fix(hooks): record_hook_timing and HookTimer are defined but never called — hook timing stats are dead code #1494

@JeremyDev87

Description

@JeremyDev87

Problem

The CodingBuddy plugin has two hook-timing facilities — both fully implemented, both fully tested, both never invoked by any actual hook. As a result:

  1. The Stop hook summary never shows the `⏱ PreToolUse:Xms PostToolUse:Yms` timing report that `SessionStats.format_summary()` is wired to emit.
  2. Every `PostToolUse` / `PreToolUse` / `SessionStart` / `Stop` script runs without measuring its own runtime, so the project has zero data on hook performance even though the data structures exist.

Affected code

Facility 1 — `SessionStats.record_hook_timing`

File: `packages/claude-code-plugin/hooks/lib/stats.py`

```python
def record_hook_timing(self, hook_name: str, elapsed_ms: float) -> None:
"""Record a hook execution timing in memory."""
if hook_name not in self._mem_hook_timings:
self._mem_hook_timings[hook_name] = []
self._mem_hook_timings[hook_name].append(elapsed_ms)
self._pending_count += 1
```

Search proves this method is never called by hook code:

```bash
cd packages/claude-code-plugin
rg -n 'record_hook_timing' hooks/

Only match: hooks/lib/stats.py — the definition itself.

```

`format_summary()` already consumes `hook_timings` and produces a `⏱` line; `finalize()` already computes `hook_timing_stats` (count, avg_ms, p95_ms, max_ms). There is just no producer.

Facility 2 — `HookTimer` class

File: `packages/claude-code-plugin/hooks/lib/hook_timer.py`

A complete `HookTimer` class with `start()`, `stop()`, `get_stats()`, `get_warnings()` exists. It is also never imported by any hook:

```bash
cd packages/claude-code-plugin
rg -n 'HookTimer|hook_timer' hooks/

Only match: hooks/lib/hook_timer.py — the definition itself.

```

Why this matters

  • The whole purpose of feat: Adaptive hook timeout — track execution time and suggest adjustments #945 (per the docstrings) was "adaptive hook timeout tracking" + "warnings for hooks approaching their timeout threshold". Today neither happens because no hook actually times itself.
  • The `format_summary()` Stop hook output is missing a feature users would benefit from: knowing whether their hooks are getting slow.
  • The presence of two parallel facilities (`SessionStats.record_hook_timing` and `HookTimer`) is confusing — one of them should be deleted, the other wired up.

Recommended approach

Step 1 — Decide which facility to keep

Facility Strengths Weaknesses
`SessionStats.record_hook_timing` Persists across processes (disk-backed); already consumed by `format_summary`/`finalize` Adds disk I/O to every hook
`HookTimer` In-memory only, no I/O cost Per-process only, dies with the process — useless for short-lived hooks

Recommendation: keep `SessionStats.record_hook_timing` (cross-process is the only model that makes sense for short-lived hook processes), delete `hook_timer.py` and its tests. `HookTimer` cannot work for the actual deployment topology.

Step 2 — Wire it up

For each hook script in `packages/claude-code-plugin/hooks/` (`pre-tool-use.py`, `post-tool-use.py`, `session-start.py`, `stop.py`, `user-prompt-submit.py`):

  1. Capture `time.monotonic()` at the very top of the handler.
  2. In a `finally:` block (so it runs even on early exit), compute `elapsed_ms = (time.monotonic() - start) * 1000`.
  3. Call `SessionStats(session_id=...).record_hook_timing(hook_name, elapsed_ms)` followed by `stats.flush()` (same short-lived-process pattern as fix(hooks): persist tool stats from short-lived hook processes #1492).

Hook name should match the Claude Code hook event name exactly: `PreToolUse`, `PostToolUse`, `SessionStart`, `Stop`, `UserPromptSubmit`.

Step 3 — Verify the Stop summary now includes timings

After this change, a session that calls a few tools should produce a Stop hook summary like:

```
[CB] 3m | 12 tools | 0 errors | Bash:5 Edit:3 Read:4 | ⏱ PostToolUse:42ms PreToolUse:8ms Stop:120ms
```

The `⏱` segment is what proves the producer is now wired.

Acceptance criteria

  • `packages/claude-code-plugin/hooks/lib/hook_timer.py` and its tests deleted (or alternatively, decide and document why `HookTimer` should stay alongside `record_hook_timing`).
  • Each hook script in `packages/claude-code-plugin/hooks/*.py` measures its own elapsed time and calls `SessionStats.record_hook_timing(hook_name, elapsed_ms)` followed by `flush()` in a `finally` block.
  • Hook timing recording must NOT raise — exceptions in this path swallowed (matching the existing `# Never block tool execution` pattern in those hooks).
  • New regression test in `packages/claude-code-plugin/tests/` that:
    • Imports the post-tool-use handler module
    • Invokes its handler with a fake event
    • Asserts the on-disk `hook_timings["PostToolUse"]` list has at least one entry
  • Manual verification: in a real Claude Code session, the Stop summary contains the `⏱` segment with at least one hook name and a non-zero ms value.
  • Existing `TestHookTimingIntegration` tests in `tests/test_stats.py` still pass.

Reproduction (current dead-code state)

```bash
cd packages/claude-code-plugin

Verify record_hook_timing is dead:

rg -n 'record_hook_timing' hooks/ # only the definition

Verify HookTimer is dead:

rg -n 'HookTimer|hook_timer' hooks/ # only the definition

Verify the Stop summary never emits the ⏱ segment in practice:

cat ~/.codingbuddy/*.json 2>/dev/null | python3 -c "import json, sys; [print(k, v) for k, v in json.loads(sys.stdin.read()).items() if 'timing' in k]"

Expected output today: hook_timings {} — empty.

```

References

  • Discovered while reviewing fix(hooks): persist tool stats from short-lived hook processes #1492 (`fix(hooks): persist tool stats from short-lived hook processes`).
  • Related: race condition issue for `SessionStats.flush()` (separate issue, also discovered during fix(hooks): persist tool stats from short-lived hook processes #1492 review).
  • Touched files (read-only context):
    • `packages/claude-code-plugin/hooks/lib/stats.py` — `record_hook_timing`, `format_summary`, `finalize`
    • `packages/claude-code-plugin/hooks/lib/hook_timer.py` — entire file (candidate for deletion)
    • `packages/claude-code-plugin/hooks/post-tool-use.py` — example caller that needs the `finally`-block wiring
    • `packages/claude-code-plugin/tests/test_stats.py` — `TestHookTimingIntegration` already covers the consumer side

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions