Skip to content

feat(hooks): add duration_ms to post_tool_call (inspired by Claude Code 2.1.119) - #15429

Merged
teknium1 merged 1 commit into
mainfrom
claude-code-inspired/post-tool-hook-duration
Apr 26, 2026
Merged

feat(hooks): add duration_ms to post_tool_call (inspired by Claude Code 2.1.119)#15429
teknium1 merged 1 commit into
mainfrom
claude-code-inspired/post-tool-hook-duration

Conversation

@teknium1

Copy link
Copy Markdown
Contributor

Summary

Plugin hooks fired after a tool dispatch now receive an integer duration_ms kwarg measuring how long the tool's registry.dispatch() call took. Plugin authors can build latency dashboards, per-tool SLO alerts, and regression canaries without wrapping every tool manually.

Inspired by Claude Code 2.1.119 (released Apr 23, 2026), which added duration_ms to its PostToolUse hook inputs — the community use cases were immediately obvious (latency monitoring, budget alerts) and the feature lands cleanly inside our existing plugin hook shape.

Source: https://code.claude.com/docs/en/changelog"Hooks: PostToolUse/PostToolUseFailure inputs include duration_ms"

Changes

File What changed
model_tools.py Measure time.monotonic() before/after registry.dispatch(); pass duration_ms to invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
hermes_cli/hooks.py Add duration_ms: 42 to _DEFAULT_PAYLOADS["post_tool_call"] so hermes hooks test / hermes hooks doctor stdin-JSON matches runtime shape
tests/test_model_tools.py New test_post_tool_call_receives_non_negative_integer_duration_ms; updated existing call_args_list assertion to accept the new kwarg
website/docs/user-guide/features/hooks.md Document the new parameter + updated example showing per-tool latency tracking
website/docs/guides/build-a-hermes-plugin.md Updated the post_tool_call callback-signature line in the hooks summary table

Shell hooks (agent/shell_hooks.py) need no code change_serialize_payload already promotes any non-top-level kwarg into payload["extra"], so shell-hook scripts see extra.duration_ms in their stdin JSON automatically. Verified E2E.

How hermes-agent's implementation differs from Claude Code

  • Claude Code places duration_ms at the top level of the PostToolUse input JSON. Hermes plugin hooks get it as a direct kwarg (same level as tool_name, result, etc.); hermes shell hooks receive it under payload.extra.duration_ms, matching the existing pattern for result, task_id, and tool_call_id.
  • Claude Code also exposes a separate PostToolUseFailure event. Hermes catches tool exceptions and fires post_tool_call with an error-JSON result instead; duration_ms is measured across the successful-dispatch path only (which is the only path where the hook fires today).
  • pre_tool_call does NOT get duration_ms — nothing has run yet at that point, so the value would be meaningless. Regression-asserted in the new test.

Validation

Before After
post_tool_call kwargs tool_name, args, result, task_id, session_id, tool_call_id + duration_ms: int
transform_tool_result kwargs same + duration_ms: int
Shell-hook stdin JSON extra had result, task_id, tool_call_id + extra.duration_ms
tests/test_model_tools.py 19 passed 20 passed
tests/agent/test_shell_hooks.py + tests/hermes_cli/test_plugins.py + tests/plugins/test_disk_cleanup_plugin.py 145 passed 145 passed

E2E with real PluginManager, real handle_function_call, registry.dispatch monkey-patched to time.sleep(0.05) → captured hook callback saw duration_ms=50 (int). ✅

Backward compatibility

Fully additive — existing post_tool_call callbacks using **kwargs keep working unchanged. Plugins that explicitly named all kwargs in their signature without **kwargs would break, but the documented pattern (and every in-repo plugin) already ends the signature with **kwargs.

Plugin hooks fired after a tool dispatch now receive an integer
duration_ms kwarg measuring how long the tool's registry.dispatch()
call took (time.monotonic() before/after). Inspired by Claude Code
2.1.119 which added the same field to PostToolUse hook inputs.

Wire points:
- model_tools.py: measure dispatch latency, pass duration_ms to
  invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
