headroom/docs/metrics-technical-guide.md

Ignoring revisions in .git-blame-ignore-revs. Click here to bypass and see the normal blame view.

224 lines
12 KiB
Markdown
Raw Permalink Normal View History

fix(reporting): show net vs gross savings, real skip thresholds, and the effective profile (#3123) ## Description Six reporting/config defects found while investigating a user reporting ~1% savings on Claude Code. **None of these changes how much Headroom compresses** — all of them change whether an operator can tell what it did. Every one was found by reading that user's own 227,777 lines of proxy logs against the code. ## Changes Made - **`perf/analyzer`: parse and render `tok_inflated`.** Every PERF line carried it; nothing downstream read it. The report could print `321,239,562 -> 313,274,727` directly above `8,455,763 saved` — two figures that differ by exactly the 490,928 tokens of inflation it omitted. - **`content_router`: report the real skip thresholds.** The routing summary hardcoded `skipped (<50 words)` regardless of what was in force. Wrong number (the message gate is `min_tokens`, 10–250 by profile), wrong unit (tokens and characters, never words), and it merged two different gates under one label. - **`perf/analyzer`: disclose that Transform Effectiveness is partial.** It is built only from `pipeline.py`'s `Transform NAME:` lines. `compression_units.py` / `compression_batches.py` contain zero logging calls, so the table read `content_router: 189,783 saved` against a PERF total 44x larger. Reports the divergence rather than a coverage ratio — the two are different populations and neither contains the other (those lines carry no request_id, fire per stage, and are emitted before the forwarder decides). - **`perf/analyzer`: disclose the routing denominator.** Percentages were taken over 4 of the router's 17 outcome buckets, silently dropping buckets larger than several it displayed. - **`savings_tracker`: stop dropping tool-schema dollars.** `estimate_request_savings_usd` prices four buckets; `record_request` read three. `tool_schema` was computed and discarded, so a quarter of the token headline never reached "Cost saved". The two inputs are disjoint (verified at the call site), so this is additive, not double-counting. - **`agent_savings`: an unknown profile no longer degrades to `balanced`.** `balanced` is a different product posture from the default `coding`: cache→token mode, dedup off, tool-search off, user messages uncompressed, message floor 25x higher, block floor 20x higher. A typo in `HEADROOM_SAVINGS_PROFILE` silently reconfigured the whole proxy. Now degrades to `DEFAULT_PROFILE` and names the resolved profile in the warning. - **`agent_savings`: give `min_chars_for_block` a config-object path.** Every other router pipeline kwarg travels on the config object; this one alone was env-only, so an unseeded proxy applied every sibling `coding` knob while this floor stayed at 500 instead of 25. - **`server`: log the resolved compression posture at startup**, reading cross-turn dedup off the constructed router rather than the environment (the router resolves it as `config OR env`, so reading env alone would be a guess). ## Testing - [x] Unit tests pass, [x] ruff, [x] mypy, [x] new tests added ```text uv run pytest tests/ -k "content_router or agent_savings or perf or analyzer or savings or proxy_server or cli_perf or prometheus" 620 passed, 25 skipped uv run mypy headroom # Success uv run ruff check . && ruff format --check . # clean ``` ## Real behavior proof - **Setup:** macOS arm64, Python 3.12, this branch. Input: 60 MB / 227,777 lines of real proxy logs from the reporting user (6 rotated files, 2,792 PERF lines, 2026-08-17 → 2026-08-19). - **Steps:** pointed `headroom.perf.analyzer.LOG_DIR` at that directory and rendered the report before and after the patch. - **After-fix output (real data, unmodified):** ```text Requests: 2792 Tokens: 321,288,161 -> 313,323,326 (2.6% messages) Tokens saved: 11,158,901 (3.4% reduction) · inflated 490,928 (net message reduction 7,964,835) · messages 8,455,763 · tool schemas 2,703,138 ! stage-level total 190,641 != PERF message total 8,455,763 — this table sees only engines that emit a Transform line, counts per stage, and does not check whether the mutation shipped Skipped: 44641 (77%) — below size floor (shares are of these 4 buckets only, n=58319; see `[router] route_counts=` for the full outcome space) ``` The arithmetic now closes on the page: `8,455,763 - 490,928 = 7,964,835`, matching the token delta exactly. Before the patch none of the three annotated lines existed and the `Skipped` line claimed `<50 words`. - **Profile resolution verified by execution**, not inspection — subprocesses with controlled env: ```text vanilla (nothing set) mode=cache dedupe=1 tool_search=1 min_tokens=10 min_chars=25 HEADROOM_SAVINGS_PROFILE=coding mode=cache dedupe=1 tool_search=1 min_tokens=10 min_chars=25 unknown profile name (before) mode=token dedupe=0 tool_search=0 min_tokens=250 min_chars=500 unknown profile name (after) -> resolves to `coding`, warning names it coding, seeding never runs min_chars=25 (was 500 before this patch) ``` - **Not tested:** live paid Anthropic traffic. These are reporting/config surfaces; the wire path is untouched by this PR. ## Review readiness - [x] Self-reviewed. Three overclaims in my own first draft were corrected before this PR: a false subset claim in the Transform Effectiveness note, a comment asserting `min_chars_for_block` was the *only* env-only field (it is the only env-only *router pipeline kwarg*; `cross_turn_dedup`, `tool_search`, `protect_reads`, `code_aware`, `effort_router`, `lossless` remain env-only via a different mechanism and are **not** fixed here), and a money-path expression that relied on `a + b if c else d` grouping. ## Known remaining (deliberately out of scope) - `Requests: N` still overcounts: the Codex WS forwarder reuses one `request_id` across every turn (one observed 156x), plus ~18 duplicate PERF emissions. - `compression_units.py` / `compression_batches.py` remain unlogged — this PR *discloses* the blind spot rather than closing it. - The headline stays **gross**. True net is `11,158,901 - 490,928 = 10,667,973` (3.3%, not 3.4%). Making net the headline lowers every user's reported savings ~4.4%; that is a product call, not mine, so the inflation is surfaced beside it instead. 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-authored-by: Tejas Chopra <tejas@Tejass-MacBook-Pro.local> Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
2026-08-19 00:16:37 -07:00
# Headroom Metrics — Dashboard Guide
What each metric shows, so you can build panels against it.
**Two endpoints.** Both are on the proxy (default `:8787`).
| Surface | How to get it | Use it for |
|---|---|---|
| **Prometheus**`GET /metrics` | Always on, no config | Everything below. Start here. |
| **OpenTelemetry** — OTLP/HTTP | `HEADROOM_OTEL_METRICS_ENABLED=1` + `pip install "headroom-ai[proxy,otel]"` | Same data, dotted names, plus per-tenant labels |
Names differ between them: Prometheus uses `headroom_tokens_saved_total` (**milliseconds** for timings), OTel uses `headroom.proxy.tokens.saved` (**seconds**). Both are listed below.
---
## The savings panel — start here
**`headroom.proxy.tokens.saved`** is the headline number. It already combines compression + tool-schema deferral — no need to add anything to it.
| Metric | What it shows |
|---|---|
| **`headroom.proxy.tokens.saved`** *(OTel)* | **Total input tokens Headroom kept out of the request.** Compression + tool savings, combined. This is your hero number. |
| `headroom.proxy.savings.usd{source}` *(OTel)* | **Dollars saved**, split by layer: `compression`, `tool_schema`, `output_shaping`, `provider_cache`. Sum for the total. |
| `headroom_persistent_savings_tokens_saved_total` | Same tokens-saved number, but **survives proxy restarts**. Use for "lifetime saved" tiles. |
| `headroom_persistent_savings_compression_savings_usd_total` | **Lifetime dollars saved**, durable across restarts. |
| `headroom_tokens_input_total` | Input tokens actually sent upstream (post-compression). The denominator for a reduction %. |
| `headroom_tokens_output_total` | Output tokens returned by the provider. |
```promql
# Hero tile: tokens saved per second
rate(headroom_tokens_saved_total[5m])
+ sum(rate(headroom_savings_attributed_tokens_total{source="tool_search",realized="true"}[5m]))
# Context reduction %
100 * rate(headroom_tokens_saved_total[5m])
/ clamp_min(rate(headroom_tokens_input_total[5m]) + rate(headroom_tokens_saved_total[5m]), 1)
# Lifetime tiles (survive restart)
headroom_persistent_savings_tokens_saved_total
headroom_persistent_savings_compression_savings_usd_total
```
> **One catch on the Prometheus side.** `headroom_tokens_saved_total` is compression **only** — it leaves out tool-schema deferral. The OTel `headroom.proxy.tokens.saved` includes both. That's why the query above adds the `tool_search` term back in. On tool-heavy workloads the gap is large.
---
## Latency panel
All Prometheus timings are in **milliseconds**, exposed as `_sum` / `_count` / `_min` / `_max`. Build means with `rate(sum)/rate(count)`.
| Metric | What it shows |
|---|---|
| **`headroom_overhead_ms_*`** | **Latency Headroom itself adds.** Handler entry → end of compression. Excludes the LLM call. This is the "what does this cost us" number. |
| `headroom_latency_ms_*` | Total request duration, including the provider. |
| `headroom_ttfb_ms_*` | Time to first byte from upstream. Streaming requests only. |
| `headroom_stage_timing_ms_*{path,stage}` | Where time went inside the handler — `compression_first_stage`, `upstream_connect`, `memory_context`, etc. |
| `headroom_transform_timing_ms_*{transform}` | Time per compression transform. Use to find a slow transform. |
```promql
# Headroom's added overhead, mean ms
rate(headroom_overhead_ms_sum[5m]) / rate(headroom_overhead_ms_count[5m])
# End-to-end, mean ms
rate(headroom_latency_ms_sum[5m]) / rate(headroom_latency_ms_count[5m])
# Slowest stages
topk(5, rate(headroom_stage_timing_ms_sum[5m]) / rate(headroom_stage_timing_ms_count[5m]))
```
> **No percentiles are available.** There are no histogram buckets on `/metrics`, and the OTel histograms ship with default buckets that put every request into one bucket, so `histogram_quantile()` returns nonsense. **Means work fine.** For real p95/p99 today, use the `headroom perf` CLI.
>
> Also: divide each `_sum` by **its own** `_count`. Overhead and TTFB are only sampled when > 0, so their counts are smaller than the latency count.
---
## Cache panel
| Metric | What it shows |
|---|---|
| `headroom_provider_cache_hit_requests_total{provider}` | Requests that read from the provider's prompt cache. |
| `headroom_provider_cache_requests_total{provider}` | Requests with any cache activity. **The correct denominator for hit rate.** |
| `headroom_cache_read_tokens_total{provider}` | Tokens served from cache (the discounted ones). |
| `headroom_cache_write_tokens_total{provider}` | Tokens written into cache (these carry a premium). |
| `headroom_cache_write_ttl_tokens_total{provider,ttl}` | Cache writes split by TTL — `5m` vs `1h`. |
| `headroom_uncached_input_tokens_total{provider}` | Input tokens that missed cache entirely. |
| `headroom_cache_bust_total` | Requests where compression broke a cached prefix. **Should stay near zero.** |
| `headroom_cache_miss_attribution_total{provider,reason}` | Why a cached prefix missed — `ttl_expiry`, `prefix_change`, `unknown`. |
```promql
# Cache hit rate by provider
sum by (provider) (rate(headroom_provider_cache_hit_requests_total[5m]))
/ sum by (provider) (rate(headroom_provider_cache_requests_total[5m]))
# Compression breaking cache — alert if this rises
rate(headroom_cache_bust_total[5m])
```
> **Don't use `headroom_requests_cached_total` as a hit rate.** It mixes the provider's prompt cache with Headroom's own response cache into one boolean, so it measures neither.
---
## Traffic & health panel
| Metric | What it shows |
|---|---|
| `headroom_requests_total` | Requests handled. Unlabelled. |
| `headroom_requests_by_provider{provider}` | Traffic split by provider — `anthropic`, `openai`, `gemini`, `bedrock`… |
| `headroom_requests_by_model{model}` | Traffic split by model. Capped at 1024 distinct; overflow lands in `model="other"`. |
| `headroom_requests_failed_total` | Upstream 5xx errors. |
| `headroom_requests_rate_limited_total` | Requests **Headroom** rejected via its own rate limiter (not upstream 429s). |
| `headroom_compression_failed_total{reason}` | Compression failures — `timeout` or `error`. Fails open, so traffic keeps flowing but savings quietly stop. **Worth an alert.** |
| `headroom_compression_quarantine_total{event}` | Compression disabled after repeated timeouts — `activated`, `skipped`, `released`. |
| `headroom_inbound_requests_active` | In-flight requests, gauge. Counts all HTTP including `/metrics`. |
| `headroom_active_ws_sessions` | Live Codex WebSocket sessions, gauge. |
```promql
# Failure rate
rate(headroom_requests_failed_total[5m])
/ clamp_min(rate(headroom_requests_total[5m]) + rate(headroom_requests_failed_total[5m]), 1)
# Savings silently stopped
sum by (reason) (rate(headroom_compression_failed_total[5m]))
# Traffic mix
sum by (provider) (rate(headroom_requests_by_provider[5m]))
```
---
## Anthropic subscription panel
Only if you're on an Anthropic OAuth/subscription plan. OTel only, gauges, no labels.
| Metric | What it shows |
|---|---|
| `headroom.subscription.5h_utilization_pct` | How much of the 5-hour rate-limit window is used (0100). |
| `headroom.subscription.7d_utilization_pct` | Same for the 7-day window. |
| `headroom.subscription.5h_seconds_to_reset` | Seconds until the 5-hour window resets. |
| `headroom.subscription.7d_seconds_to_reset` | Seconds until the 7-day window resets. |
| `headroom.subscription.overage_usd` | Extra-usage credits consumed, in dollars. |
---
## Attribution — where savings came from
| Metric | What it shows |
|---|---|
| `headroom_savings_attributed_tokens_total{source,realized}` | Tokens saved, broken out by named source. `source="tool_search"` is tool-schema deferral. |
| `headroom_savings_attributed_usd_total{source,realized}` | Dollars saved by source. **Gauge, can go negative** — don't `rate()` it. |
| `headroom_savings_attribution_events_total{source,realized}` | How often each source contributed. |
| `headroom_waste_signal_tokens_total{signal}` | Wasteful patterns *detected* in the input — `json_bloat`, `base64`, `repetition`, `reread`… This is diagnosis, **not savings**. |
These rows *explain* the headline total — they are never added to it.
---
## Compression internals
| Metric | What it shows |
|---|---|
| `headroom.compression.tokens.input` *(OTel)* | Tokens going into the compression pipeline. |
| `headroom.compression.tokens.output` *(OTel)* | Tokens coming out. |
| `headroom.compression.tokens.saved` *(OTel)* | The difference. Pipeline-level view of compression only. |
| `headroom.compression.runs` *(OTel)* | Pipeline executions. Note: **per pipeline run, not per request.** |
| `headroom.compression.pipeline.duration` *(OTel, seconds)* | How long the pipeline took. |
| `headroom.compression.transforms{transform}` *(OTel)* | Which transforms fired. **High cardinality — drop or aggregate at the collector.** |
---
## Five things that will break a dashboard
1. **Only savings counters survive a restart.** 55 of 60 Prometheus families reset to zero when the proxy restarts. Only `headroom_persistent_savings_*` is durable, and it needs `HEADROOM_WORKSPACE_DIR` on a persistent volume — otherwise it resets on every deploy.
2. **No percentiles anywhere.** Use means. See the latency section.
3. **`headroom_latency_ms` measures differently for streaming.** On streaming requests the timer starts *after* compression, so end-to-end is `latency + overhead`. On non-streaming it's just `latency`. Don't mix both in one panel.
4. **A 5xx erases its own savings.** Requests that fail upstream are dropped from every savings and token counter. During a provider incident, savings rates look artificially clean while throughput falls.
5. **`/metrics` needs auth if you set a proxy token.** With `HEADROOM_PROXY_TOKEN` set, any non-loopback scraper must send `Authorization: Bearer <token>`. Loopback is always exempt.
---
## Metrics the docs mention that don't exist
If panels came back empty, this is probably why. These names appear in the published docs but not in the code:
`headroom_compression_ratio` · `headroom_latency_seconds` (and `_bucket`) · `headroom_cache_hits_total` · `headroom_cache_misses_total` · `headroom_cost_usd_total` · the `mode="optimize"` label on `headroom_requests_total`
The shipped `examples/grafana/headroom-dashboard.json` also filters every panel on `pool` and `hook` labels that no metric emits — the dropdowns will be permanently empty. Its metric names are otherwise correct.
---
## Setup reference
```bash
# Prometheus — nothing to do, GET /metrics is always on
# OpenTelemetry
pip install "headroom-ai[proxy,otel]"
export HEADROOM_OTEL_METRICS_ENABLED=1
export HEADROOM_OTEL_METRICS_ENDPOINT=https://otel.corp.example/v1/metrics
export HEADROOM_OTEL_METRICS_HEADERS="authorization=Bearer XXX"
export HEADROOM_OTEL_RESOURCE_ATTRIBUTES="service.instance.id=$HOSTNAME"
```
| Variable | Default | Notes |
|---|---|---|
| `HEADROOM_OTEL_METRICS_ENABLED` | `0` | Master switch |
| `HEADROOM_OTEL_METRICS_EXPORTER` | `otlp_http` | Or `console`. No gRPC exporter exists. |
| `HEADROOM_OTEL_METRICS_ENDPOINT` | unset | Passed verbatim — `/v1/metrics` is **not** appended |
| `HEADROOM_OTEL_METRICS_HEADERS` | unset | `k=v,k2=v2` |
| `HEADROOM_OTEL_METRICS_EXPORT_INTERVAL_MS` | `10000` | |
| `HEADROOM_OTEL_SERVICE_NAME` | `headroom-proxy` | |
| `HEADROOM_OTEL_RESOURCE_ATTRIBUTES` | unset | **Set `service.instance.id` here** — Headroom doesn't, and replicas will collide |
Verify with `curl -s localhost:8787/stats | jq .otel`.
**Multi-tenant labels:** `register_otel_metric_attribute_provider()` adds request-scoped attributes (tenant, team, cost centre) to every OTel datapoint. Max 16 attributes, 256 chars each.
**Air-gapped deployments:** `HEADROOM_OFFLINE=1` disables all outbound traffic — the anonymous usage beacon (which is **on by default**), the update check, and model downloads.
---