headroom/tests/test_per_model_tool_savings.py
Tejas Chopra 81fe9d5345
fix(metrics): attribute tool-schema savings per model, not just compression (#3155)
## Description

Reported against 0.36.0 (VS Code + Copilot + Claude Code): the per-model
breakdown disagreed with the headline printed four lines above it.

```
Tokens saved: 625,277
  · messages       36,071
  · tool schemas  589,206
Per-Model Breakdown
  <a>: 35,907 tokens saved
  <b>:      0 tokens saved
  <c>:    164 tokens saved
  <d>:      0 tokens saved
```

The rows sum to **36,071** — the *messages* line exactly. All 589,206
tokens of tool-schema deferral, 94% of the headline, had no row to land
in, so every tool-heavy model reported "0 tokens saved" while real
dollars were credited to it.

Deferral is disjoint from message compression by construction: deferred
schemas never enter the message token counts, so they move neither
`tokens_saved` nor `tokens_sent`. The headline, the PERF line, and the
savings ledger (#2795) all already fold the two together. Three
per-model surfaces did not.

Closes #

## Type of Change

- [x] Bug fix (non-breaking change that fixes an issue)
- [ ] New feature (non-breaking change that adds functionality)
- [ ] Breaking change (fix or feature that would cause existing
functionality to change)
- [ ] Documentation update
- [ ] Performance improvement
- [ ] Code refactoring (no functional changes)

## Changes Made

- **`perf/analyzer.py`** — the per-model loop summed `tokens_saved`
while its own headline summed `tokens_saved + tool_saved`. Now uses the
same all-layers construction (`headline_before = before + tool_saved`),
and prints a `· messages / · tool schemas` split line only when there is
a split to show.
- **`proxy/savings_tracker.py`** — added a `tool_tokens_saved` bucket to
`_empty_by_model_entry()`, normalization, and
`_record_by_model_locked()`; `record_request()` gained a
`tool_search_saved` parameter. `_by_model_snapshot_locked()` ranks and
computes `savings_percent` off the combined figure and exposes
`headline_tokens_saved`.
- **`proxy/prometheus_metrics.py`** — **the seam.** `record_request`
already accepted `tool_search_saved` and already folded it into the
per-model *dollars*, but never passed it to
`savings_tracker.record_request`. Tokens and money therefore disagreed
on the same row.
- **`proxy/cost.py`** (feeds the dashboard's "Per-Model Token Savings"
table) — added `_tool_saved_by_model`, a `tool_schema_saved` kwarg, and
`compression_tokens_saved` / `tool_tokens_saved` alongside a combined
`tokens_saved`. The `stats()` loop now iterates the **union** of both
dicts: keying off compression alone dropped a deferral-only model from
the table entirely rather than merely under-reporting it.
- **`proxy/outcome.py`** — forwards the figure it already computed for
`metrics.record_request` to `cost_tracker.record_tokens`.
- **`dashboard.html`** — the "Tokens Saved" cell gains a `title` showing
the compression/deferral split.

Design notes:
- Components stay separately addressable rather than widening an
existing field's meaning in place, so persisted state remains readable
by older readers.
- Percentages use the all-layers numerator over `saved + sent` —
deferred schemas were never in `sent`, so that is still the pre-Headroom
volume.
- `CostTracker.stats()["savings_usd"]` is deliberately **not** widened:
deferral is already priced by `SavingsTracker`, and this tracker's
dollars feed budget enforcement, where counting it twice would
double-book the saving.

## Testing

- [x] Unit tests pass (`pytest`)
- [x] Linting passes (`ruff check .`)
- [x] Type checking passes (`mypy headroom`)
- [x] New tests added for new functionality
- [ ] Manual testing performed

### Test Output

```text
$ pytest tests/test_per_model_tool_savings.py -q
11 passed in 0.94s

# Same file against pre-fix code (git stash), proving the tests bite:
5 failed, 1 passed
  FAILED test_per_model_rows_reconcile_with_the_headline
  FAILED test_a_tool_only_model_no_longer_reads_zero
  FAILED test_tracker_attributes_deferral_to_the_model
  FAILED test_tracker_default_is_unchanged_without_deferral
  FAILED test_state_written_before_this_field_existed_still_loads
(the one that passes pre-fix is the "compression-only model is unchanged" guard)

$ pytest tests/ -q          # this branch
3 failed, 11374 passed, 587 skipped in 343.55s

$ pytest tests/ -q          # clean origin/main, same machine
3 failed, 11364 passed, 587 skipped in 352.64s

Identical 3 failures on both — pre-existing and environmental, not regressions:
  test_learn/test_integration.py::TestCodexIntegration::test_full_pipeline
  test_release_workflows.py::test_no_native_tls_in_wheel_build_tree   (FileNotFoundError: 'cargo')
  test_graceful_shutdown.py::test_run_server_installs_cancelled_error_filter
    (whole-suite ordering flake; tests/test_graceful_shutdown.py passes 11/11 in isolation on this branch)

$ ruff check headroom/
All checks passed!

$ mypy headroom/proxy/cost.py headroom/proxy/savings_tracker.py \
       headroom/proxy/prometheus_metrics.py headroom/proxy/outcome.py \
       headroom/perf/analyzer.py
Success: no issues found in 5 source files
```

## Real Behavior Proof

- Environment: macOS, Python 3.12.13, this branch rebased on
`origin/main` @ `1f96dabc`.
- Exact command / steps: reproduced the reported shape as a unit test —
three models with 35,907 / 0 / 164 message savings and 400,000 / 189,206
/ 0 deferral, then rendered `format_report`.
- Observed result: headline `Tokens saved: 625,277` unchanged; rows now
read `435,907` / `189,206` / `164` and sum to the headline. The seam
test drives the real `PrometheusMetrics.record_request` and asserts the
tracker's `by_model` entry ends up at `tokens_saved=400,
tool_tokens_saved=54,000, headline_tokens_saved=54,400`.
- Not tested: no live proxy run against a real Copilot/Claude Code
session; the arithmetic is pinned at the four code seams instead. The
dashboard `title` tooltip is markup-only and not covered by a rendering
test.

## Runtime Rollout Safety

- Rollout-managed feature(s): none — this is reporting arithmetic, not a
request-path behavior.
- Minimum rollout channel: n/a.
- Stable/default behavior changed: yes, displayed per-model token
savings and percentages increase to include tool-schema deferral. No
request is treated differently.
- Kill switch / disable path: n/a. Components remain separately readable
(`compression_tokens_saved` / `tool_tokens_saved`) if a consumer wants
the old message-only figure.
- Unsafe override required: none.
- Qualification impact: none — `savings_usd` and budget enforcement are
unchanged by design.
- Rollback path: revert the commit; `tool_tokens_saved` in persisted
state is then simply ignored by the older reader.

## Review Readiness

- [x] I have performed a self-review
- [x] This PR is ready for human review

## Checklist

- [x] My code follows the project's style guidelines

Co-authored-by: Tejas Chopra <tejas@Tejass-MacBook-Pro.local>
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-20 11:54:02 -07:00

242 lines
8.8 KiB
Python

"""Per-model attribution must count tool-schema deferral, not just compression.
Reported against 0.36.0 with a per-model breakdown reading:
Tokens saved: 625,277
· messages 36,071
· tool schemas 589,206
Per-Model Breakdown
<model-a>: ... 35,907 tokens saved
<model-b>: ... 0 tokens saved
<model-c>: ... 164 tokens saved
<model-d>: ... 0 tokens saved
The rows sum to 36,071 — the *messages* line exactly. All 589,206 tokens of
tool-schema deferral, 94% of the headline, had no row to land in, so the
breakdown contradicted the total printed four lines above it and every
tool-heavy model reported "0 tokens saved".
Both surfaces had the same shape of bug and both are pinned here:
* ``perf/analyzer.py`` summed ``tokens_saved`` per model while its own headline
summed ``tokens_saved + tool_saved``.
* ``savings_tracker`` had no per-model field for deferral at all, and
``prometheus_metrics.record_request`` received the figure but did not pass it
down — while already folding it into the per-model *dollars*, so money and
tokens disagreed on the same row.
"""
from __future__ import annotations
from headroom.perf.analyzer import PerfRecord, PerfReport, format_report
from headroom.proxy.savings_tracker import SavingsTracker, _normalize_by_model
def _record(model: str, *, before: int, saved: int, tool_saved: int) -> PerfRecord:
return PerfRecord(
timestamp="2026-08-16T00:00:00Z",
request_id=f"req-{model}-{saved}-{tool_saved}",
model=model,
tokens_before=before,
tokens_after=before - saved,
tokens_saved=saved,
tool_saved=tool_saved,
)
# --------------------------------------------------------------------------- #
# CLI report (`headroom perf`)
# --------------------------------------------------------------------------- #
def test_per_model_rows_reconcile_with_the_headline() -> None:
"""The reported symptom: rows that do not add up to the total above them."""
report = PerfReport(
perf_records=[
_record("model-a", before=100_000, saved=35_907, tool_saved=400_000),
_record("model-b", before=50_000, saved=0, tool_saved=189_206),
_record("model-c", before=20_000, saved=164, tool_saved=0),
]
)
text = format_report(report)
# Headline is unchanged: 36,071 messages + 589,206 tool schemas.
assert "Tokens saved: 625,277" in text
# Every model's own tool savings now appear on its row.
assert "model-a: 1 reqs, 435,907 tokens saved" in text
assert "model-b: 1 reqs, 189,206 tokens saved" in text
assert "model-c: 1 reqs, 164 tokens saved" in text
def test_a_tool_only_model_no_longer_reads_zero() -> None:
"""A model whose entire win is deferral used to render as saving nothing."""
report = PerfReport(
perf_records=[_record("tool-heavy", before=8_000, saved=0, tool_saved=120_000)]
)
text = format_report(report)
assert "tool-heavy: 1 reqs, 120,000 tokens saved" in text
# Denominator includes what was withheld — deferred schemas were never in
# tokens_before — so the percent is 120,000/128,000, not 120,000/8,000.
assert "(94%)" in text
assert "· messages 0 · tool schemas 120,000" in text
def test_a_compression_only_model_keeps_its_single_line_shape() -> None:
report = PerfReport(perf_records=[_record("plain", before=10_000, saved=2_500, tool_saved=0)])
text = format_report(report)
assert "plain: 1 reqs, 2,500 tokens saved (25%)" in text
assert "tool schemas" not in text.split("Per-Model Breakdown")[1]
# --------------------------------------------------------------------------- #
# Dashboard / API (`savings_tracker`)
# --------------------------------------------------------------------------- #
def test_tracker_attributes_deferral_to_the_model(tmp_path) -> None:
tracker = SavingsTracker(path=str(tmp_path / "savings.json"))
tracker.record_request(
model="gpt-5-codex",
input_tokens=10_000,
tokens_saved=1_000,
tool_search_saved=90_000,
)
entry = tracker.snapshot()["by_model"]["gpt-5-codex"]
# The two layers stay separately addressable...
assert entry["tokens_saved"] == 1_000
assert entry["tool_tokens_saved"] == 90_000
# ...and the combined figure is what the percent is computed from.
assert entry["headline_tokens_saved"] == 91_000
# 91,000 / (91,000 + 10,000)
assert entry["savings_percent"] == 90.1
def test_tracker_default_is_unchanged_without_deferral(tmp_path) -> None:
"""Callers that pass no deferral must see exactly the old numbers."""
tracker = SavingsTracker(path=str(tmp_path / "savings.json"))
tracker.record_request(model="claude-sonnet-4-6", input_tokens=9_000, tokens_saved=1_000)
entry = tracker.snapshot()["by_model"]["claude-sonnet-4-6"]
assert entry["tool_tokens_saved"] == 0
assert entry["headline_tokens_saved"] == 1_000
assert entry["savings_percent"] == 10.0
def test_state_written_before_this_field_existed_still_loads() -> None:
"""Backward compatibility: the key is simply absent in older state files."""
normalized = _normalize_by_model(
{
"legacy-model": {
"requests": 3,
"tokens_saved": 500,
"compression_savings_usd": 0.25,
"total_input_tokens": 4_500,
"total_input_cost_usd": 1.5,
}
}
)
assert normalized["legacy-model"]["tool_tokens_saved"] == 0
assert normalized["legacy-model"]["tokens_saved"] == 500
# --------------------------------------------------------------------------- #
# Dashboard "Per-Model Token Savings" table (`cost.py`)
# --------------------------------------------------------------------------- #
def test_cost_tracker_per_model_counts_both_layers() -> None:
from headroom.proxy.cost import CostTracker
tracker = CostTracker()
tracker.record_tokens("gpt-5-codex", 1_000, 9_000, tool_schema_saved=40_000)
row = tracker.stats()["per_model"]["gpt-5-codex"]
assert row["compression_tokens_saved"] == 1_000
assert row["tool_tokens_saved"] == 40_000
assert row["tokens_saved"] == 41_000
# 41,000 / (41,000 + 9,000)
assert row["reduction_pct"] == 82.0
def test_cost_tracker_shows_a_deferral_only_model_at_all() -> None:
"""Keying the loop off compression alone dropped such a model entirely."""
from headroom.proxy.cost import CostTracker
tracker = CostTracker()
tracker.record_tokens("tool-only", 0, 2_000, tool_schema_saved=18_000)
stats = tracker.stats()
assert "tool-only" in stats["per_model"]
assert stats["per_model"]["tool-only"]["tokens_saved"] == 18_000
def test_cost_tracker_totals_reconcile_with_the_rows() -> None:
from headroom.proxy.cost import CostTracker
tracker = CostTracker()
tracker.record_tokens("model-a", 1_000, 5_000, tool_schema_saved=40_000)
tracker.record_tokens("model-b", 500, 5_000, tool_schema_saved=0)
stats = tracker.stats()
assert stats["total_tokens_saved"] == sum(
row["tokens_saved"] for row in stats["per_model"].values()
)
assert stats["total_compression_tokens_saved"] == 1_500
assert stats["total_tool_tokens_saved"] == 40_000
def test_cost_tracker_default_call_is_unchanged() -> None:
"""Existing callers that pass no deferral keep the old numbers exactly."""
from headroom.proxy.cost import CostTracker
tracker = CostTracker()
tracker.record_tokens("claude-sonnet-4-6", 2_500, 7_500)
row = tracker.stats()["per_model"]["claude-sonnet-4-6"]
assert row["tokens_saved"] == 2_500
assert row["tool_tokens_saved"] == 0
assert row["reduction_pct"] == 25.0
# --------------------------------------------------------------------------- #
# The seam itself
# --------------------------------------------------------------------------- #
def test_metrics_forwards_deferral_to_the_tracker(tmp_path) -> None:
"""`record_request` always received the figure; it just never passed it on.
Pinning this at the seam rather than only at the destination: the tracker
could be correct in isolation and the dashboard still read zero, which is
exactly the state that shipped.
"""
import asyncio
from headroom.proxy.prometheus_metrics import PrometheusMetrics
tracker = SavingsTracker(path=str(tmp_path / "savings.json"))
metrics = PrometheusMetrics(savings_tracker=tracker, stateless=True)
asyncio.run(
metrics.record_request(
provider="openai",
model="gpt-5-codex",
input_tokens=6_000,
output_tokens=100,
tokens_saved=400,
latency_ms=12.0,
tool_search_saved=54_000,
)
)
entry = tracker.snapshot()["by_model"]["gpt-5-codex"]
assert entry["tokens_saved"] == 400
assert entry["tool_tokens_saved"] == 54_000
assert entry["headline_tokens_saved"] == 54_400