From 039399a017d5ae039c2c07f6a60ce398b07cb5ff Mon Sep 17 00:00:00 2001 From: Tejas Chopra Date: Tue, 7 Apr 2026 20:43:04 -0700 Subject: [PATCH 1/3] fix: eliminate duplicate proxy logging and guard against token inflation Duplicate logging: wrap.py redirects stderr to proxy.log while _setup_file_logging also writes there via RotatingFileHandler. Set propagate=False on the headroom logger and guard against adding duplicate handlers. Token inflation: 5.8% of requests had optimized_tokens > original_tokens due to tokenizer counting mismatches between handler and pipeline. Added guards in all handlers (anthropic, openai, gemini, batch) to revert to original messages when optimization inflates tokens. --- headroom/proxy/handlers/anthropic.py | 23 ++++++++++++++++++-- headroom/proxy/handlers/batch.py | 11 +++++++++- headroom/proxy/handlers/gemini.py | 12 ++++++++++- headroom/proxy/handlers/openai.py | 32 +++++++++++++++++++++++++--- headroom/proxy/helpers.py | 11 ++++++++-- 5 files changed, 80 insertions(+), 9 deletions(-) diff --git a/headroom/proxy/handlers/anthropic.py b/headroom/proxy/handlers/anthropic.py index 064a6683a..365a866bc 100644 --- a/headroom/proxy/handlers/anthropic.py +++ b/headroom/proxy/handlers/anthropic.py @@ -681,7 +681,17 @@ class AnthropicHandlerMixin: # Flag compression failure for observability _compression_failed = True - tokens_saved = max(0, original_tokens - optimized_tokens) + # Guard: if "optimization" inflated tokens, revert to originals + if optimized_tokens > original_tokens: + logger.warning( + f"[{request_id}] Optimization inflated tokens " + f"({original_tokens} -> {optimized_tokens}), reverting to original messages" + ) + optimized_messages = original_messages + optimized_tokens = original_tokens + transforms_applied = [] + + tokens_saved = original_tokens - optimized_tokens optimization_latency = (time.time() - start_time) * 1000 # Hook: post_compress — let hooks observe compression results @@ -1592,9 +1602,18 @@ class AnthropicHandlerMixin: # Use pipeline's token counts for consistency with pipeline logs original_tokens = result.tokens_before optimized_tokens = result.tokens_after + # Guard: if "optimization" inflated tokens, revert to originals + if optimized_tokens > original_tokens: + logger.warning( + f"[{request_id}] Batch item optimization inflated tokens " + f"({original_tokens} -> {optimized_tokens}), reverting" + ) + optimized_messages = messages + optimized_tokens = original_tokens + total_original_tokens += original_tokens total_optimized_tokens += optimized_tokens - tokens_saved = max(0, original_tokens - optimized_tokens) + tokens_saved = original_tokens - optimized_tokens total_tokens_saved += tokens_saved # CCR Tool Injection: Inject retrieval tool if compression occurred diff --git a/headroom/proxy/handlers/batch.py b/headroom/proxy/handlers/batch.py index 14076ec63..8ce5fe683 100644 --- a/headroom/proxy/handlers/batch.py +++ b/headroom/proxy/handlers/batch.py @@ -158,9 +158,18 @@ class BatchHandlerMixin: # Use pipeline's token counts for consistency with pipeline logs original_tokens = result.tokens_before optimized_tokens = result.tokens_after + # Guard: if "optimization" inflated tokens, revert to originals + if optimized_tokens > original_tokens: + logger.warning( + f"[{request_id}] Batch item optimization inflated tokens " + f"({original_tokens} -> {optimized_tokens}), reverting" + ) + optimized_messages = messages + optimized_tokens = original_tokens + total_original_tokens += original_tokens total_optimized_tokens += optimized_tokens - tokens_saved = max(0, original_tokens - optimized_tokens) + tokens_saved = original_tokens - optimized_tokens total_tokens_saved += tokens_saved # CCR Tool Injection: Inject retrieval tool if compression occurred diff --git a/headroom/proxy/handlers/gemini.py b/headroom/proxy/handlers/gemini.py index 3ded54954..d11abb6ad 100644 --- a/headroom/proxy/handlers/gemini.py +++ b/headroom/proxy/handlers/gemini.py @@ -265,7 +265,17 @@ class GeminiHandlerMixin: _compression_failed = True logger.warning(f"[{request_id}] Gemini optimization failed: {e}") - tokens_saved = max(0, original_tokens - optimized_tokens) + # Guard: if "optimization" inflated tokens, revert to originals + if optimized_tokens > original_tokens: + logger.warning( + f"[{request_id}] Optimization inflated tokens " + f"({original_tokens} -> {optimized_tokens}), reverting to original messages" + ) + optimized_messages = messages + optimized_tokens = original_tokens + transforms_applied = [] + + tokens_saved = original_tokens - optimized_tokens optimization_latency = (time.time() - start_time) * 1000 # Query Echo: disabled — hurts prefix caching in long conversations. diff --git a/headroom/proxy/handlers/openai.py b/headroom/proxy/handlers/openai.py index 328ab2367..984484731 100644 --- a/headroom/proxy/handlers/openai.py +++ b/headroom/proxy/handlers/openai.py @@ -298,7 +298,17 @@ class OpenAIHandlerMixin: # Flag compression failure for observability _compression_failed = True - tokens_saved = max(0, original_tokens - optimized_tokens) + # Guard: if "optimization" inflated tokens, revert to originals + if optimized_tokens > original_tokens: + logger.warning( + f"[{request_id}] Optimization inflated tokens " + f"({original_tokens} -> {optimized_tokens}), reverting to original messages" + ) + optimized_messages = original_messages + optimized_tokens = original_tokens + transforms_applied = [] + + tokens_saved = original_tokens - optimized_tokens optimization_latency = (time.time() - start_time) * 1000 # Hook: post_compress @@ -791,7 +801,17 @@ class OpenAIHandlerMixin: except Exception as e: logger.warning(f"[{request_id}] Responses API optimization failed: {e}") - tokens_saved = max(0, original_tokens - optimized_tokens) + # Guard: if "optimization" inflated tokens, revert to originals + if optimized_tokens > original_tokens: + logger.warning( + f"[{request_id}] Optimization inflated tokens " + f"({original_tokens} -> {optimized_tokens}), reverting to original messages" + ) + optimized_messages = messages + optimized_tokens = original_tokens + transforms_applied = [] + + tokens_saved = original_tokens - optimized_tokens optimization_latency = (time.time() - start_time) * 1000 # Convert compressed messages back to Responses API items @@ -1056,7 +1076,13 @@ class OpenAIHandlerMixin: if instructions and opt and opt[0].get("role") == "system": body["instructions"] = opt[0]["content"] opt = opt[1:] - body["input"] = messages_to_responses_items(opt, input_data, preserved) + if result.tokens_after <= original_tokens: + body["input"] = messages_to_responses_items(opt, input_data, preserved) + else: + logger.warning( + f"[{request_id}] WS optimization inflated tokens " + f"({original_tokens} -> {result.tokens_after}), reverting" + ) tokens_saved = max(0, original_tokens - result.tokens_after) first_msg_raw = json.dumps(body) logger.info( diff --git a/headroom/proxy/helpers.py b/headroom/proxy/helpers.py index fea2d8273..41faa0626 100644 --- a/headroom/proxy/helpers.py +++ b/headroom/proxy/helpers.py @@ -78,8 +78,15 @@ def _setup_file_logging() -> None: handler.setFormatter( logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") ) - # Attach to the headroom root logger so all sub-loggers are captured - logging.getLogger("headroom").addHandler(handler) + # Attach to the headroom root logger so all sub-loggers are captured. + # Disable propagation to root to avoid duplicate writes when + # wrap.py redirects stderr to the same log file. + headroom_logger = logging.getLogger("headroom") + if not any( + isinstance(h, RotatingFileHandler) for h in headroom_logger.handlers + ): + headroom_logger.addHandler(handler) + headroom_logger.propagate = False except OSError: # Non-fatal: can't write logs (read-only fs, permissions, etc.) pass From 1006bc3522b03eb260d81a326d3f76df084ac111 Mon Sep 17 00:00:00 2001 From: Tejas Chopra Date: Tue, 7 Apr 2026 21:21:21 -0700 Subject: [PATCH 2/3] fix: skip token inflation guard in cache mode Cache mode assembles prefix+compressed-delta which can legitimately have different token counts than the original messages. The inflation guard only applies to optimize/token modes. --- headroom/proxy/handlers/anthropic.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/headroom/proxy/handlers/anthropic.py b/headroom/proxy/handlers/anthropic.py index 365a866bc..a41210c2c 100644 --- a/headroom/proxy/handlers/anthropic.py +++ b/headroom/proxy/handlers/anthropic.py @@ -681,8 +681,9 @@ class AnthropicHandlerMixin: # Flag compression failure for observability _compression_failed = True - # Guard: if "optimization" inflated tokens, revert to originals - if optimized_tokens > original_tokens: + # Guard: if "optimization" inflated tokens, revert to originals. + # Skip in cache mode where prefix-stability may legitimately shift counts. + if optimized_tokens > original_tokens and not is_cache_mode(self.config.mode): logger.warning( f"[{request_id}] Optimization inflated tokens " f"({original_tokens} -> {optimized_tokens}), reverting to original messages" @@ -691,7 +692,7 @@ class AnthropicHandlerMixin: optimized_tokens = original_tokens transforms_applied = [] - tokens_saved = original_tokens - optimized_tokens + tokens_saved = max(0, original_tokens - optimized_tokens) optimization_latency = (time.time() - start_time) * 1000 # Hook: post_compress — let hooks observe compression results From 4baef0e598620575b2ee15077e23253dd7212014 Mon Sep 17 00:00:00 2001 From: Tejas Chopra Date: Tue, 7 Apr 2026 21:33:16 -0700 Subject: [PATCH 3/3] chore: fix ruff lint issues (import sorting, trailing whitespace) --- headroom/evals/memory/runner_v2.py | 2 +- headroom/evals/memory/runner_v3.py | 2 +- headroom/rtk/installer.py | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/headroom/evals/memory/runner_v2.py b/headroom/evals/memory/runner_v2.py index e42ff56cb..63434e6dc 100644 --- a/headroom/evals/memory/runner_v2.py +++ b/headroom/evals/memory/runner_v2.py @@ -15,9 +15,9 @@ from __future__ import annotations import asyncio import json import logging +import tempfile import time import uuid -import tempfile from collections.abc import Callable from dataclasses import dataclass, field from datetime import datetime diff --git a/headroom/evals/memory/runner_v3.py b/headroom/evals/memory/runner_v3.py index 91e49f421..08f793325 100644 --- a/headroom/evals/memory/runner_v3.py +++ b/headroom/evals/memory/runner_v3.py @@ -20,9 +20,9 @@ from __future__ import annotations import asyncio import json import logging +import tempfile import time import uuid -import tempfile from dataclasses import dataclass, field from datetime import datetime from pathlib import Path diff --git a/headroom/rtk/installer.py b/headroom/rtk/installer.py index 3336418bf..d9804e741 100644 --- a/headroom/rtk/installer.py +++ b/headroom/rtk/installer.py @@ -77,7 +77,7 @@ def download_rtk(version: str | None = None) -> Path: # Validate URL scheme to prevent B310 warning if not url.startswith(("http://", "https://")): raise ValueError(f"Invalid URL scheme in {url}") - + # Try default SSL first, fall back to unverified for macOS framework Python try: with urlopen(url, timeout=30) as response: