Skip to content

fix(qqbot): prevent event-loop busy-spin when WebSocket is half-closed - #29057

Closed
xieyuanqing wants to merge 1 commit into
NousResearch:mainfrom
xieyuanqing:fix/qqbot-listen-loop-busy-spin
Closed

fix(qqbot): prevent event-loop busy-spin when WebSocket is half-closed#29057
xieyuanqing wants to merge 1 commit into
NousResearch:mainfrom
xieyuanqing:fix/qqbot-listen-loop-busy-spin

Conversation

@xieyuanqing

Copy link
Copy Markdown

Summary

gateway/platforms/qqbot/adapter.py::QQAdapter._read_events can return
normally on a stale, already-closed ClientWebSocketResponse. When that
happens the outer _listen_loop re-enters _read_events immediately
without any awaitable actually suspending, the asyncio event loop is
starved, and the whole gateway hangs at 100% CPU. This PR makes
_read_events raise in that situation so _listen_loop reaches its
reconnect path, and adds regression tests.

Trigger / observed failure

In production a single failed QQ-Bot reconnect at 06:35:14 (gateway
URL request returned an empty body) froze the gateway for 4h 24m until
operator intervention.

Log evidence right before the hang:

06:35:14 WARNING [QQBot] WebSocket error: WebSocket closed
06:35:14 INFO    [QQBot] Reconnecting in 2s (attempt 1)...
06:35:46 WARNING [QQBot] Reconnect failed: Failed to get QQ Bot gateway URL:
# no further log lines for the next 4h+

py-spy dump against the wedged process (MainThread at ~100% CPU, all
other threads idle):

Thread <pid> (active+gil): "MainThread"
    _read_events (gateway/platforms/qqbot/adapter.py:656)
    _listen_loop (gateway/platforms/qqbot/adapter.py:492)
    run_gateway (hermes_cli/gateway.py:3255)
    ...

Side-effects of the hang:

  • Other platforms running on the same event loop (Telegram, cron ticker,
    heartbeats) silently stopped firing.
  • systemctl restart could not shut the process down — the asyncio
    signal handler never ran because the loop was starved. The process
    had to be SIGKILL'd.

Root cause

When _reconnect() fails before _open_ws() is entered (e.g.
_get_gateway_url() raises or returns empty), self._ws is left
pointing at the previous, already-closed ClientWebSocketResponse
— it is not None, and self._ws.closed is True.

The next _listen_loop iteration calls _read_events:

async def _read_events(self) -> None:
    if not self._ws:                              # _ws is not None, skipped
        raise RuntimeError("WebSocket not connected")

    while self._running and self._ws and not self._ws.closed:
        ...                                       # condition False, body never runs

The function returns. Back in _listen_loop:

while self._running:
    try:
        await self._read_events()   # returns immediately, no suspension
        backoff_idx = 0
        ...

Because no await in this path actually yields (_read_events only
suspends inside self._ws.receive(), which is unreachable), CPython
holds the GIL and the asyncio loop never runs any other task. From the
outside the process looks alive (PID present, Active: running) but is
completely unresponsive.

Fix

  • Treat self._ws is None or self._ws.closed as a precondition failure
    in _read_events and raise RuntimeError("WebSocket not connected").
    This routes control back to _listen_loop, which already handles the
    exception path and goes through _mark_transport_disconnected() +
    _reconnect().
  • Document the invariant in the docstring (the coroutine must terminate
    via raise or via self._running being cleared — never return
    normally on a non-functional socket) so future edits don't silently
    reintroduce the regression.

The change is intentionally small. The reconnect machinery itself is
already correct; the bug is specifically that _read_events is too
permissive about what counts as a runnable read.

Tests

Added tests/gateway/test_qqbot.py::TestReadEventsClosedSocket:

  • test_raises_when_ws_is_none — preserves the existing contract.
  • test_raises_when_ws_is_closed — pins the new behaviour and asserts
    receive() is never even called on a closed socket.
  • test_does_not_busy_spin_on_closed_socket — wraps the call in
    asyncio.wait_for(..., timeout=1.0) so a future regression surfaces
    as a CI timeout instead of an indefinite hang.

Full QQ-Bot test module passes locally:

$ ./venv/bin/python -m pytest tests/gateway/test_qqbot.py -q
...
147 passed, 1 warning in 15.97s

Risk / compatibility

  • No public API or configuration change.
  • Behaviour change is limited to the case _ws is not None and _ws.closed is True, which previously caused a silent infinite loop. In every
    branch where _listen_loop already expected an exception (transient
    WS error, server CLOSE, etc.) the new path is equivalent.
  • No new dependencies.

After a reconnect attempt fails before _open_ws can replace self._ws
(for example when _get_gateway_url returns an empty body), the adapter
is left with a stale, already-closed ClientWebSocketResponse. The next
iteration of _listen_loop re-enters _read_events, whose while-condition
is immediately False, so the coroutine returns normally. _listen_loop
then loops again without any suspending await, and the whole asyncio
event loop is starved at 100% CPU.

Observed in production: a single failed QQ gateway reconnect at 06:35
froze the process for 4+ hours. The main thread was pinned at
~100% CPU, all other platforms (Telegram, cron, heartbeats) stopped
firing, and 'systemctl restart' could not deliver SIGTERM because the
asyncio loop never yielded long enough to run the signal handler. The
process had to be SIGKILL'd.

Fix:
  * Treat 'self._ws is None or self._ws.closed' as a precondition
    failure in _read_events and raise so _listen_loop reaches its
    reconnect path instead of busy-looping.
  * Document the invariant in the docstring so future edits do not
    silently regress it.

Includes regression tests that fail (hang up to a 1s wait_for) without
the guard.
@alt-glitch alt-glitch added type/bug Something isn't working P2 Medium — degraded but workaround exists comp/gateway Gateway runner, session dispatch, delivery platform/qqbot QQ Bot adapter labels May 20, 2026
@alt-glitch

Copy link
Copy Markdown
Collaborator

Competing fix for the QQBot WebSocket busy-spin root issue #17703 — see also #27821, #29010, #20994 (all open PRs targeting the same bug). This PR has the most detailed root-cause analysis and includes production log evidence.

@teknium1

Copy link
Copy Markdown
Contributor

This has been implemented on current main, so I think this PR can be closed as superseded by the merged fix.

Evidence from this automated hermes-sweeper review:

  • gateway/platforms/qqbot/adapter.py:684 now checks self._ws.closed on entry to _read_events() and raises instead of returning normally on a closed-but-non-None socket.
  • gateway/platforms/qqbot/adapter.py:639 routes that exception through _listen_loop()'s existing disconnect/reconnect path.
  • tests/gateway/test_qqbot.py:2201 adds regression coverage for the closed WebSocket guard.
  • The fix landed in 3eeca4613d618618093db416b564a2b9ef8dbe6a via merged PR fix(qqbot): stop 100% CPU spin when WebSocket is closed but not None (#31193, #31771) #40574. The earlier maintainer comment here noting competing fixes for the same QQBot busy-spin issue lines up with that merged follow-up.

Thanks for the detailed production root-cause writeup; it matches the behavior now fixed on main.

@teknium1 teknium1 closed this Jun 15, 2026
@teknium1 teknium1 added the sweeper:implemented-on-main Sweeper: behavior already present on current main label Jun 15, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

comp/gateway Gateway runner, session dispatch, delivery P2 Medium — degraded but workaround exists platform/qqbot QQ Bot adapter sweeper:implemented-on-main Sweeper: behavior already present on current main type/bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants