fix(proxy): fail-open on corrupt golden bytes instead of RuntimeError (#603)

* fix(proxy): fail-open on corrupt golden bytes instead of RuntimeError

Permanent session corruption: once golden bytes become unreadable
(UnicodeDecodeError / JSONDecodeError), every subsequent request for
the session raised RuntimeError, returning 500 until proxy restart.

Fix: log at ERROR level and recover — skip the corrupt memory tool,
or regenerate a fresh CCR definition — rather than propagating
RuntimeError and permanently breaking the session.

Also change proxy_inbound_request_aborted from logger.info to
logger.error with exc_info=True so tracebacks appear in logs.

Closes: proxy silent-500 sessions in the wild (observed 2026-06-04)

* fix(tests): re-enable headroom log propagation in corrupt-bytes tests

configure_proxy_logging() sets headroom_logger.propagate = False to prevent
duplicate writes when the proxy redirects stderr to a log file. In CI the
proxy initialises its logging stack before the test suite, leaving propagation
disabled. pytest's caplog handler attaches to the root logger, so records that
stop at the headroom logger are never captured.

Added _enable_headroom_log_propagation autouse fixture that temporarily
re-enables propagation for the duration of each test, making caplog capture
work regardless of the surrounding logging configuration.

* fix(tests): remove unused imports from corrupt-bytes regression tests

Remove json, SessionCcrTracker, and SessionToolTracker imports that were
imported but never referenced in the test body. Fixes ruff F401 and I001
lint errors reported by CI.

---------

Co-authored-by: Patrick Ancillotti <patrick.ancillotti@people.inc>

headroom/proxy/helpers.py

@@ -2304,11 +2304,14 @@ def apply_session_sticky_memory_tools(
             try:
                 tool_def = json.loads(golden_bytes.decode("utf-8"))
             except (UnicodeDecodeError, json.JSONDecodeError) as exc:
-                # Should never happen — golden bytes were produced by us.
+                logger.error(
-                # Loud failure per build constraint #4.
+                    "corrupt golden tool bytes for session %s tool %s: %s — skipping tool injection",
-                raise RuntimeError(
+                    session_id,
-                    f"corrupt golden tool bytes for session {session_id} tool {tool_name}: {exc}"
+                    tool_name,
-                ) from exc
+                    exc,
+                    exc_info=True,
+                )
+                continue
             tools_out.append(tool_def)
             existing_names.add(tool_name)
             replay_bytes += len(golden_bytes)
@@ -2584,21 +2587,24 @@ def apply_session_sticky_ccr_tool(
         if golden is not None:
             try:
                 tool_def = json.loads(golden.decode("utf-8"))
+                tools_out.append(tool_def)
+                log_tool_injection_decision(
+                    provider=provider,
+                    session_id=session_id,
+                    decision="inject_sticky_replay",
+                    tool_definition_bytes_count=len(golden),
+                    request_id=request_id,
+                )
+                return tools_out, True
             except (UnicodeDecodeError, json.JSONDecodeError) as exc:
-                # Should never happen — golden bytes were produced by us.
+                logger.error(
-                raise RuntimeError(
+                    "corrupt golden CCR tool bytes for session %s: %s — regenerating fresh definition",
-                    f"corrupt golden CCR tool bytes for session {session_id}: {exc}"
+                    session_id,
-                ) from exc
+                    exc,
-            tools_out.append(tool_def)
+                    exc_info=True,
-            log_tool_injection_decision(
+                )
-                provider=provider,
+                # Fall through to fresh creation below
-                session_id=session_id,
+        # Tracker says "done CCR" but has no golden bytes (or they were corrupt). Pin
-                decision="inject_sticky_replay",
-                tool_definition_bytes_count=len(golden),
-                request_id=request_id,
-            )
-            return tools_out, True
-        # Tracker says "done CCR" but somehow has no golden bytes. Pin
         # them now so future turns are stable.
         tool_def = create_ccr_tool_definition(provider)
         canonical = serialize_tool_definition_canonical(tool_def)

headroom/proxy/server.py

@@ -1761,7 +1761,7 @@ def create_app(config: ProxyConfig | None = None) -> FastAPI:
                 proxy.metrics.record_inbound_aborted(reason=type(exc).__name__)
             except Exception:
                 logger.debug("record_inbound_aborted failed", exc_info=True)
-            logger.info(
+            logger.error(
                 "event=proxy_inbound_request_aborted id=%s method=%s path=%s reason=%s "
                 "duration_ms=%.2f",
                 inbound_id,
@@ -1769,6 +1769,7 @@ def create_app(config: ProxyConfig | None = None) -> FastAPI:
                 path,
                 type(exc).__name__,
                 (time.perf_counter() - started) * 1000.0,
+                exc_info=True,
             )
             raise
         try:

tests/test_corrupt_golden_bytes_recovery.py

@@ -0,0 +1,288 @@
+"""Regression tests for corrupt golden bytes fail-open recovery.
+
+Guards against:
+- Bug: corrupt (invalid JSON/bytes) golden tool definitions previously raised
+  RuntimeError, permanently breaking the session until proxy restart.
+- Fix: log at ERROR and recover — skip the corrupt memory tool entry, or
+  regenerate a fresh CCR definition — rather than propagating RuntimeError.
+
+Covers both injection sites:
+  1. apply_session_sticky_memory_tools (memory tool golden bytes)
+  2. apply_session_sticky_ccr_tool (CCR golden bytes)
+"""
+
+from __future__ import annotations
+
+import logging
+from collections.abc import Iterator
+from typing import Any
+
+import pytest
+
+from headroom.proxy.helpers import (
+    _reset_session_ccr_tracker_for_test,
+    _reset_session_tool_tracker_for_test,
+    apply_session_sticky_ccr_tool,
+    apply_session_sticky_memory_tools,
+    get_session_ccr_tracker,
+    get_session_tool_tracker,
+    serialize_tool_definition_canonical,
+)
+
+# ---------------------------------------------------------------------------
+# Test isolation
+# ---------------------------------------------------------------------------
+
+
+@pytest.fixture(autouse=True)
+def _reset_trackers() -> None:
+    _reset_session_tool_tracker_for_test()
+    _reset_session_ccr_tracker_for_test()
+    yield
+    _reset_session_tool_tracker_for_test()
+    _reset_session_ccr_tracker_for_test()
+
+
+@pytest.fixture(autouse=True)
+def _enable_headroom_log_propagation() -> Iterator[None]:
+    """Re-enable propagation on the headroom logger during tests.
+
+    configure_proxy_logging() calls headroom_logger.propagate = False to prevent
+    duplicate writes when the proxy redirects stderr to a log file. In CI the proxy
+    may initialise its logging before the test suite runs, leaving propagation
+    disabled. pytest's caplog attaches its handler to the root logger, so it only
+    sees records that propagate all the way up. This fixture re-enables propagation
+    for the duration of each test so caplog captures headroom log records correctly.
+    """
+    headroom_logger = logging.getLogger("headroom")
+    original = headroom_logger.propagate
+    headroom_logger.propagate = True
+    yield
+    headroom_logger.propagate = original
+
+
+# ---------------------------------------------------------------------------
+# Helpers
+# ---------------------------------------------------------------------------
+
+
+def _make_memory_tool_def(name: str) -> dict[str, Any]:
+    return {"name": name, "description": "test tool", "input_schema": {"type": "object"}}
+
+
+def _seed_memory_tool(
+    provider: str,
+    session_id: str,
+    tool_name: str,
+    tool_bytes: bytes,
+) -> None:
+    tracker = get_session_tool_tracker()
+    tracker.record_injection(
+        provider=provider,
+        session_id=session_id,
+        tool_name=tool_name,
+        tool_definition_bytes=tool_bytes,
+    )
+
+
+def _seed_ccr_done(
+    provider: str,
+    session_id: str,
+    golden_bytes: bytes,
+) -> None:
+    tracker = get_session_ccr_tracker()
+    tracker.record_ccr_done(provider, session_id, golden_bytes)
+
+
+# ---------------------------------------------------------------------------
+# Fix 1a: apply_session_sticky_memory_tools — corrupt memory golden bytes
+# ---------------------------------------------------------------------------
+
+
+class TestCorruptMemoryGoldenBytes:
+    """Corrupt memory tool bytes must not raise RuntimeError."""
+
+    def test_corrupt_bytes_does_not_raise(self) -> None:
+        """Invalid JSON golden bytes: no RuntimeError, returns normally."""
+        session_id = "sess-corrupt-mem-1"
+        _seed_memory_tool("anthropic", session_id, "memory_save", b"NOT_VALID_JSON{{{")
+
+        # Must not raise.
+        tools_out, was_injected = apply_session_sticky_memory_tools(
+            provider="anthropic",
+            session_id=session_id,
+            request_id="req-1",
+            existing_tools=None,
+            memory_tools_to_inject=[_make_memory_tool_def("memory_save")],
+            inject_this_turn=True,
+        )
+        # The corrupt entry is skipped; no tool injected from golden bytes.
+        assert isinstance(tools_out, list)
+
+    def test_corrupt_bytes_logs_error(self, caplog: pytest.LogCaptureFixture) -> None:
+        """Corrupt golden bytes are logged at ERROR level with exc_info."""
+        session_id = "sess-corrupt-mem-2"
+        _seed_memory_tool("anthropic", session_id, "memory_search", b"\xff\xfe invalid")
+
+        with caplog.at_level(logging.ERROR, logger="headroom.proxy"):
+            apply_session_sticky_memory_tools(
+                provider="anthropic",
+                session_id=session_id,
+                request_id="req-2",
+                existing_tools=None,
+                memory_tools_to_inject=[_make_memory_tool_def("memory_search")],
+                inject_this_turn=True,
+            )
+
+        error_records = [r for r in caplog.records if r.levelno >= logging.ERROR]
+        assert error_records, "Expected at least one ERROR log for corrupt golden bytes"
+        assert any("corrupt" in r.getMessage().lower() for r in error_records)
+        # exc_info must be attached so the traceback appears in logs.
+        assert any(r.exc_info is not None for r in error_records)
+
+    def test_valid_tool_survives_alongside_corrupt_entry(self) -> None:
+        """A valid second tool is still injected even when one entry is corrupt."""
+        session_id = "sess-corrupt-mem-3"
+        valid_def = _make_memory_tool_def("memory_search")
+        valid_bytes = serialize_tool_definition_canonical(valid_def)
+
+        _seed_memory_tool("anthropic", session_id, "memory_save", b"CORRUPT_JSON")
+        _seed_memory_tool("anthropic", session_id, "memory_search", valid_bytes)
+
+        tools_out, was_injected = apply_session_sticky_memory_tools(
+            provider="anthropic",
+            session_id=session_id,
+            request_id="req-3",
+            existing_tools=None,
+            memory_tools_to_inject=[
+                _make_memory_tool_def("memory_save"),
+                _make_memory_tool_def("memory_search"),
+            ],
+            inject_this_turn=True,
+        )
+
+        # Valid entry must be present.
+        names = [t.get("name") for t in tools_out]
+        assert "memory_search" in names, "valid tool should survive corrupt sibling"
+
+    def test_unicode_decode_error_handled(self, caplog: pytest.LogCaptureFixture) -> None:
+        """UnicodeDecodeError from non-UTF-8 bytes is also handled gracefully."""
+        session_id = "sess-corrupt-mem-4"
+        # Bytes that are not valid UTF-8.
+        _seed_memory_tool("anthropic", session_id, "memory_save", b"\x80\x81\x82\x83")
+
+        with caplog.at_level(logging.ERROR, logger="headroom.proxy"):
+            # Must not raise RuntimeError or UnicodeDecodeError.
+            apply_session_sticky_memory_tools(
+                provider="anthropic",
+                session_id=session_id,
+                request_id="req-4",
+                existing_tools=None,
+                memory_tools_to_inject=[_make_memory_tool_def("memory_save")],
+                inject_this_turn=True,
+            )
+
+        error_records = [r for r in caplog.records if r.levelno >= logging.ERROR]
+        assert error_records
+
+
+# ---------------------------------------------------------------------------
+# Fix 1b: apply_session_sticky_ccr_tool — corrupt CCR golden bytes
+# ---------------------------------------------------------------------------
+
+
+class TestCorruptCcrGoldenBytes:
+    """Corrupt CCR tool bytes must not raise RuntimeError; fresh def regenerated."""
+
+    def test_corrupt_bytes_does_not_raise(self) -> None:
+        """Invalid JSON in CCR golden bytes: no RuntimeError."""
+        session_id = "sess-corrupt-ccr-1"
+        _seed_ccr_done("anthropic", session_id, b"NOT_VALID_JSON{{{")
+
+        # Must not raise.
+        tools_out, was_injected = apply_session_sticky_ccr_tool(
+            provider="anthropic",
+            session_id=session_id,
+            request_id="req-1",
+            existing_tools=None,
+            has_compressed_content_this_turn=False,
+        )
+        assert isinstance(tools_out, list)
+
+    def test_corrupt_bytes_logs_error(self, caplog: pytest.LogCaptureFixture) -> None:
+        """Corrupt CCR golden bytes are logged at ERROR level with exc_info."""
+        session_id = "sess-corrupt-ccr-2"
+        _seed_ccr_done("anthropic", session_id, b"bad bytes {")
+
+        with caplog.at_level(logging.ERROR, logger="headroom.proxy"):
+            apply_session_sticky_ccr_tool(
+                provider="anthropic",
+                session_id=session_id,
+                request_id="req-2",
+                existing_tools=None,
+                has_compressed_content_this_turn=False,
+            )
+
+        error_records = [r for r in caplog.records if r.levelno >= logging.ERROR]
+        assert error_records, "Expected at least one ERROR log for corrupt CCR golden bytes"
+        assert any("corrupt" in r.getMessage().lower() for r in error_records)
+        assert any(r.exc_info is not None for r in error_records)
+
+    def test_corrupt_bytes_falls_through_to_fresh_definition(self) -> None:
+        """After corrupt bytes, a valid fresh CCR tool definition is injected."""
+        session_id = "sess-corrupt-ccr-3"
+        _seed_ccr_done("anthropic", session_id, b"CORRUPT_JSON_HERE")
+
+        tools_out, was_injected = apply_session_sticky_ccr_tool(
+            provider="anthropic",
+            session_id=session_id,
+            request_id="req-3",
+            existing_tools=None,
+            has_compressed_content_this_turn=False,
+        )
+
+        # A fresh CCR tool definition must have been regenerated and injected.
+        assert was_injected is True, "Should still inject a fresh CCR tool after corrupt bytes"
+        assert len(tools_out) == 1, "Exactly one CCR tool should be injected"
+        # Verify it is a valid tool definition (JSON-serializable with a name).
+        tool = tools_out[0]
+        name = tool.get("name") or tool.get("function", {}).get("name")
+        assert name is not None, "Regenerated tool definition must have a name"
+
+    def test_unicode_decode_error_falls_through_to_fresh_definition(self) -> None:
+        """UnicodeDecodeError in CCR golden bytes also triggers fresh definition."""
+        session_id = "sess-corrupt-ccr-4"
+        # Non-UTF-8 bytes.
+        _seed_ccr_done("anthropic", session_id, b"\x80\x81\x82\x83")
+
+        tools_out, was_injected = apply_session_sticky_ccr_tool(
+            provider="anthropic",
+            session_id=session_id,
+            request_id="req-4",
+            existing_tools=None,
+            has_compressed_content_this_turn=False,
+        )
+
+        assert was_injected is True
+        assert len(tools_out) == 1
+
+    def test_valid_golden_bytes_still_injected(self) -> None:
+        """Sanity check: valid CCR golden bytes still work correctly after fix."""
+        from headroom.ccr.tool_injection import create_ccr_tool_definition
+        from headroom.proxy.helpers import serialize_tool_definition_canonical
+
+        session_id = "sess-valid-ccr"
+        valid_def = create_ccr_tool_definition("anthropic")
+        valid_bytes = serialize_tool_definition_canonical(valid_def)
+        _seed_ccr_done("anthropic", session_id, valid_bytes)
+
+        tools_out, was_injected = apply_session_sticky_ccr_tool(
+            provider="anthropic",
+            session_id=session_id,
+            request_id="req-valid",
+            existing_tools=None,
+            has_compressed_content_this_turn=False,
+        )
+
+        assert was_injected is True
+        assert tools_out == [valid_def]