fix(proxy/cost): record each request's savings exactly once (drop 3 double-counts) (#2545)

## Description

An audit of savings accounting found three **double-count** bugs: the P0
outcome-funnel refactor centralized cost + PERF recording in
`emit_request_outcome`, but three pre-funnel emits were never removed,
so they fire a second time on their paths.

| Path | Stray emit | + Funnel | Effect |
|---|---|---|---|
| OpenAI chat direct, non-streaming | explicit
`cost_tracker.record_tokens` (`handlers/openai.py` ~4140) |
`outcome.py:418` | **2× spend / requests; budget period cost doubled** →
`check_budget` can block at half the real spend |
| OpenAI **Responses** buffered (Codex HTTP) | explicit `record_tokens`
(~5223) | `outcome.py:418` | same |
| Codex **WS** turns | explicit `PERF` log line (~7291) |
`outcome.py:482` | `headroom perf` **double-counts** saved + requests
every WS turn (analyzer sums per line, no dedup by request_id) |

All three are pure duplicates: the funnel's `cost_tracker.record_tokens`
is a **superset** of the explicit calls' args, and its PERF line uses
the **same per-turn deltas** (verified: `7246-7249` == the explicit
line's fields). The `/stats` headline was already correct
(SavingsTracker fires once, inside the funnel) — only cost/budget and
`headroom perf` were affected.

Closes #

## Type of Change
- [x] Bug fix (non-breaking)

## Changes Made
- Remove the explicit `cost_tracker.record_tokens` on the OpenAI chat
non-streaming path and the Responses buffered path — keep the
`cache_write`/`uncached` computation the funnel needs.
- Remove the duplicate WS PERF log line (+ its now-dead `_perf_*` locals
and the now-unused `_summarize_transforms` import).
- Add a regression test: cost is recorded exactly once on the
non-streaming chat path (was 2×).

## Testing
- [x] `ruff check` + `ruff format --check` clean; `mypy` clean
- [x] Regression + existing tests pass

### Test Output
```text
pytest tests/test_openai_chat_turn_hooks.py -q            → 6 passed  (incl. new double-count regression)
pytest tests/test_openai_responses_context_compaction.py  → 12 passed
pytest tests/test_openai_codex_ws_lifecycle.py + timings + savings_deferral → 38 passed
ruff/mypy → clean
```

## Real Behavior Proof
- **Verified by code trace**, not just tests: `grep
cost_tracker.record_tokens` across the handler now returns only the
funnel call (`outcome.py:418`); the explicit chat/Responses calls are
gone. The WS funnel outcome (`openai.py:7246-7249`) feeds
`outcome.py:482`'s PERF with the same deltas the deleted line used.
- **Not covered:** a related finding (OpenAI-chat *streaming* skips turn
hooks entirely, `openai.py:3484 "and not stream"`) is **intentionally
deferred** — that gate protects re-drive-requiring hooks (tool-router
deferral) which can't run mid-stream; a proper fix needs a per-hook
"safe-on-stream" capability flag, out of scope here.

## Checklist
- [x] Self-reviewed
- [x] No new warnings; tests pass locally
- [x] Did **not** edit `CHANGELOG.md`

## Additional Notes
This is the "sources" half of the savings audit. A companion PR will fix
the "sinks" half — tool-search/deferral savings are never aggregated
into `Metrics`, so the session summary, `cost.py` summary, `headroom
perf --json/csv`, and the `all_layers` total under-report them.

headroom/proxy/handlers/openai.py

@@ -67,7 +67,7 @@ from headroom.proxy.auth_mode import (
     should_stamp_codex_client,
 )
 from headroom.proxy.compression_decision import CompressionDecision
-from headroom.proxy.cost import _summarize_transforms, header_safe_transforms
+from headroom.proxy.cost import header_safe_transforms
 from headroom.proxy.handlers._debug_dump import _debug_dump_mode, _redact_debug_value
 from headroom.proxy.image_isolation import run_image_compression_isolated
 from headroom.proxy.outcome import RequestOutcome
@@ -4135,17 +4135,9 @@ class OpenAIHandlerMixin:
                 # OpenAI has no write penalty — uncached = total - cached
                 uncached_input_tokens = max(0, total_input_tokens - cache_read_tokens)
 
-                # (record_tokens clamps negative savings to 0 universally — the
+                # Cost is recorded exactly once by the outcome funnel below
-                # forwarded request is never larger than the original.)
+                # (_record_request_outcome -> emit_request_outcome -> cost_tracker.
-                if self.cost_tracker:
+                # record_tokens); recording here too double-counted spend + budget.
-                    self.cost_tracker.record_tokens(
-                        model,
-                        tokens_saved,
-                        optimized_tokens,
-                        cache_read_tokens=cache_read_tokens,
-                        cache_write_tokens=cache_write_tokens,
-                        uncached_tokens=uncached_input_tokens,
-                    )
 
                 # Memory: handle memory tool calls in OpenAI Chat Completions response.
                 # After executing tools, send a continuation request so the model
@@ -5213,27 +5205,14 @@ class OpenAIHandlerMixin:
                                 f"[{request_id}] Memory tool handling failed (responses): {e}"
                             )
 
-                    if self.cost_tracker:
+                    # Cost is recorded once by the outcome funnel below; here we only
-                        cache_write_tokens = _infer_openai_cache_write_tokens(
+                    # compute the cache-write / uncached split the funnel needs.
-                            total_input_tokens,
+                    # (Recording here too double-counted spend + budget on this path.)
-                            cache_read_tokens,
+                    cache_write_tokens = _infer_openai_cache_write_tokens(
-                        )
+                        total_input_tokens,
-                        uncached_input_tokens = max(0, total_input_tokens - cache_read_tokens)
+                        cache_read_tokens,
-                        # (record_tokens clamps negative savings to 0 universally.)
+                    )
-                        self.cost_tracker.record_tokens(
+                    uncached_input_tokens = max(0, total_input_tokens - cache_read_tokens)
-                            model,
-                            tokens_saved,
-                            total_input_tokens,
-                            cache_read_tokens=cache_read_tokens,
-                            cache_write_tokens=cache_write_tokens,
-                            uncached_tokens=uncached_input_tokens,
-                        )
-                    else:
-                        cache_write_tokens = _infer_openai_cache_write_tokens(
-                            total_input_tokens,
-                            cache_read_tokens,
-                        )
-                        uncached_input_tokens = max(0, total_input_tokens - cache_read_tokens)
 
                     effective_optimized_tokens = (
                         total_input_tokens if total_input_tokens > 0 else optimized_tokens
@@ -7266,41 +7245,10 @@ class OpenAIHandlerMixin:
                                 )
                             )
 
-                            # Structured PERF log line so ``headroom perf``
+                            # The PERF line for this Codex turn is emitted once by
-                            # counts this Codex turn. Pre-P2 this emit was
+                            # the outcome funnel above (emit_request_outcome), using
-                            # missing, which is why Codex traffic showed up
+                            # the same per-turn deltas — a second emit here duplicated
-                            # as ``Requests: 0`` in the perf report even
+                            # every WS turn in `headroom perf` (double saved + requests).
-                            # under heavy load — the same visibility bug
-                            # class as #327's "Cache write: 0" report.
-                            _perf_input_tokens = max(0, input_delta)
-                            _perf_cache_read = max(0, cache_read_delta)
-                            _perf_cache_write = max(0, cache_write_delta)
-                            _perf_cache_hit_pct = (
-                                round(
-                                    _perf_cache_read / (_perf_cache_read + _perf_cache_write) * 100
-                                )
-                                if (_perf_cache_read + _perf_cache_write) > 0
-                                else 0
-                            )
-                            _perf_tok_before = _perf_input_tokens + max(0, saved_delta)
-                            _perf_num_msgs = (
-                                len(body.get("messages") or body.get("input") or [])
-                                if isinstance(body, dict)
-                                else 0
-                            )
-                            logger.info(
-                                f"[{request_id}] PERF "
-                                f"model={model_for_metrics} msgs={_perf_num_msgs} "
-                                f"tok_before={_perf_tok_before} "
-                                f"tok_after={_perf_input_tokens} "
-                                f"tok_saved={max(0, saved_delta)} "
-                                f"cache_read={_perf_cache_read} "
-                                f"cache_write={_perf_cache_write} "
-                                f"cache_hit_pct={_perf_cache_hit_pct} "
-                                f"opt_ms={overhead_delta_ms:.0f} "
-                                f"transforms={_summarize_transforms(transforms_applied)} "
-                                f"client={client or ''}"
-                            )
 
                             ws_recorded_input_tokens_total = ws_input_tokens_total
                             ws_recorded_output_tokens_total = ws_output_tokens_total

tests/test_openai_chat_turn_hooks.py

@@ -308,6 +308,36 @@ def test_in_place_message_fold_is_counted():
         assert any(int(lg.get("tokens_saved", 0) or 0) > 0 for lg in logs), logs
 
 
+def test_cost_recorded_once_not_twice_nonstreaming():
+    """Regression: the OpenAI chat non-streaming direct path recorded cost TWICE —
+    an explicit `cost_tracker.record_tokens` plus the outcome funnel's own call —
+    doubling spend, request count, and budget consumption. It must fire once."""
+
+    async def fake_retry(method, url, headers, body, *args, **kwargs):
+        return httpx.Response(
+            200, json=_final_response(), headers={"content-type": "application/json"}
+        )
+
+    app = create_app(_config())
+    with TestClient(app) as client:
+        client.app.state.proxy._retry_request = fake_retry
+        ct = client.app.state.proxy.cost_tracker
+        calls = {"n": 0}
+        _orig = ct.record_tokens
+
+        def _counting(*a, **k):
+            calls["n"] += 1
+            return _orig(*a, **k)
+
+        ct.record_tokens = _counting
+        resp = _post(
+            client,
+            {"model": "gpt-4o", "messages": [{"role": "user", "content": "hi"}], "stream": False},
+        )
+        assert resp.status_code == 200, resp.text
+        assert calls["n"] == 1, f"cost recorded {calls['n']}x — double-count regression"
+
+
 def test_direct_path_noop_when_no_hook_registered():
     # No hook registered -> byte-identical passthrough, single upstream call.
     calls = {"n": 0}