Skip to content

fix(plugins): don't drop healthy concurrent fail-open hook invocations - #98385

Closed
chelsealong wants to merge 2 commits into
NousResearch:mainfrom
chelsealong:fix/hook-fail-open-concurrent-invocations
Closed

chelsealong wants to merge 2 commits into
NousResearch:mainfrom
chelsealong:fix/hook-fail-open-concurrent-invocations

Conversation

@chelsealong

Copy link
Copy Markdown
Contributor

Fixes #98382

Problem

PluginManager.invoke_hook used a single running flag
(callback_key in self._hook_running_callbacks) to mean two different
things: "this callback's worker exceeded plugins.hook_callback_timeout
and is still running" and "a healthy invocation of this callback from a
moment ago hasn't returned yet." Both states hit the same skip branch:

if (
    suppressed_until is not None and suppressed_until > now
) or running:
    logger.warning(...)
    if fail_closed:
        results.append(_pre_tool_call_timeout_block())
    continue

For fail-open observer hooks (everything except pre_tool_call), this
meant a second concurrent event was silently dropped even when the first
callback was well within its timeout — e.g. two post_tool_call events
0.3s apart, callback duration ~0.6s, default timeout 30s: no timeout ever
occurred, yet the second invocation was skipped and logged as "skipped
after previous timeout or while still running." Reported as 376 dropped
callback events in two days on a profile with overlapping cron sessions,
with the affected callbacks being evidence/audit recorders — so this
silently loses telemetry.

Fix

Split the two states apart in hermes_cli/plugins.py::PluginManager.invoke_hook:

  • timed_out — a confirmed timeout (from _hook_timeout_suppressed_until,
    set only when a caller's done.wait(timeout) actually elapsed) — always
    skips, for every hook. This is what keeps a genuinely hung worker from
    spawning unbounded duplicates.
  • running alone (worker still executing, no confirmed timeout) — only
    skips for pre_tool_call, which must keep failing closed on any overlap.
    For other bounded hooks, a second invocation now starts its own
    concurrent worker instead of being dropped.

pre_tool_call's fail-closed behavior is unchanged (still covered by
test_pre_tool_call_timeout_fail_closed), and the existing hung-callback
suppression test (test_hung_callback_suppresses_repeat_fires) still
passes because it exercises the confirmed-timeout path, not mere overlap.

Test

Added test_concurrent_healthy_invocations_both_processed in
tests/hermes_cli/test_plugins.py: registers a post_tool_call callback
that sleeps 0.3s, invokes the hook from two threads 0.15s apart with a
5s timeout budget, and asserts both invocations actually ran and both
results came back.

Confirmed it fails without the fix (git checkout HEAD~1 -- hermes_cli/plugins.py):

FAILED tests/hermes_cli/test_plugins.py::TestForceReloadSymmetry::test_concurrent_healthy_invocations_both_processed
AssertionError: assert ['first'] == ['first', 'second']
...
WARNING  hermes_cli.plugins:plugins.py:5625 Hook 'post_tool_call' callback slow skipped after previous timeout or while still running

With the fix, full suite passes via the mandated hermetic runner:

$ scripts/run_tests.sh tests/hermes_cli/test_plugins.py
[100.0% |    75/~75 | ✓75 | ✗ 0] ✓ tests/hermes_cli/test_plugins.py (75✓, 4.3s)
=== Summary: 1 files, 75 tests passed, 0 failed (100% complete) in 4.3s (8 workers) ===

ruff check hermes_cli/plugins.py tests/hermes_cli/test_plugins.py — all checks passed.

AI assistance disclosure

This change was authored by an AI coding agent (Claude), including the
diagnosis, fix, and regression test, with the test-failure-without-fix
verification shown above run by the same agent.

invoke_hook conflated two different states under one `running` flag: a
callback that actually exceeded plugins.hook_callback_timeout, and a
healthy callback from an earlier invocation still executing within its
timeout. Both were skipped identically, so a second concurrent event for
a fail-open observer hook (e.g. post_tool_call) was silently dropped even
though the first callback completed well within budget.

Keep pre_tool_call failing closed on any overlap, and keep a confirmed
timeout (tracked via _hook_timeout_suppressed_until) from spawning
unbounded duplicate workers. But let other bounded hooks run a second,
concurrent worker when the only reason to skip was that "something is
still running" and it hasn't actually timed out.
@liyangbing

Copy link
Copy Markdown

Review

The fix correctly separates a confirmed timeout from a healthy overlap, and the mutation check is strong evidence for the original regression. One follow-up boundary remains: allowing every bounded fail-open hook to start another worker removes silent loss, but without a per-callback concurrency/queue limit it can turn a burst of events into unbounded worker growth when callback duration exceeds arrival rate.

Please make the post-fix policy explicit:

1. Define a bounded maximum of concurrent workers or queued events per callback/hook, with an observable overflow result and counters.
2. Keep the confirmed-timeout suppression separate from ordinary backpressure; queue saturation must not be mislabeled as a timeout.
3. Preserve event ordering where an observer depends on it, or document that callbacks may complete out of order and carry an event sequence for reconciliation.
4. Define cancellation and shutdown: admitted callbacks must either drain within a bound or be reported as dropped, and a late worker must not mutate unloaded plugin state.
5. Keep pre_tool_call fail-closed on overlap and confirmed timeout, while proving observer exceptions/cancellation do not change that policy.

Regression matrix

Please cover:
• two healthy concurrent invocations: both run and return
• sustained event burst with slow callback: bounded workers/queue and explicit overflow evidence
• confirmed timeout followed by repeated events: no worker fan-out
• timeout watchdog racing with normal completion
• out-of-order completion with event IDs and ordering policy
• plugin reload/unload and process shutdown while workers or queued events remain
• concurrent pre_tool_call overlap, callback exception, cancellation, and fail-closed result

Direct evidence: PR #98385, including the PluginManager.invoke_hook change and the mutation-verified healthy-concurrency test.

@alt-glitch alt-glitch added type/bug Something isn't working P3 Low — cosmetic, nice to have comp/cli CLI entry point, hermes_cli/, setup wizard comp/plugins Plugin system and bundled plugins labels Aug 30, 2026
Follow-up to NousResearch#98382/NousResearch#98385 review: removing the drop-on-overlap
behavior for fail-open hooks made per-callback concurrency unbounded.
Add plugins.hook_callback_max_concurrency (default 4) to cap in-flight
workers per (hook, callback); invocations past the cap are dropped and
tracked in a separate overflow counter so queue saturation is never
conflated with a confirmed timeout. pre_tool_call is unaffected since
it already fails closed on any overlap.
@chelsealong

Copy link
Copy Markdown
Contributor Author

Addressed the concrete, boundable part of the follow-up: added plugins.hook_callback_max_concurrency (default 4) to cap in-flight workers per (hook, callback) for fail-open hooks, so a sustained burst can no longer fan out unbounded workers once callback duration exceeds arrival rate. Overflow beyond the cap is dropped and counted in a separate _hook_overflow_counts dict, keeping it distinct from a confirmed timeout (item 2). Docstring now documents that concurrent workers for the same callback may complete out of order (item 3's documented alternative, rather than adding event-sequence plumbing). pre_tool_call is untouched — it already fails closed on any overlap regardless of this cap, so item 5's policy is unchanged (existing test_pre_tool_call_timeout_fail_closed still covers it). Added test_burst_beyond_max_concurrency_is_bounded_and_counted, which fails on HEAD~1 with AttributeError: ... no attribute '_resolve_hook_callback_max_concurrency' and passes with the fix; full tests/hermes_cli/test_plugins.py is green (76/76) via scripts/run_tests.sh, and ruff check is clean.

Left out of scope for this PR: item 4 (drain-on-shutdown / cancellation reporting). Implementing a bounded drain would require joining the abandoned worker threads this file deliberately never joins, to avoid reintroducing the #6622 hang — that's a real conflict with an existing invariant here, not something I want to guess a resolution for without maintainer input, so I didn't add code for it.

@kshitijk4poor

Copy link
Copy Markdown
Contributor

Thanks @chelsealong — the symptom this fixes (healthy concurrent invocations of the same fail-open hook being dropped by the per-callback running gate) is now resolved on main by #111177 (73f808e47f, salvage of #110470 by @deadczarvc): the gate is keyed on the call identity (tool_call_id/turn_id), a timed-out worker is tracked as abandoned per callback so a hung hook still leaks exactly one thread, and transform_terminal_output/transform_llm_output carry an identity too. Bound by test_concurrent_same_tool_calls_with_distinct_ids_both_run. Closing as superseded; you submitted this before that fix existed, so credit for the report and shape stands.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

comp/cli CLI entry point, hermes_cli/, setup wizard comp/plugins Plugin system and bundled plugins P3 Low — cosmetic, nice to have type/bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Concurrent observer-hook invocations are dropped as if a callback had timed out

4 participants