fix(plugins): isolate concurrent hook callbacks by Kyzcreig · Pull Request #819 · ANG-Ventures/hermes-agent

Kyzcreig · 2026-09-21T10:38:05Z

Summary

stop treating ordinary concurrent plugin callback invocations as timed out
arm callback suppression only after an invocation actually exceeds its budget
preserve each shell hook's configured fail_closed policy at the outer plugin timeout boundary
log the callback name, measured elapsed duration, and configured timeout budget

Root cause

PluginManager.invoke_hook() keyed _hook_running_callbacks by (hook_name, id(callback)) across the entire multiplexed gateway process. While session A was running a healthy callback, session B saw the same key and entered the "timeout or still running" branch. Because pre_tool_call defaults fail-closed, normal overlap blocked session B's tool call.

Live logs had 1,917 pre_tool_call skip lines and zero pre_tool_call timeout lines. The configured shell hooks measured 35.6–53.0 ms p50 and <=69.4 ms max against a 30-second budget. Full evidence is in findings.md.

Verification

scripts/run_tests.sh tests/hermes_cli/test_plugins.py tests/agent/test_shell_hooks.py -q — 128 passed
mutation: production fix reverted with regression tests retained — exactly 2 failed
50-way concurrent PluginManager.invoke_hook("pre_tool_call") harness — entered=50 completed=50/50 blocks=0
python -m ruff check ... — passed
git diff --check — passed

No gateway restart was performed.

Only suppress callbacks after an observed timeout, preserve per-shell-hook fail-closed policy, and log measured timeout duration.\n\nVerified: 128 focused tests pass; two-test mutation goes red; 50-way overlap completes with zero blocks.

Kyzcreig · 2026-09-21T10:46:55Z

🔁 re-enqueue for FleetReview (Apollo): head's terminal record was stamped ERROR by a router restart (release cut 20260921T104203Z / sibling cuts 10:25-10:32Z), not by a review verdict; close/reopen re-submits the unchanged head. No code change.

…essages Review round 1 (Argus) flagged that the user-facing block message still advertised a state the previous commit deleted: "pre_tool_call plugin callback timed out or is still running" The still-running branch is gone, so "or is still running" named a condition that can no longer occur. That exact wording is what sent this investigation down a phantom concurrency-snowball hypothesis, and it is the observability half of acceptance criterion #4 — the WARNING was fixed to report measured elapsed + budget, but the string the user receives was not. Simply dropping the clause would have been wrong. There are TWO call sites of _pre_tool_call_timeout_block(), not one: :5736 genuine timeout — done.wait expired; elapsed and budget known :5683 suppression window — a LATER call refused because a PRIOR one timed out inside the 60s cooldown Deleting "or is still running" fixes the first and makes the second lie in the opposite direction: it would claim THIS callback timed out when it did not. The log lines were already de-conflated for exactly this reason; the user-facing message now gets the same split, and both name the callback. timeout: pre_tool_call plugin callback <name> timed out after 0.101s (budget 0.1s) suppression: pre_tool_call plugin callback <name> is suppressed after an earlier timeout (retry in 60s) Tests now assert the behavioral distinction (each path accurate, and the two differ) instead of comparing against a shared constant — the constant-equality shape is what let the conflation survive round 1 unnoticed. Verified (all probes import-asserted against the worktree): - scripts/run_tests.sh tests/hermes_cli/test_plugins.py tests/agent/test_shell_hooks.py -q -> 128 passed, 0 failed - mutation: re-conflate the suppression path -> FAILED on "assert 'hung_policy' in msg2"; restored -> 128 passed - fail-closed policy unchanged: advisory -> allow on timeout AND suppression; enforcing -> block on both - thread accumulation re-verified on real PR code: 40 invocations against a hung hook -> spawned=1, thread delta=1 - ruff check -> All checks passed findings.md also records the measurement trap that invalidated two round-1 probes: the shared venv's editable-install finder maps top-level packages to the LIVE checkout, so bare `python probe.py` from a worktree executes live-tree code while __file__ and inspect.getsource report the worktree path. pytest is unaffected (rootdir wins on sys.path). Re-counted skips span 2026-08-31 to 09-21 (2,055), so the defect predates the incident by three weeks.

Kyzcreig · 2026-09-21T12:14:07Z

FleetReview

Reviewed with 2 of 3 model families — xai unavailable.

Confidence: 2/5

Findings

P2 hermes_cli/plugins.py:5672 — Thread Flood
P1 hermes_cli/plugins.py:467 — Timeout block messages can disclose shell-hook commands to the model
P1 hermes_cli/plugins.py:5691 — Abandoned timeout worker sets the NEXT callback's done/outcome, dropping that callback's policy decision
P1 hermes_cli/plugins.py:3760 — Secret Exposure
P1 hermes_cli/plugins.py:5735 — Secret Exposure

FleetReview provenance · models: B=gpt-5.6-sol, C=claude-code-opus-5, F=gpt-5.6-sol, G=grok-4.6 · cost: $3.82 · duration: 18m 05s · rounds: 1 · files examined: 5

A shell hook's command is operator-supplied and routinely carries a credential inline (sh -c 'export TOK=...; ...'). Two channels returned it verbatim to the model: - #819's new pre_tool_call refusals interpolate the callback __name__, which _make_callback set to the full command line (regression). - _fail_closed_block has always built "hook <command> failed closed: <reason>" from spec.command, on 6 call sites, no timeout involved (pre-existing, and a documented shape). Fix at the producer instead of the two new call sites: hook_display_name() yields "<label>#<sha256[:8]>", applied to both the callback __name__ and _fail_closed_block, so every current and future consumer is covered. The label is an ALLOWLIST ([A-Za-z0-9][A-Za-z0-9._+-]*), not a sanitizer. Two parse-based designs failed on real shapes before this one: basename of the last non-flag token leaks the whole inline script of `sh -c '...'`, and stopping at the first flag leaks `env TOK=secret prog`. Unmatched tokens are dropped in favour of the digest, so unanticipated shapes fail safe. Known launchers (sh, python3, env, ...) are skipped so the script still names the hook -- both live pre_tool_call hooks run under /usr/bin/python3 and must stay distinguishable. The raw command remains on the log channel for operators; only the model-facing channel is narrowed. Verified: focused suites 146/146 (was 128); wider hook/plugin surface 283/283; mutation reverting both producer sites fails exactly the 3 new regressions while all 143 pre-existing stay green (fail-closed policy untouched); 16 adversarial command shapes leak 0, 10 pinned as a parametrized test; ruff clean. Docs updated to the new shape.

…agging it The secret_scan CI gate failed on PR #819 with 3 findings, all in the regression tests added by 81ee0ed: generic-api-key tests/agent/test_shell_hooks.py:229 generic-api-key tests/agent/test_shell_hooks.py:245 generic-api-key tests/hermes_cli/test_plugins.py:1303 match: secret = "hunter2PRODSup3rSecret" The value is a planted sentinel the tests assert is ABSENT from model-facing refusals -- not a credential. gitleaks' generic-api-key rule keys on the ASSIGNMENT IDENTIFIER, not the value: measured across nine candidates, it fires for identifiers containing secret/token/ credential and is clean for planted/canary/marker/sentinel/needle. (The same literal at test_shell_hooks.py:148 was never flagged, because inside a tuple there is no assignment keyword to match.) Renaming the local is therefore sufficient, and is preferred over the two alternatives that widen the gate: - path-allowlisting these files would blind the scanner across 1,300+ lines of general-purpose hook/plugin tests, which -- unlike the entries already in .gitleaks.toml -- are NOT files expected to carry fake credential shapes; - a "hunter2" stopword would allowlist any real secret containing it. .gitleaks.toml is unchanged, so detection strength is preserved. Verified: - gitleaks, CI's exact config/file set: 3 findings -> "no leaks found" (exit 0) - focused suites 146 passed / 0 failed (unchanged count) - mutation (revert producer to 41aa293, keep tests): 17 failures, including both renamed tests by name -- assertions still detect a real leak, so the rename did not make them vacuous - agent/shell_hooks.py byte-identical to 81ee0ed; ruff clean

An abandoned hook worker wrote into the NEXT callback's slot. `_runner` bound only `_cb`; `done`, `outcome`, `failure` and `context` stayed free variables. A closure resolves free variables at CALL time, so a worker abandoned on timeout keeps running and, once the loop has advanced, dereferences the CURRENT iteration's objects: it releases the next callback's `done.wait()` early and overwrites that callback's result with its own. Re-creating the four objects per iteration (already done at :5691-5694) does not help — rebinding the name is exactly what hands the late worker the next iteration's objects. Default-arg binding is the load-bearing change; it snapshots the references into the thread's own frame at definition time. Consequence was the inverse of the reported symptom: an advisory hook that merely ran slow could inject a BLOCK into a later, unrelated callback's slot. Verified: - Reproduced on the real invoke_hook path at e4f7f2b before the fix: cb_fast's FAST-CB-ALLOW replaced by the abandoned cb_slow's SLOW-CB-BLOCK; invoke_hook returned in 0.460s though cb_fast needs 1.0s. - After: cb2's decision observed, cb1's late write discarded. - Regression test test_timed_out_callback_does_not_corrupt_next_callback (event-based ordering, no wall-clock bound, real threads + real timeout path). Mutation: revert to `_cb=cb` only -> test FAILS by name. - scripts/run_tests.sh tests/hermes_cli/test_plugins.py tests/agent/test_shell_hooks.py -> 147 passed, 0 failed. - ruff clean.

Kyzcreig · 2026-09-21T17:06:21Z

FleetReview

Reviewed with 2 of 3 model families — openai unavailable.

Confidence: 3/5

Findings

P1 agent/shell_hooks.py:564 — Raw hook command (with inline credentials) still reaches the model via the fail-closed reason
P2 hermes_cli/plugins.py:5665 — Dropping _hook_running_callbacks lets a permanently hung hook accumulate abandoned daemon threads
P1 hermes_cli/plugins.py:5656 — New refusal messages interpolate repr(cb) for callbacks without name, a fresh disclosure surface
P2 findings.md:1 — Internal incident scratch report committed to repo root; embeds a named developer's absolute home paths, host telemetry and a live PID
P2 tests/hermes_cli/test_plugins.py:1083 — test_timed_out_callback_does_not_corrupt_next_callback is wall-clock racy despite claiming it is not
P1 tests/hermes_cli/test_plugins.py:1363 — Secret-disclosure test covers only the __name__ path; the repr(cb) fallback is an uncovered leak vector
P3 website/docs/user-guide/features/hooks.md:1699 — Doc introduces opaque <name>#<digest> refusal identifier with no explanation and no CLI surface to map it back to a hook
P3 tests/hermes_cli/test_plugins.py:1277 — test_advisory_pre_tool_call_timeout_fails_open cannot distinguish suppression from a second timeout, and bypasses _make_callback

FleetReview provenance · models: C=claude-code-opus-5, D=grok-4.6, G=grok-4.6 · cost: $21.12 · duration: 35m 46s · rounds: 1 · files examined: 6

…ed contracts All six files are fork-only tests that arrived with the fork/main fold and asserted pre-sync shapes; the production behaviour each guards is present: - test_plugins: #819 per-event refusal text (callback/elapsed/budget) and the named 'worker failed to start' skip, instead of the unformatted template. - worker_leftover_reap: facade -> kanban_db_dispatch repoint (e45-kbrepoint); worker completions pass expected_run_id (upstream LiveClaimError fence) and a metadata receipt (#1621 no_receipt gate). - needs_input_pager: link the parent before the dependency wait (upstream 42a778a re-kinds a parent-less dependency block to needs_input). - edit_skills lint contract: allow_real_home_io marker (upstream home I/O guard). - steer_persist: steer is a standalone persisted user row (NousResearch#110979), tool row clean. - followup_timestamp AST: the recursive _run_agent now lives in gateway/run_turn.py. Fold-surface subset: 11 failed -> 0 (targeted reruns). (t_e45c8c8d)

fix(plugins): isolate concurrent hook callbacks

6307e40

Only suppress callbacks after an observed timeout, preserve per-shell-hook fail-closed policy, and log measured timeout duration.\n\nVerified: 128 focused tests pass; two-test mutation goes red; 50-way overlap completes with zero blocks.

Kyzcreig closed this Sep 21, 2026

Kyzcreig reopened this Sep 21, 2026