diff --git a/CHANGELOG.md b/CHANGELOG.md index 0bb94435..fc691eb8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,8 @@ ### Fixed +- **The background-task completion drain thread can no longer spin at 100% CPU when the process registry is (re)initializing.** If the registry didn't yet expose its `completion_queue`, the drain loop's broad `except Exception: continue` swallowed the `AttributeError` and immediately retried with no delay — a hot loop. The loop now reads the queue defensively (`getattr(..., None)`) and backs off on the stop event when it's missing, catches `queue.Empty` separately as the normal idle path, and logs (no longer silently swallows) any unexpected queue error before backing off. No delivery latency is added — real completions are still drained on the 1 Hz blocking `get`. Thanks @ai-ag2026. (#5782, #2476, #4633) + - **Passkey login no longer risks a hung or mis-framed response on keep-alive connections.** The passkey-login success `200` was written without a `Content-Length` header, so a client on a persistent connection could wait for a body boundary that never came or mis-frame the next response. The response now sends an explicit `Content-Length` matching the body's byte length. Thanks @ai-ag2026. (#5785) - **Zero-token turns (a pre-flight cancel or setup error) no longer leak a streaming-meter session.** The streaming meter's `begin_session()` and its 1 Hz ticker were started before the outer `try`, so a raise or cancel before the first token left the `_sessions[stream_id]` entry unreclaimed (`get_stats()` only prunes sessions that emitted a token), inflating the SSE `active` count over a long-lived server. `begin_session()` + the ticker start now live inside the outer `try` so the paired `end_session()` / ticker-stop teardown in the `finally` always runs. Thanks @ai-ag2026. (#5787, #4633, #2476) diff --git a/api/background_process.py b/api/background_process.py index 7147291d..754c31c3 100644 --- a/api/background_process.py +++ b/api/background_process.py @@ -1325,10 +1325,28 @@ def _drain_loop() -> None: return logger.info("bg_task_complete drain thread started") while not _DRAIN_STOP.is_set(): + # Read the queue defensively: a rebuilt/partially-initialized registry + # may not expose ``completion_queue`` (mirrors streaming.py's + # ``getattr(process_registry, 'completion_queue', None)`` guard). Direct + # attribute access here would raise AttributeError, which the old broad + # ``except Exception: continue`` swallowed silently and re-tried with no + # backoff — a 100%-CPU tight loop. Back off on the stop event instead. + q = getattr(process_registry, "completion_queue", None) + if q is None: + _DRAIN_STOP.wait(1.0) + continue try: - evt = process_registry.completion_queue.get(timeout=1.0) + evt = q.get(timeout=1.0) + except queue.Empty: + # Nothing to drain this second — re-check the stop flag and loop. + continue except Exception: - # queue.Empty or transient — re-check stop flag and continue. + # Unexpected queue failure: log it (not silent) and back off on the + # stop event so a persistent error can't spin the thread hot. + logger.warning( + "bg_task_complete drain queue read failed", exc_info=True + ) + _DRAIN_STOP.wait(1.0) continue if not isinstance(evt, dict): continue diff --git a/tests/test_bg_task_drain_loop_backoff.py b/tests/test_bg_task_drain_loop_backoff.py new file mode 100644 index 00000000..38341424 --- /dev/null +++ b/tests/test_bg_task_drain_loop_backoff.py @@ -0,0 +1,129 @@ +"""Regression test for the bg_task_complete drain-loop tight-spin (#2476, #4633). + +``_drain_loop`` read ``process_registry.completion_queue`` directly and wrapped +it in a bare ``except Exception: continue``. A registry missing that attribute +raised ``AttributeError`` that was swallowed and retried with no backoff — a +100%-CPU tight loop with no log line. The loop now: + + * reads the queue via ``getattr(process_registry, 'completion_queue', None)`` + and backs off on the stop event when it is absent (mirrors streaming.py), + * catches ``queue.Empty`` explicitly (the normal idle path → plain continue), + * logs + backs off on any other queue error instead of tight-looping. + +Uses the shared ``install_fake_registry`` stub helper (see ``_wakeup_helpers``). +""" + +from __future__ import annotations + +import queue +import threading + +from tests._wakeup_helpers import install_fake_registry + + +class _CountingStop: + """Stand-in for ``_DRAIN_STOP`` that records ``wait()`` and self-terminates. + + In the OLD (buggy) code the missing-queue path hit ``continue`` and never + touched the stop event's ``wait`` — it just re-spun on ``is_set()``. So a + recorded ``wait(1.0)`` call is exactly the proof the backoff path was taken. + ``wait`` sets the flag after ``exit_after`` calls so the loop exits promptly + without any real sleep, keeping the test deterministic and fast. + """ + + def __init__(self, exit_after: int = 1): + self._flag = threading.Event() + self.wait_calls: list[float | None] = [] + self._exit_after = exit_after + + def is_set(self) -> bool: + return self._flag.is_set() + + def set(self) -> None: + self._flag.set() + + def clear(self) -> None: + self._flag.clear() + + def wait(self, timeout=None): + self.wait_calls.append(timeout) + if len(self.wait_calls) >= self._exit_after: + self._flag.set() + return self._flag.is_set() + + +def _run_drain_with_stop(monkeypatch, fake_registry, stop) -> threading.Thread: + from api import background_process as bp + + install_fake_registry(monkeypatch, fake_registry) + monkeypatch.setattr(bp, "_DRAIN_STOP", stop, raising=True) + t = threading.Thread(target=bp._drain_loop, name="test-drain", daemon=True) + t.start() + return t + + +def test_missing_completion_queue_backs_off_instead_of_spinning(monkeypatch): + """A registry with no completion_queue must back off, not tight-loop.""" + + class _NoQueueRegistry: + pass # deliberately no completion_queue attribute + + stop = _CountingStop(exit_after=1) + t = _run_drain_with_stop(monkeypatch, _NoQueueRegistry(), stop) + t.join(timeout=3.0) + + assert not t.is_alive(), "drain loop did not terminate on stop" + # The backoff path ran: wait() was called with the 1.0s backoff timeout. + assert stop.wait_calls, "missing-queue path did not back off (tight loop)" + assert stop.wait_calls[0] == 1.0 + + +def test_non_empty_queue_error_logs_and_backs_off(monkeypatch): + """A non-Empty queue error is logged and backed off, not swallowed silently.""" + + class _BoomQueue: + def get(self, timeout=None): + raise RuntimeError("queue exploded") + + class _BoomRegistry: + completion_queue = _BoomQueue() + + stop = _CountingStop(exit_after=1) + t = _run_drain_with_stop(monkeypatch, _BoomRegistry(), stop) + t.join(timeout=3.0) + + assert not t.is_alive() + assert stop.wait_calls and stop.wait_calls[0] == 1.0 + + +def test_empty_queue_is_the_plain_continue_path(monkeypatch): + """queue.Empty is the normal idle path: continue, no backoff wait().""" + + class _EmptyQueue: + def __init__(self, stop): + self._stop = stop + + def get(self, timeout=None): + # Stop the loop after being polled once so the test terminates, + # then raise Empty like a real idle queue. + self._stop.set() + raise queue.Empty + + class _EmptyRegistry: + pass + + stop = _CountingStop(exit_after=99) # effectively never self-terminates + reg = _EmptyRegistry() + reg.completion_queue = _EmptyQueue(stop) + t = _run_drain_with_stop(monkeypatch, reg, stop) + t.join(timeout=3.0) + + assert not t.is_alive() + # Empty took the explicit `continue` path — no backoff wait() was recorded. + assert stop.wait_calls == [] + + +if __name__ == "__main__": # pragma: no cover - manual invocation + import pytest + + raise SystemExit(pytest.main([__file__, "-v"]))