- hermes_cli/hooks.py: include duration_ms in the synthetic payload
  used by 'hermes hooks test' and 'hermes hooks doctor' so shell-hook
  authors see the same shape at development time as runtime
- shell hooks (agent/shell_hooks.py): no code change needed;
  _serialize_payload already surfaces non-top-level kwargs under
  payload['extra'], so duration_ms lands at extra.duration_ms for
  shell-hook scripts

Plugin authors can now build latency dashboards, per-tool SLO alerts,
and regression canaries without having to wrap every tool manually.

Test: tests/test_model_tools.py::test_post_tool_call_receives_non_negative_integer_duration_ms
E2E: real PluginManager + dispatch monkey-patched with a 50ms sleep,
hook callback observes duration_ms=50 (int).

Refs: https://code.claude.com/docs/en/changelog (2.1.119, Apr 23 2026)
@github-actions

Copy link
Copy Markdown
Contributor

⚠️ npm lockfile hash out of date

Checked against commit 0f82c75 (PR head at check time).

The hash = "sha256-..." line in these nix files no longer matches the committed package-lock.json:

Apply the fix

  • Apply lockfile fix — tick to push a commit with the correct hashes to this PR branch
  • Or run the Nix Lockfile Fix workflow manually (pass PR #15429)
  • Or locally: nix run .#fix-lockfiles -- --apply and commit the diff

@alt-glitch alt-glitch added type/feature New feature or request P3 Low — cosmetic, nice to have comp/tools Tool registry, model_tools, toolsets comp/plugins Plugin system and bundled plugins labels Apr 25, 2026
@teknium1

Copy link
Copy Markdown
Contributor Author

PR Review — #15429: duration_ms on post_tool_call / transform_tool_result

Verdict: Approve — ship it.
Tests: 168/168 passed (test_model_tools + test_shell_hooks + test_plugins + test_disk_cleanup_plugin), 7s.
Live E2E: ✓ 50ms sleep inside registry.dispatch → hook observed duration_ms=50 (int); pre_tool_call kwargs correctly omit the key; shell-hook auto-promotion into payload.extra verified without code change.

Critical

  • None.

Warnings

  • Adjacent pre-existing doc bug (website/docs/user-guide/features/hooks.md:330). The "Fires:" paragraph is self-contradictory: "Does not fire if the tool raised an unhandled exception (the error is caught … and post_tool_call fires with that error string as result)." The runtime truth (verified against model_tools.py:626-629 outer except Exception as e) is that both post_tool_call and transform_tool_result are skipped when dispatch() raises — "does NOT fire" half is right, the parenthetical tail is wrong. git blame puts it on 5879b3ef8 (Apr 4), not this PR — but since the PR is already editing this section, one-line fix here is cheap and keeps the plugin contract honest.

Suggestions

  • Follow-up: emit duration_ms on the exception path too. Current wiring (_dispatch_start = time.monotonic()dispatch()int(...)) means any raising tool produces zero telemetry. Wrapping dispatch() in try/finally so the hook fires with duration_ms + error-JSON result would close the latency-dashboard blind spot. Out of scope for this PR; worth a ticket.
  • _DEFAULT_PAYLOADS is shell-addressable only. transform_tool_result is correctly absent from hermes_cli/hooks.py:125, since _DEFAULT_PAYLOADS only feeds hermes hooks test / doctor stdin synthesis and transform_tool_result is a Python-plugin-only hook. A one-line comment above the table declaring that invariant would save future contributors the grep.
  • Shell-hook authors will look in the wrong place. The PR's claim that extra.duration_ms appears in shell-hook stdin is correct (agent/shell_hooks.py:464-480 auto-promotes non-top-level kwargs into payload.extra), but hooks.md never tells shell-hook authors that's where new fields land. One sentence in the duration_ms row — "Shell-hook scripts receive this under .extra.duration_ms." — prevents the obvious confusion.

Looks Good

  • time.monotonic() over time.time() — non-decreasing, NTP-safe; int((t2-t1)*1000) ≥ 0 holds by PEP 418.
  • Single measurement shared between post_tool_call and transform_tool_result (test asserts post_duration == transform_duration — nice tightening).
  • Placement after pre_tool_call / notify_other_tool_call isolates pure dispatch latency.
  • Test patches target the correct symbols: model_tools.registry.dispatch (registry imported top-level) and hermes_cli.plugins.invoke_hook (the source module, not the lazy rebind — correct per the lazy-import-trap pattern).
  • ANY on the existing call_args_list assertion keeps the order check honest without over-specifying.
  • Backward-compat verified across in-tree plugins — only plugins/disk-cleanup/__init__.py:128 hooks post_tool_call, ends with **_: Any, accepts the new kwarg transparently. Zero in-repo plugins break.
  • Fail-open try/except around both hook invocations preserved — a buggy duration_ms-consuming plugin can't take down tool dispatch.
  • Rationale comment at model_tools.py:~565 is exemplary: cites Claude Code 2.1.119, explains the monotonic choice, documents the "both hooks observe the same measurement" contract.

@teknium1
teknium1 merged commit 59b56d4 into main Apr 26, 2026
9 of 13 checks passed
@teknium1
teknium1 deleted the claude-code-inspired/post-tool-hook-duration branch April 26, 2026 05:13
donald131 pushed a commit to donald131/hermes-agent that referenced this pull request May 2, 2026
NousResearch#15429)

Plugin hooks fired after a tool dispatch now receive an integer
duration_ms kwarg measuring how long the tool's registry.dispatch()
call took (time.monotonic() before/after). Inspired by Claude Code
2.1.119 which added the same field to PostToolUse hook inputs.

Wire points:
- model_tools.py: measure dispatch latency, pass duration_ms to
  invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
- hermes_cli/hooks.py: include duration_ms in the synthetic payload
  used by 'hermes hooks test' and 'hermes hooks doctor' so shell-hook
  authors see the same shape at development time as runtime
- shell hooks (agent/shell_hooks.py): no code change needed;
  _serialize_payload already surfaces non-top-level kwargs under
  payload['extra'], so duration_ms lands at extra.duration_ms for
  shell-hook scripts

Plugin authors can now build latency dashboards, per-tool SLO alerts,
and regression canaries without having to wrap every tool manually.

Test: tests/test_model_tools.py::test_post_tool_call_receives_non_negative_integer_duration_ms
E2E: real PluginManager + dispatch monkey-patched with a 50ms sleep,
hook callback observes duration_ms=50 (int).

Refs: https://code.claude.com/docs/en/changelog (2.1.119, Apr 23 2026)
02356abc pushed a commit to 02356abc/hermes-agent that referenced this pull request May 14, 2026
NousResearch#15429)

Plugin hooks fired after a tool dispatch now receive an integer
duration_ms kwarg measuring how long the tool's registry.dispatch()
call took (time.monotonic() before/after). Inspired by Claude Code
2.1.119 which added the same field to PostToolUse hook inputs.

Wire points:
- model_tools.py: measure dispatch latency, pass duration_ms to
  invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
- hermes_cli/hooks.py: include duration_ms in the synthetic payload
  used by 'hermes hooks test' and 'hermes hooks doctor' so shell-hook
  authors see the same shape at development time as runtime
- shell hooks (agent/shell_hooks.py): no code change needed;
  _serialize_payload already surfaces non-top-level kwargs under
  payload['extra'], so duration_ms lands at extra.duration_ms for
  shell-hook scripts

Plugin authors can now build latency dashboards, per-tool SLO alerts,
and regression canaries without having to wrap every tool manually.

Test: tests/test_model_tools.py::test_post_tool_call_receives_non_negative_integer_duration_ms
E2E: real PluginManager + dispatch monkey-patched with a 50ms sleep,
hook callback observes duration_ms=50 (int).

Refs: https://code.claude.com/docs/en/changelog (2.1.119, Apr 23 2026)
dannyJ848 pushed a commit to dannyJ848/hermes-agent that referenced this pull request May 17, 2026
NousResearch#15429)

Plugin hooks fired after a tool dispatch now receive an integer
duration_ms kwarg measuring how long the tool's registry.dispatch()
call took (time.monotonic() before/after). Inspired by Claude Code
2.1.119 which added the same field to PostToolUse hook inputs.

Wire points:
- model_tools.py: measure dispatch latency, pass duration_ms to
  invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
- hermes_cli/hooks.py: include duration_ms in the synthetic payload
  used by 'hermes hooks test' and 'hermes hooks doctor' so shell-hook
  authors see the same shape at development time as runtime
- shell hooks (agent/shell_hooks.py): no code change needed;
  _serialize_payload already surfaces non-top-level kwargs under
  payload['extra'], so duration_ms lands at extra.duration_ms for
  shell-hook scripts

Plugin authors can now build latency dashboards, per-tool SLO alerts,
and regression canaries without having to wrap every tool manually.

Test: tests/test_model_tools.py::test_post_tool_call_receives_non_negative_integer_duration_ms
E2E: real PluginManager + dispatch monkey-patched with a 50ms sleep,
hook callback observes duration_ms=50 (int).

Refs: https://code.claude.com/docs/en/changelog (2.1.119, Apr 23 2026)
gweeteve pushed a commit to gweeteve/hermes-agent that referenced this pull request Jun 2, 2026
NousResearch#15429)

Plugin hooks fired after a tool dispatch now receive an integer
duration_ms kwarg measuring how long the tool's registry.dispatch()
call took (time.monotonic() before/after). Inspired by Claude Code
2.1.119 which added the same field to PostToolUse hook inputs.

Wire points:
- model_tools.py: measure dispatch latency, pass duration_ms to
  invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
- hermes_cli/hooks.py: include duration_ms in the synthetic payload
  used by 'hermes hooks test' and 'hermes hooks doctor' so shell-hook
  authors see the same shape at development time as runtime
- shell hooks (agent/shell_hooks.py): no code change needed;
  _serialize_payload already surfaces non-top-level kwargs under
  payload['extra'], so duration_ms lands at extra.duration_ms for
  shell-hook scripts

Plugin authors can now build latency dashboards, per-tool SLO alerts,
and regression canaries without having to wrap every tool manually.

Test: tests/test_model_tools.py::test_post_tool_call_receives_non_negative_integer_duration_ms
E2E: real PluginManager + dispatch monkey-patched with a 50ms sleep,
hook callback observes duration_ms=50 (int).

Refs: https://code.claude.com/docs/en/changelog (2.1.119, Apr 23 2026)
waefrebeorn pushed a commit to waefrebeorn/slermes that referenced this pull request Jul 2, 2026
NousResearch#15429)

Plugin hooks fired after a tool dispatch now receive an integer
duration_ms kwarg measuring how long the tool's registry.dispatch()
call took (time.monotonic() before/after). Inspired by Claude Code
2.1.119 which added the same field to PostToolUse hook inputs.

Wire points:
- model_tools.py: measure dispatch latency, pass duration_ms to
  invoke_hook("post_tool_call", ...) and invoke_hook("transform_tool_result", ...)
- hermes_cli/hooks.py: include duration_ms in the synthetic payload
  used by 'hermes hooks test' and 'hermes hooks doctor' so shell-hook
  authors see the same shape at development time as runtime
- shell hooks (agent/shell_hooks.py): no code change needed;
  _serialize_payload already surfaces non-top-level kwargs under
  payload['extra'], so duration_ms lands at extra.duration_ms for
  shell-hook scripts

Plugin authors can now build latency dashboards, per-tool SLO alerts,
and regression canaries without having to wrap every tool manually.

Test: tests/test_model_tools.py::test_post_tool_call_receives_non_negative_integer_duration_ms
E2E: real PluginManager + dispatch monkey-patched with a 50ms sleep,
hook callback observes duration_ms=50 (int).

Refs: https://code.claude.com/docs/en/changelog (2.1.119, Apr 23 2026)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

comp/plugins Plugin system and bundled plugins comp/tools Tool registry, model_tools, toolsets P3 Low — cosmetic, nice to have type/feature New feature or request

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants