mirror of
https://github.com/headroomlabs-ai/headroom.git
synced 2026-08-27 14:17:10 -04:00
f624d3a00a
Seven commits from one week of load testing: one hang, two request-path correctness fixes, and four hot-path costs that only show up in production. ## Reliability **Bound every upstream call.** The litellm backend had no timeout at all, so a request the upstream never answered blocked its caller forever. Observed under load on 2026-08-07: four agent workers on ESTABLISHED connections for 36+ minutes while `/readyz` answered in 0.11s. No error, no retry, no log line — indistinguishable from slow work, which is the worst shape a failure can take. A float rather than an `httpx.Timeout`, deliberately: litellm expands a float across all four httpx phases, so on a streaming call it becomes the maximum gap *between chunks*, not a cap on total generation. A long answer streaming steadily is never cut off; a stalled one dies. Default 600s via `HEADROOM_UPSTREAM_TIMEOUT`; 0, negative, and junk fall back to the default rather than meaning "no timeout". **Keep the consistency re-count off the event loop.** It ran `tokenizer.count_messages` twice directly on the loop. Since Claude counting moved to a real BPE that is CPU-bound work stalling every other in-flight request — ~1s on a 2.3 MB body, with `/healthz` gaps tracking body size. Offloaded via `asyncio.to_thread` on the same tokenizer instance, so reported values are unchanged. (#2810) **Survive a re-parse MemoryError.** `MemoryError` is not a `ValueError`, so on 1M-context payloads the byte-faithful forwarder's verification re-parse escaped the handler and aborted an otherwise-fine request — 14 aborts across 8 days of reporter logs. (#2768) ## Performance All four are measured, not guessed. Each degrades with something a short benchmark does not vary: uptime, content shape, or process age. | fix | before | after | |---|---|---| | Cost-record walk per request (at 100k records) | 13.6 ms | bounded by model count | | JSON-block scan, JS-style object logs (1200 lines) | 4643 ms | 183 ms | | JSON-block scan, truncated JSONL | 3737 ms | 116 ms | | Lazy imports inside user requests | multi-second | paid at startup | | `count_text` (80% of local CPU) | — | memoised | Two worth calling out: - **The cost walk degrades with proxy *uptime*, not load.** A freshly started proxy pays ~0.01 ms; a month-old one pays 4–13 ms on every request, on the event loop, holding the metrics lock. Deliberately not a TTL cache over `stats()`: those values feed `check_budget()` when `--budget` is set, and a stale reading under-enforces the budget. The fix is to stop computing what the caller discards. - **The JSON-block memo is built only *after* a scan fails to balance.** That ordering is load-bearing, not an optimisation — caching from the start made pretty-printed JSON ~2x slower, since content that balances on the first scan has nothing to reuse and just pays the per-line dict traffic. Still a constant-factor fix, not an asymptotic one. ## Tests +1202 lines, 20 files. Each fix is pinned by a test that fails on the unmodified code: the re-count test asserts no `count_messages` pass runs with a live event loop in its thread; the re-parse test drives a `MemoryError` through the real request path and expects a 200; `totals()` equality with `stats()` is asserted across model counts, request volumes, and both pricing branches. The timeout test is structural rather than a mock — the failure mode is a dispatch path someone adds later without a guard, which mocking the existing four cannot catch. 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
70 lines
2.4 KiB
Python
70 lines
2.4 KiB
Python
"""Every upstream call must be bounded.
|
|
|
|
There was no timeout in this backend at all. Observed 2026-08-07 under load:
|
|
four agent workers blocked on ESTABLISHED connections for 36+ minutes while
|
|
the proxy answered /readyz in 0.11s. No error, no retry, no log line -- the
|
|
caller simply stops, forever, and that is indistinguishable from slow work.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import ast
|
|
from pathlib import Path
|
|
|
|
import pytest
|
|
|
|
from headroom.backends.litellm import (
|
|
DEFAULT_UPSTREAM_TIMEOUT,
|
|
UPSTREAM_TIMEOUT_ENV,
|
|
_upstream_timeout,
|
|
)
|
|
|
|
_SRC = Path(__file__).resolve().parents[1] / "headroom" / "backends" / "litellm.py"
|
|
|
|
|
|
def test_every_acompletion_call_is_bounded():
|
|
"""A new dispatch path added without a timeout reintroduces the hang.
|
|
|
|
Checked structurally rather than by mocking, because the failure mode is a
|
|
call site someone ADDS later -- which no mock of the existing paths sees.
|
|
"""
|
|
tree = ast.parse(_SRC.read_text())
|
|
calls, guards = 0, 0
|
|
for node in ast.walk(tree):
|
|
if not isinstance(node, ast.Call):
|
|
continue
|
|
fn = node.func
|
|
if isinstance(fn, ast.Name) and fn.id == "acompletion":
|
|
calls += 1
|
|
if (
|
|
isinstance(fn, ast.Attribute)
|
|
and fn.attr == "setdefault"
|
|
and node.args
|
|
and isinstance(node.args[0], ast.Constant)
|
|
and node.args[0].value == "timeout"
|
|
):
|
|
guards += 1
|
|
assert calls > 0, "no acompletion call sites found -- test is stale"
|
|
assert guards >= calls, (
|
|
f"{calls} acompletion call site(s) but only {guards} timeout guard(s); "
|
|
"an unbounded upstream call blocks its caller forever"
|
|
)
|
|
|
|
|
|
def test_a_junk_env_value_cannot_disable_the_timeout(monkeypatch):
|
|
"""`0` means 'no timeout' to httpx, i.e. exactly the bug. So does junk."""
|
|
for bad in ("", "0", "-1", "nonsense", "None"):
|
|
monkeypatch.setenv(UPSTREAM_TIMEOUT_ENV, bad)
|
|
assert _upstream_timeout() == DEFAULT_UPSTREAM_TIMEOUT, bad
|
|
|
|
|
|
def test_an_operator_can_still_tune_it(monkeypatch):
|
|
monkeypatch.setenv(UPSTREAM_TIMEOUT_ENV, "42.5")
|
|
assert _upstream_timeout() == pytest.approx(42.5)
|
|
|
|
|
|
def test_the_default_is_generous_enough_for_real_work():
|
|
"""Streaming: litellm expands a float across all httpx phases, so this is
|
|
the max gap BETWEEN CHUNKS, not a cap on total generation. A steady long
|
|
answer is never cut off."""
|
|
assert 60.0 <= DEFAULT_UPSTREAM_TIMEOUT <= 1800.0
|