fix(plugins): stop the hook slot from latching off for the life of the process - #107894
deadczarvc wants to merge 2 commits into
Conversation
Two halves of one outage in the enforcement layer: - an abandoned timeout worker never reached _release_token, so its key latched "still running" for the life of the process and every later call of that hook failed closed (observed: 100 skips and 15 blocked tool calls over 2h) - the running/suppression key ignored the tool, so a slow hook for one tool rejected unrelated tools whose matcher never ran Regression: tests/hermes_cli/test_plugins.py::test_slow_hook_for_one_tool_does_not_block_an_unrelated_tool Live check after backend restart: 0 blocked tool calls.
|
Related, already merged upstream: #94339 (un-invert the stdio children liveness check) fixed the polarity half of the same family, and #96452 salvaged the reconnect-on-fast-fail half of our previous report #95626 (our commit was cherry-picked there with authorship preserved). This PR is the next defect in that same lifecycle: the hook enforcement layer latches itself off. Unlike the MCP path, here the abandoned worker never releases its slot, so the first timeout poisons every later call of that hook for the life of the process — including tools whose matcher never ran. Both halves are covered by a regression test; the invariant check ( |
…alone Concurrent invocations of the same tool in one session collapsed into a single busy key (hook_name, id(cb)): the second invocation was reported as 'still running' and dropped. For pre_tool_call a drop is a fail-closed block, so the gate silenced itself on an ordinary, healthy callback. Measured on a busy profile: 3574 skip lines and 0 timeout lines in one hour — every skip was the 'while still running' branch, i.e. pure key collision, not slowness. The gate now keys on the call identity that is already in the payload (tool_call_id, else turn_id, else none — the last case behaves exactly as before). Suppression stays keyed coarsely on (hook_name, id(cb)): a hung callback is a fact about the callback, so its back-off must not be diluted per call. Refs #98382. Independent of #107894 (that one releases the slot on timeout; this one stops healthy concurrency from colliding). (cherry picked from commit 53b3dac)
…alone Concurrent invocations of the same tool in one session collapsed into a single busy key (hook_name, id(cb)): the second invocation was reported as 'still running' and dropped. For pre_tool_call a drop is a fail-closed block, so the gate silenced itself on an ordinary, healthy callback. Measured on a busy profile: 3574 skip lines and 0 timeout lines in one hour — every skip was the 'while still running' branch, i.e. pure key collision, not slowness. The gate now keys on the call identity that is already in the payload (tool_call_id, else turn_id, else none — the last case behaves exactly as before). Suppression stays keyed coarsely on (hook_name, id(cb)): a hung callback is a fact about the callback, so its back-off must not be diluted per call. Refs NousResearch#98382. Independent of NousResearch#107894 (that one releases the slot on timeout; this one stops healthy concurrency from colliding). (cherry picked from commit 53b3dac)
|
Closing as superseded by upstream work. The latch half is fixed in The scoping half is covered too, by a different mechanism: the gate key is now Thanks for landing it. I am closing this PR rather than rebasing a narrower duplicate. |
Problem
The hook enforcement layer can latch itself off for the life of the process.
_run_callback_with_timeoutwaitstimeoutfor the worker; on expiry it logs, records_hook_timeout_suppressed_until[callback_key]and returns without freeing the slot.The abandoned worker never reaches
_release_token, socallback_keystays in_hook_running_callbacksforever. Every later call of that hook fails closed — not for thesuppression window, but until the process restarts.
(hook_name, id(cb))— it ignores the tool. A slow shellhook that fired for tool A therefore rejects unrelated tool B whose own matcher never ran.
Observed in the field: one stalled callback produced 459 hook skips and 15 blocked tool
calls over 2 hours, including calls that never matched the stalled hook's own matcher.
Repro (hermetic)
tests/hermes_cli/test_plugins.py::test_slow_hook_for_one_tool_does_not_block_an_unrelated_toolregisters a hook that never returns for one tool and asserts an unrelated tool still passes.
Fix
_release_token(callback_key)) so the latch is bounded bythe suppression window instead of the process lifetime;
tool_namefor tool-bearing events (tool-less events keep the old key).Fail-closed behaviour and "same tool does not run two workers" are preserved.
Verification
tests/hermes_cli/test_plugins.pysuite passes;observation window, against 478/hour before the fix;
plugins.hook_callback_timeout, so the abandoned-worker path is not reachable in normaloperation (
our_max * 1.2 <= kernel, with threaded path disabled as an explicit escape).