fix(agent): shorten interruptible_*_api_call poll window 0.3s → 0.05s - #57933
Closed
mopga wants to merge 10 commits into
Closed
fix(agent): shorten interruptible_*_api_call poll window 0.3s → 0.05s#57933mopga wants to merge 10 commits into
mopga wants to merge 10 commits into
Conversation
…7903 Quantifies the GIL starvation caused by the main-thread busy-poll in interruptible_api_call (agent/chat_completion_helpers.py:393). The bench runs a simulated 6-30s LLM call via a MagicMock agent and measures how many times a parallel heartbeat thread gets to tick during the call. On the current code (300ms t.join poll) it reports ~3x the baseline tick count; the target after a sub-event-loop fix is 5x+ (50ms future.result poll). The script is plain-stdlib and has no model-provider or API-key dependency, so it's safe to run in CI on any developer machine. Usage: python scripts/bench_interruptible_api_call.py --seconds 10 Exit code 0 = fixed (ratio >= 4.0); 1 = partial (2.0 <= ratio < 4.0); 2 = broken (ratio < 2.0). On current main this reports 2 with ratio ~3.0x, matching the symptom from issue NousResearch#57903. This is a diagnostic-only commit. The fix itself is a follow-up that replaces t.join(timeout=0.3) with future.result(timeout=0.05) on a concurrent.futures.Future returned by the worker thread. See: NousResearch#57903
…ptible_api_call Replaces the misleading 'ratio to baseline' framing in scripts/bench_interruptible_api_call.py with a two-metric diagnostic: 1. GIL yield: how many times a parallel heartbeat thread ticks during a long SDK call. Current code yields ~10/s (theoretical max 10/s for a 100ms-interval heartbeat), confirming the busy-poll already releases the GIL correctly via Python's _Condition.wait. 2. Interrupt latency: how quickly interruptible_api_call returns after _interrupt_requested flips mid-call. Current code returns in ~50ms (budget 500ms), confirming the 300ms poll window is not the bottleneck for interrupt detection. Together these rule out two plausible-but-wrong diagnoses (GIL starvation, slow interrupt) and pinpoint the real symptom: the sync t.join in the same thread as the asyncio event loop starves heartbeat scheduling on the main thread, even though GIL is yielded to other threads. Adds tests/agent/test_interruptible_api_call_yields_gil.py as a pytest regression guard. Pins interrupt latency to <=1.0s (generous for slow CI). Passes on current main; would fail if a future change bumped the busy-poll window back up. See: NousResearch#57903 (issue body will be updated to reflect the corrected diagnosis)
Reduces the worst-case event-loop stall from 300ms to 50ms during long-running non-streaming LLM calls. run_conversation runs synchronously on the asyncio event loop thread, so each t.join blocks the loop from advancing until the join times out. 300ms is long enough that the 2s heartbeat callback in web_server.py and the desktop WebSocket heartbeats fall behind, tripping the 5s-stall watchdog (event loop stalled Ns warnings) and the desktop's 10s WS timeout. Halving the window to 50ms keeps the worst-case stall well under the 5s threshold. The activity-touch cadence is preserved at 30s (600 × 0.05s, was 100 × 0.3s). The new poll interval is configurable via HERMES_INTERRUPTIBLE_API_POLL_SECONDS (config.yaml is for non-secret behavioral settings per AGENTS.md, so an env override is the right escape hatch here). A single time.sleep(0) is added after each join for an explicit GIL yield — covers the edge case where the worker thread finishes during the join and the join returns early without giving other threads a chance to schedule. This is the first commit of the multi-step migration described in issue NousResearch#57903. The Bedrock (line 1879) and streaming (line 2816) siblings get the same treatment in follow-up commits. Verified locally: - bench interrupt latency: 47ms → 0ms - bench GIL yield: unchanged (~10/s, theoretical max) - tests/agent/test_interruptible_api_call_yields_gil.py: PASSED - tests/agent/test_cascading_interrupt_6600.py (3 tests): PASSED - tests/test_tui_gateway_server.py (303 tests): PASSED See: NousResearch#57903
Same fix as the previous commit for the non-streaming interruptible_api_call — applies to the Bedrock boto3 path which also busy-polls t.join(timeout=0.3) on the main thread. See issue NousResearch#57903. Verified locally: - tests/agent/test_bedrock_adapter.py (132 tests): PASSED - tests/agent/test_interruptible_api_call_yields_gil.py: PASSED - tests/agent/test_cascading_interrupt_6600.py (3 tests): PASSED - tests/test_tui_gateway_server.py (303 tests): PASSED
Same fix as the previous two commits. The streaming path is the one most often exercised by long-running LLM calls (large context prefill, reasoning models) so this is the highest-impact of the three sibling interruptible_*_api_call functions. This is the last of the three t.join(timeout=0.3) sites in this file. Issue NousResearch#57903's "minimal fix" series is now complete; the remaining work (sub-event-loop bridge or async migration) is a separate, larger change tracked in the issue. Verified locally: - tests/agent/test_interruptible_api_call_yields_gil.py: PASSED - tests/agent/test_cascading_interrupt_6600.py (3): PASSED - tests/agent/test_bedrock_adapter.py (132): PASSED - tests/agent/test_compression_interrupt_protection.py (5): PASSED - tests/agent/test_codex_ttfb_watchdog.py (5): PASSED - tests/test_tui_gateway_server.py (303): PASSED Total: 454 passed in 43.10s
Pins the main-thread poll window to <= 0.2s by instrumenting threading.Thread.join and recording every timeout the production function uses. The fix in commit 29f55d4 (non-streaming), 9d996b1 (Bedrock), and 1750b40 (streaming) sets the poll window to 0.05s (configurable via HERMES_INTERRUPTIBLE_API_POLL_SECONDS). If anyone reverts the fix or bumps the window back to 0.3s (or higher), this test fails with the recorded join timeouts and a pointing message. The 0.2s budget is generous — it leaves room for the 50ms default + future tuning — but tight enough to catch the 300ms baseline that produced the original stall warnings. The interrupt path itself uses 2.0s joins to give the worker time to observe the close; the test filters those out via a <=1.0s threshold so they don't pollute the pin. Verified locally: both tests pass; the new test runs in <1s.
Runs N parallel simulated interruptible_api_call instances and measures per-call latency + heartbeat ticks. Complements the single-call bench_interruptible_api_call.py. Usage: python scripts/load_interruptible_api_call.py --seconds 8 --concurrency 3 On the post-fix code (50ms poll) this reports perfect parallelism (3 concurrent 3s calls complete in 3.0s, 30/30 heartbeat ticks). The real symptom — event-loop starvation in the same thread — can only be measured with the live Hermes serve + desktop (gui.log watch). This load script confirms the GIL/contention side of the fix in a reproducible way. See: NousResearch#57903
… gap warning The previous minimal fix (50ms poll) did not eliminate the symptom in production: 17-25s event-loop stalls still occur during long LLM calls. The stalls are longer than the LLM call latency itself, so they are NOT caused by the LLM HTTP call blocking the main thread — something else holds the main thread for 17-25s at a time. This commit adds a wall-clock gap measurement between consecutive polls in interruptible_api_call's wait loop. If a gap > 500ms is observed, the agent logs a status warning that names the gap size and the poll count. This makes the next stall reproducible — the warning will surface in the desktop status stream and the gateway logs, pinpointing which call instance had the issue and how long the main thread was actually blocked outside the poll loop. Once we see the gap warnings in a live session, we can identify the exact code path (retry backoff, JSON parsing in a stream chunk, GC, lock contention, etc.) and target the actual fix. This is a diagnostic commit. The instrumentation will be removed once the real fix is in place. See issue NousResearch#57903. Verified locally: 137 tests pass (interruptible + cascading + bedrock).
Reproduces the realistic streaming-shape load: worker thread does periodic CPU bursts (80ms each, every 50ms) to mimic JSON parsing of large streaming chunks. A parallel heartbeat thread measures the largest gap between 20ms-interval heartbeats during the call. Budget: 500ms max gap. The 50ms poll window from commit 29f55d4 passes this test in isolation (max gap ~80-150ms — bounded by the worker's CPU burst size, not the poll window). If the test fails, the 50ms window is still too long for the realistic load and we need the sub-event-loop bridge or async migration to fully fix issue NousResearch#57903. Verified locally: test passes in 3s on current code.
Tries to reproduce the 15-25s event-loop stall pattern observed in production during long LLM streaming sessions. Simulates: - 6-second streaming call (long enough to expose the pattern) - JSON parsing of realistic 6KB chunks every 50ms (mimics Anthropic MessageStream event parsing on Python 3.11) - I/O wait between chunks (socketpair + non-blocking recv) - Heavier tool-call chunk parse every 10th iteration The current 50ms poll window passes this test on standalone CI (6.58s). This is the baseline; if the test starts failing on a heavier load or after a future change to the SDK integration, the sub-event-loop bridge from issue NousResearch#57903 is the next step. Verified locally: passes in 6.65s.
mopga
marked this pull request as ready for review
July 3, 2026 21:16
alt-glitch
added
type/bug
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Closing this PR — diagnostic instrumentation (commit 6be7934) showed that the busy-poll is not the bottleneck. The poll gap > 500ms warning never fired during production stalls, proving the main thread is NOT in our poll loop during stalls. Standalone reproduction tests pass because they mock the SDK with time.sleep-based workloads that release the GIL; the real Anthropic SDK holds the GIL differently during real HTTP/JSON parsing on 300K+ token contexts.
The PR remains valid as a tiny, harmless improvement (50ms poll instead of 300ms; explicit time.sleep(0) after each poll; new regression-guard tests). It just does not solve the symptom the issue tracks. Maintaining it would be misleading, so closing.
A follow-up issue would be needed for the real fix, which requires one of:
Will not reopen unless a maintainer requests the poll-window reduction as a standalone change.