mirror of
https://github.com/headroomlabs-ai/headroom.git
synced 2026-08-27 14:17:10 -04:00
## Summary Multiple Windows users reported (via Discord, on v0.23.0, `pip install "headroom-ai[all]"`) that the proxy delivers **zero compression** and adds **+30s latency to every request**: `Optimization failed: TimeoutError:` with `compression_first_stage ≈ 30000ms` on every optimization attempt, for the lifetime of the process. Log analysis showed the wedge starts at the **first message eligible for real compression** (earlier requests succeed because everything is skipped/excluded) — and never recovers, even though the Kompress model loaded successfully at startup. ### Root cause chain 1. `create_cpu_session_options` disabled ONNX Runtime's CPU memory arena on **all** platforms. On Windows this is catastrophic: every `Run()` falls back to per-node `VirtualAlloc`/free, slowing ModernBERT inference by 2–3 orders of magnitude (onnxruntime#11627). One reporter's perf summary showed max optimization overhead of **200,369ms** (~13 chunks × ~15s) — slow, not deadlocked. 2. The first slow inference outlives the proxy's 30s compression-stage timeout. `asyncio.wait_for` abandons the future but **cannot kill the executor thread**, which keeps holding the Kompress `BoundedSemaphore(1)`. 3. Every later compression blocks on an **unbounded** `semaphore.acquire()`, times out at exactly 30s, and leaks another thread — permanently wedging the proxy until restart. Two adjacent Windows bugs found in the same logs are fixed too: `subprocess.run(text=True)` without `encoding=` decodes child output with cp1252, so rtk's emoji output killed reader threads (`UnicodeDecodeError: 'charmap' codec can't decode byte 0x8f`); and the OpenAI handler logged `Optimization failed: ` with an empty message because `str(asyncio.TimeoutError())` is empty. ### Fixes - **`onnx_runtime.py`** — keep the CPU arena at ORT's default on Windows; Linux/macOS keep the legacy low-RSS behavior (arena disabled) bit-for-bit. New `HEADROOM_ONNX_CPU_ARENA` env overrides either way. All ONNX sessions (Kompress, image router, memory embedders) share this helper, so one fix covers them all. - **`kompress_compressor.py`** — three layers of wedge-proofing, each fail-safing to passthrough instead of blocking: - bounded semaphore acquire (`HEADROOM_KOMPRESS_ACQUIRE_TIMEOUT_SECONDS`, default 5s) - wall-clock budget per compress/compress_batch call (`HEADROOM_KOMPRESS_TIME_BUDGET_SECONDS`, default 20s — under the 30s stage timeout, so Kompress gives up before the request is abandoned). Batch bail never emits a partially-covered text. - preload canary (`HEADROOM_KOMPRESS_CANARY_SECONDS`, default 5s, one retry to forgive cold-start warmup): machines that can never finish inference inside the stage timeout get ML compression disabled up front with one actionable warning, instead of a guaranteed 30s timeout per request. - Setting any knob `<= 0` disables that guard (restores legacy behavior). First give-up logs at WARNING with remediation hints; repeats drop to DEBUG. - **`proxy/helpers.py`, `interceptors/astgrep.py`** — `encoding="utf-8", errors="replace"` on rtk/lean-ctx/ast-grep subprocess calls. - **`handlers/openai.py`** — failure log now includes request id + exception type, matching the Anthropic handler. ### Non-Windows perf - Session options on Linux/macOS are unchanged (pinned by tests). - The only new hot-path cost is one `time.monotonic()` + a bounded acquire per chunk: micro-benchmarked at sub-microsecond (bounded acquire measured marginally *faster* than the old context-manager acquire), vs 50–500ms of inference per chunk. - Real-model smoke run on macOS: identical compression output (ratio 0.262 on a 1020-word sample), canary passes, budget/acquire give-up paths verified against the real ONNX stack by forcing tiny env values. Related (same symptom, different root cause — **not** addressed here): #810 tracks the blocked-tiktoken-download hang, which produces the same per-request 30s `TimeoutError` signature. The bounded-acquire/budget changes in this PR limit the blast radius of Kompress-side slowness only. ## Validation - `.venv/bin/ruff check headroom/ tests/...` — clean - `.venv/bin/ruff format --check` — clean (355 files) - `.venv/bin/mypy` on all five changed source files — no issues - `python -m pytest tests/test_onnx_runtime.py tests/test_kompress_failsafe.py tests/test_subprocess_encoding.py` — 25 passed (new coverage: arena platform matrix + env overrides, stuck-semaphore passthrough for compress and batch, budget bail incl. mid-batch no-data-loss, canary trip/pass/retry/disable/error-safety, UTF-8 subprocess kwargs) - `python -m pytest tests/test_transforms_content_router.py tests/test_proxy_handler_helpers.py tests/test_codex_ws_compression_scheduler.py tests/test_proxy_warmup.py tests/test_proxy_pipeline_lifecycle.py` — 52 passed (existing suites for touched areas) <!-- headroom-maintainer-template-completion:start --> ## Description This PR prepares `fix(windows): unwedge compression on degraded ONNX runtimes (every request timing out at 30s, 0% savings)` for review by documenting the intended change, validation evidence, and remaining merge-readiness context. Linked issues: None declared. ## Type of Change - [x] Bug fix - [ ] New feature - [ ] Documentation - [ ] Refactor - [ ] Tests only ## Changes Made - Commit: fix(windows): unwedge compression on degraded ONNX runtimes - Commit: fix(kompress): run preload canary off the startup path - Touches `headroom/onnx_runtime.py` - Touches `headroom/proxy/handlers/openai.py` - Touches `headroom/proxy/helpers.py` - Touches `headroom/proxy/interceptors/astgrep.py` - Touches `headroom/transforms/kompress_compressor.py` - Touches `tests/test_kompress_failsafe.py` ## Testing - [x] GitHub checks reviewed - [x] Metadata/template validation - [ ] Local functional testing ### Test Output ```text gh pr view 822 --repo chopratejas/headroom --json statusCheckRollup - CI / changes: SUCCESS - CodeQL / Analyze (actions): SUCCESS - Evaluation Suite / smoke-test: SUCCESS - Init E2E / docker-init-e2e: SUCCESS - PR Governance / label: SUCCESS - Wrap E2E / docker-wrap-e2e: SUCCESS - CodeQL / Analyze (c-cpp): SUCCESS - CodeQL / Analyze (javascript-typescript): SUCCESS - CodeQL / Analyze (python): SUCCESS - CodeQL / Analyze (rust): SUCCESS - Evaluation Suite / weekly-suite: SKIPPED - CI / commitlint: SUCCESS ``` ## Real Behavior Proof - Environment: GitHub PR metadata and checks for `chopratejas/headroom` PR #822. - Exact command / steps: Reviewed PR title, commits, changed files, linked issues, labels, and check rollup; appended this maintainer template completion block without replacing the author's original description. - Observed result: PR body now contains all required governance sections, checked readiness fields, and a non-placeholder validation evidence block. - Not tested: This pass updated PR metadata only; code validation remains represented by the linked GitHub checks and any author-provided evidence above. ## Review Readiness - [x] I have performed a self-review - [x] This PR is ready for human review <!-- headroom-maintainer-template-completion:end --> --------- Co-authored-by: JerrettDavis <mxjerrett@gmail.com>
55 lines
1.8 KiB
Python
55 lines
1.8 KiB
Python
"""Proxy-runtime subprocess calls must decode UTF-8 explicitly.
|
|
|
|
On Windows, ``subprocess.run(text=True)`` without an ``encoding`` decodes
|
|
child output with the console code page (cp1252). rtk's emoji-laden output
|
|
then kills the reader thread with ``UnicodeDecodeError: 'charmap' codec
|
|
can't decode byte ...`` (seen in user proxy logs). These tests pin the
|
|
``encoding="utf-8"`` kwarg on every proxy-runtime subprocess call.
|
|
"""
|
|
|
|
import subprocess
|
|
|
|
import headroom.lean_ctx
|
|
import headroom.proxy.helpers as helpers
|
|
import headroom.rtk
|
|
from headroom.proxy.interceptors import astgrep
|
|
|
|
|
|
def _capture_run(captured, returncode=0, stdout='{"summary": {}}'):
|
|
def fake_run(cmd, **kwargs):
|
|
captured.update(kwargs)
|
|
return subprocess.CompletedProcess(cmd, returncode, stdout=stdout, stderr="")
|
|
|
|
return fake_run
|
|
|
|
|
|
def test_rtk_stats_subprocess_uses_utf8(monkeypatch):
|
|
captured: dict = {}
|
|
monkeypatch.setattr(helpers, "run", _capture_run(captured))
|
|
monkeypatch.setattr(headroom.rtk, "get_rtk_path", lambda: "/fake/rtk")
|
|
|
|
helpers._read_rtk_lifetime_stats()
|
|
|
|
assert captured["encoding"] == "utf-8"
|
|
assert captured["errors"] == "replace"
|
|
|
|
|
|
def test_lean_ctx_stats_subprocess_uses_utf8(monkeypatch):
|
|
captured: dict = {}
|
|
monkeypatch.setattr(helpers, "run", _capture_run(captured))
|
|
monkeypatch.setattr(headroom.lean_ctx, "get_lean_ctx_path", lambda: "/fake/lean-ctx")
|
|
|
|
helpers._read_lean_ctx_lifetime_stats()
|
|
|
|
assert captured["encoding"] == "utf-8"
|
|
assert captured["errors"] == "replace"
|
|
|
|
|
|
def test_ast_grep_subprocess_uses_utf8(monkeypatch):
|
|
captured: dict = {}
|
|
monkeypatch.setattr(astgrep.subprocess, "run", _capture_run(captured, returncode=1, stdout=""))
|
|
|
|
astgrep._run_ast_grep("/fake/sg", "python", "def foo():\n pass\n")
|
|
|
|
assert captured["encoding"] == "utf-8"
|
|
assert captured["errors"] == "replace"
|