headroom/docs/observability.md
chopratejas 2a717a993e fix(observability): G3 remediation — bound cardinality + wire dead metrics
Phase G PR-G3 review identified 5 Critical + 4 High + 5 Medium
findings. This commit lands all 14 fixes plus the optional nits.

CRITICAL

* C1 (cardinality DoS): `service_tier` was read from inbound JSON
  and used verbatim as a metric label. A malicious client could
  blow up the metric vector unboundedly. Added bounded vocabulary
  in `metric_names.rs::service_tier` ({auto, default, flex,
  on_demand, priority, scale, other-sentinel}) + a `validate()`
  helper. Both request-side (`handlers/responses.rs`) and
  response-side (`proxy.rs` Responses arm) gate raw values through
  it.

* C2 (dead metric): `proxy_passthrough_bytes_modified_total` had
  no production emit site. Wired it in `proxy.rs` to fire when a
  dispatcher arm returning `NoCompression`/`Passthrough` produces
  a body of a different byte length (a true cache-poisoning
  regression detector). The check runs BEFORE the PR-E4
  prompt_cache_key injector so legitimate injector mutations do
  not trip the alarm.

* C3 (Python/Rust boundary): `proxy_image_generation_call_log_redacted_total`
  was a dead Rust counter — the redaction happens entirely in the
  Python proxy's request_logger. Removed the Rust counter; moved
  the metric to the Python proxy's `/metrics` exporter via the
  existing `redactions_total()` module-level counter.

* C4 (Python/Rust boundary): `wrap_rtk_invocations_total` was a
  dead Rust counter with no wrap-side bridge. Removed the Rust
  counter; added new `headroom/cli/wrap_rtk_metrics.py` with
  `record_rtk_invocation(tool, delta)` + `rtk_invocation_counts()`
  primitives and surfaced them via the Python proxy's `/metrics`
  exporter.

* C5 (dead metric): `proxy_compression_rejected_by_token_check_total`
  had no production caller. Wired it in
  `live_zone_anthropic.rs`, `live_zone_openai.rs`, and
  `live_zone_responses.rs` to increment on every
  `BlockAction::RejectedNotSmaller` block in the manifest. The
  metric now reflects real "compressor ran but kept original"
  cases.

HIGH

* H1 (per-strategy ratio garbage): `proxy_compression_ratio_by_strategy`
  emitted the same aggregate ratio for every strategy in
  `strategies_applied` when multiple strategies ran on one body.
  Added `per_strategy_tokens: Vec<PerStrategyTokens>` to
  `Outcome::Compressed`; per-strategy `(before, after)` is
  accumulated from the manifest at the wrapper sites and emitted
  one sample per strategy in `proxy.rs`. Empty vec → fallback to
  one aggregate-labelled sample with a debug log (Phase E
  normalization paths that don't track per-strategy tokens).

* H2 (aborted stream): cache_hit_rate observed on client
  disconnects mid-stream. Added a gate: Anthropic only fires when
  `state.status == MessageStop`, OpenAI Responses only when
  `terminal_status().is_some()`. Extracted the gate into the
  pure function `compute_anthropic_session_hit_rate(state)` so
  the H2 contract is unit-testable independent of the shared
  global registry.

* H3 (docs lie + alarm contract): docs claimed HELP/TYPE is
  reachable on fresh boot, then contradicted itself. Force-zero
  every counter / gauge MetricVec with an `__init__` sentinel
  label on each scrape so HELP/TYPE + a zero row are visible from
  boot. Histograms are NOT force-zeroed (a synthetic observe(0.0)
  would pollute percentiles). PromQL queries in docs filter
  `{... != "__init__"}` so the sentinel rows are excluded from
  aggregations.

* H4 (crate-version dependency): pinned `prometheus = "=0.13.4"`
  exactly (no caret) so a future minor bump cannot silently break
  the H3 force-zero contract that relies on this crate's gather()
  semantics. Added a clear "retest the alarm contract on bump"
  paragraph in docs.

MEDIUM

* M1 (saturate on cached > input): OpenAI Chat + Responses cache-
  hit-rate computed `non_cached = input.saturating_sub(cached)`,
  silently clamping to 0 if `cached > input`. Per "no silent
  fallbacks", log + skip the emit on this wire-format pathology.

* M2 (over-fire on non-image base64): Python redactor's "density
  heuristic" over-fired on encrypted blobs / signed tokens /
  minified JSON / tool outputs. Tightened: only redact strings
  inside known image-bearing JSON paths (`data`, `url`,
  `image_url`, `image`) OR strings starting with `data:image/`.

* M3 (NaN clamp): cache_hit_rate::observe used `f64::clamp(0,1)`
  which returns NaN for NaN input; the `debug_assert!` was
  compiled out in release. Added `is_finite()` guard with a
  loud-log + skip before observe.

* M4 (PromQL median-only): added p95, p99, mean (sum/count), and
  Phase H canary-gate query section to docs. Canary fails if ANY
  of {p50, p95, p99, mean} regresses below the Python baseline.

* M5 (label byte vs char): the `<image:base64-redacted bytes=N>`
  placeholder reported character count, not UTF-8 byte count.
  Switched to `.encode('utf-8').__len__()` so the label is
  honest for non-ASCII payloads (ASCII base64 still has byte ==
  char so existing scrapes are unchanged).

OPTIONAL

* Removed dead `debug_assert_eq!(buffered.len(), buffered.len(),
  ...)` no-op in proxy.rs.
* Normalised `record_response_status` log level from `info` to
  `debug` to match peer metric helpers.

Tests:

* Rust: 11 integration_metrics tests (was 6) + 9 cache_hit_rate
  unit tests (was 4) + 2 compression_ratio (unchanged). New
  coverage: service_tier known/unknown bucketing, C2 alarm wire,
  H1 per-strategy ratio, H2 abort gate, M3 NaN/inf skip.
* Python: 27 tests (was 13). New coverage: M2 path-gated
  redaction, M5 byte vs char label, wrap_rtk_metrics primitive
  thread safety and validation.

`cargo fmt --check`, `cargo clippy --workspace -- -D warnings`,
`cargo test -p headroom-proxy --lib` (221 passed) and the
integration_metrics + integration_compression +
integration_volatile_detector + integration_cache_control +
integration_cache_drift + integration_responses +
integration_bedrock_metrics test files all green. Full
`cargo test --workspace` deferred — disk pressure during the
agent session left insufficient space for the linker to write
the full integration test artifacts; runs that did fit all
passed. `make ci-precheck` deferred for the same reason.

ruff check + ruff format + mypy headroom/proxy/request_logger.py
+ headroom/cli/wrap_rtk_metrics.py + headroom/proxy/prometheus_metrics.py
green.
2026-05-24 10:41:56 -07:00

12 KiB
Raw Blame History

Observability — proxy metrics

The Headroom Rust proxy exposes Prometheus-format metrics on the /metrics endpoint of every running proxy instance. The metric catalogue below covers Phase D (Bedrock route instrumentation) and Phase G PR-G3 (per-invocation RTK + proxy-wide observability).

All metric names + label keys are constants in crates/headroom-proxy/src/observability/metric_names.rs, so any rename catches one file in code review.

Metric catalogue

Bedrock route (Phase D PR-D3)

Name Type Labels Purpose
bedrock_invoke_count_total Counter model, region, auth_mode One increment per Bedrock /invoke or /converse request.
bedrock_invoke_latency_seconds Histogram model, region Latency from proxy entry to upstream completion. Buckets target 50ms60s.
bedrock_eventstream_message_count_total Counter model, region, event_type One increment per parsed binary EventStream message.

Proxy-wide (Phase G PR-G3)

Cache + compression

Name Type Labels Purpose
proxy_cache_hit_rate_per_session Histogram provider Per-session cache hit rate. Phase H canary gate.
proxy_compression_ratio_by_strategy Histogram strategy, content_type compressed_tokens / original_tokens per shrunk block.
proxy_compression_rejected_by_token_check_total Counter strategy Compressor ran but failed the shrink check.

Cache-safety alarm

Name Type Labels Purpose
proxy_passthrough_bytes_modified_total Counter path Bytes mutated on a passthrough path. Must stay 0 outside the compression hot path — any non-zero rate fires the cache-safety alarm.

The alarm metric is wired in crates/headroom-proxy/src/proxy.rs: when the dispatcher returns Outcome::NoCompression or Outcome::Passthrough, the post-dispatcher byte length is compared to the original buffered length and any delta increments the counter (by the byte delta) under the request's path label. The PR-E4 prompt_cache_key injector runs AFTER the alarm check, so its intentional byte mutations do not trip the alarm.

Upstream rate limits

Name Type Labels Purpose
proxy_rate_limit_remaining_requests Gauge provider Last-seen remaining requests in the current window.
proxy_rate_limit_remaining_tokens Gauge provider Last-seen remaining tokens in the current window.
proxy_rate_limit_remaining_input_tokens Gauge provider Anthropic-only input-token bucket.
proxy_rate_limit_remaining_output_tokens Gauge provider Anthropic-only output-token bucket.

OpenAI Responses telemetry

Name Type Labels Purpose
proxy_service_tier_count_total Counter tier Service-tier distribution observed at the proxy.
proxy_response_status_count_total Counter status Terminal status distribution (completed, incomplete, failed, cancelled, in_progress).

Wrap CLI / RTK (Python-side)

Name Type Labels Purpose
wrap_rtk_invocations_total Counter tool RTK invocations observed via the wrap-CLI tail. Surfaced via the Python proxy's /metrics exporter; the wrap CLI bumps headroom.cli.wrap_rtk_metrics.record_rtk_invocation(...).

C4 remediation: This counter is Python-side because RTK is wrapped by headroom wrap (Python CLI) and the wrap-side tail is the natural emit site. The Rust proxy previously held a dead counter for this metric; that has been removed.

Image log redaction (Python-side)

Name Type Labels Purpose
proxy_image_generation_call_log_redacted_total Counter none Base64-encoded image payloads redacted from request logs. Driven from headroom.proxy.request_logger.redactions_total().

C3 remediation: Image redaction is purely a Python-proxy operation (the request logger walks JSON and replaces over- threshold image payloads with placeholders). The counter lives Python-side so we have one source of truth instead of two. The Rust proxy previously held a dead counter for this metric; that has been removed.

How to query

The proxy renders Prometheus text-format on GET /metrics:

curl -s http://127.0.0.1:8787/metrics

Phase H canary gate

The canary script that decides "ship Rust, retire Python" uses all four of these queries against proxy_cache_hit_rate_per_session to confirm parity vs the Python baseline. A single percentile is not enough — a regression that only shows up at the tail (a small class of long sessions losing cache hits) would slip through a median-only check.

# p50, p95, p99 of cache hit rate over the last 5 minutes, per provider.
histogram_quantile(0.50, sum by (provider, le) (rate(proxy_cache_hit_rate_per_session_bucket{provider!="__init__"}[5m])))
histogram_quantile(0.95, sum by (provider, le) (rate(proxy_cache_hit_rate_per_session_bucket{provider!="__init__"}[5m])))
histogram_quantile(0.99, sum by (provider, le) (rate(proxy_cache_hit_rate_per_session_bucket{provider!="__init__"}[5m])))

# Mean cache hit rate over the last 5 minutes, per provider. The
# `sum / count` form is the cleanest "average without a quantile"
# query and is what the Python baseline reports.
sum by (provider) (rate(proxy_cache_hit_rate_per_session_sum{provider!="__init__"}[5m]))
  /
sum by (provider) (rate(proxy_cache_hit_rate_per_session_count{provider!="__init__"}[5m]))

The canary fails if ANY of p50, p95, p99, or mean regresses below the Python baseline for any provider over the canary window.

Other common queries

# Cache-safety alarm. Should always be 0 (post-`__init__` row).
sum(rate(proxy_passthrough_bytes_modified_total{path!="__init__"}[5m]))

# Per-strategy compression value at p50 (post-H1 fix: each strategy
# reports its own before/after; pre-fix this was the same aggregate
# ratio repeated per strategy).
histogram_quantile(0.50, sum by (strategy, le) (rate(proxy_compression_ratio_by_strategy_bucket{strategy!="__init__"}[1h])))

# Per-strategy compression value at p95 and p99 (catch outlier
# strategies that fail to shrink at the tail).
histogram_quantile(0.95, sum by (strategy, le) (rate(proxy_compression_ratio_by_strategy_bucket{strategy!="__init__"}[1h])))
histogram_quantile(0.99, sum by (strategy, le) (rate(proxy_compression_ratio_by_strategy_bucket{strategy!="__init__"}[1h])))

# Strategies that ran but failed the token-check (compressor ran
# but its output was not strictly smaller, so the original was
# kept). High rate here means the compressor needs tuning.
sum by (strategy) (rate(proxy_compression_rejected_by_token_check_total{strategy!="__init__"}[1h]))

# Upstream rate-limit headroom (smaller = closer to throttle).
proxy_rate_limit_remaining_tokens{provider="anthropic"}

# RTK invocation rate (Python-side).
sum by (tool) (rate(wrap_rtk_invocations_total{tool!="__init__"}[5m]))

# Image-redaction rate (Python-side).
rate(proxy_image_generation_call_log_redacted_total[5m])

All queries above include a {... != "__init__"} filter so the sentinel zero-rows the boot-touch contract emits do not skew the result. See "Wiring → H3 force-zero" below.

Wiring

Every metric registration is OnceLock-backed and lazy: the first call to a *_counter() / *_gauge() / *_histogram() helper registers the family with the shared registry. handle_metrics force-touches every Phase G PR-G3 family before scraping.

H3 force-zero

The prometheus crate v0.13 skips empty MetricVecs from gather() entirely — neither HELP/TYPE lines nor rows appear until the family has been incremented at least once with a label tuple. Operators expect to see the catalogue from boot, so handle_metrics increments each counter / gauge MetricVec by 0 under a sentinel __init__ label tuple before the first scrape. HELP/TYPE then surface from boot and dashboards/alarms see a predictable scrape shape.

Counters with the __init__ label increment by 0, so the alarm-able "must stay 0" semantic of proxy_passthrough_bytes_modified_total is preserved (the family becomes visible, the rate stays 0). PromQL queries should filter {... != "__init__"} so the sentinel rows are excluded from aggregations (the catalogue above does this).

Histograms are NOT force-zeroed: a synthetic observe(0.0) would contribute a real sample to the per-label distribution and pollute percentile readings. The two histogram families (proxy_cache_hit_rate_per_session and proxy_compression_ratio_by_strategy) only surface in the scrape after the first real session, by design.

H4 prometheus crate version pin

The H3 contract above relies on the prometheus crate's v0.13 gather() semantics — empty MetricVec families are omitted from the scrape. This is implementation-defined behaviour. If crates/headroom-proxy/Cargo.toml ever bumps the prometheus dependency, retest the alarm contract:

  1. Start a fresh proxy.
  2. curl /metrics and confirm every counter / gauge family has HELP/TYPE + an __init__ row.
  3. Confirm histograms (*_cache_hit_rate_per_session, *_compression_ratio_by_strategy) DO NOT appear (no observe() calls yet).
  4. Drive one cache-hit session, scrape again, confirm histograms now appear.
  5. Confirm passthrough_bytes_modified_total stays at 0 across passthrough requests.

The crate version is pinned exactly (= "0.13.4", no caret) in Cargo.toml precisely so a silent semver bump cannot break the contract without a code-review trigger.

C2 alarm wiring

proxy_passthrough_bytes_modified_total fires from proxy.rs when a dispatcher arm that promised byte-equal passthrough (Outcome::NoCompression or Outcome::Passthrough) produces a final body of a different byte length. The check runs BEFORE the PR-E4 prompt_cache_key injector so the injector's intentional byte mutations do not trip the alarm.

H1 per-strategy ratio wiring

proxy_compression_ratio_by_strategy samples one observation per strategy using the strategy's OWN before/after token counts (plumbed through Outcome::Compressed.per_strategy_tokens from the manifest in live_zone_anthropic / live_zone_openai / live_zone_responses). Pre-H1 the same aggregate ratio was emitted per strategy when multiple strategies ran on one body, making Phase H per-strategy dashboards read garbage.

H2 aborted-stream gate

The proxy_cache_hit_rate_per_session histogram observes ONLY when the SSE stream completed:

  • Anthropic: state.status == StreamStatus::MessageStop after the channel closes.
  • OpenAI Chat: state.usage.is_some() (the final usage chunk only arrives at stream completion).
  • OpenAI Responses: state.terminal_status().is_some().

A client disconnect mid-stream closes the channel without setting the terminal flag — under H2 we log + skip rather than observe a garbage half-stream sample.

Cardinality discipline

Every label vocabulary is bounded by code, not customer input:

  • model / region: read from path params + Config::bedrock_region.
  • auth_mode: 3-variant enum (payg, oauth, subscription).
  • provider: 3 values (anthropic, openai_chat, openai_responses).
  • strategy: &'static str from the compressor's BlockAction::Compressed.
  • content_type: &'static str from headroom_core::transforms::ContentType.
  • tier: validated through crate::observability::metric_names::service_tier::validate(raw: &str). Returns one of {auto, default, flex, on_demand, priority, scale} or the sentinel "other" for anything else. The raw inbound value is never used as a label. A malicious client posting {"service_tier":"<random>"} per request gets bucketed to "other" and a tracing::warn! is emitted so wire-format drift surfaces loudly in logs.
  • status: 5-variant enum.
  • tool (Python-side wrap_rtk_invocations_total): bounded by the set of tools the wrap CLI rewrites, captured by headroom.cli.wrap_rtk_metrics.

There is no code path where a malicious client can drive label cardinality unbounded.

See also

  • docs/rtk-architecture.md — why RTK lives wrap-side, not proxy-side.
  • crates/headroom-proxy/src/observability/ — implementation.
  • REALIGNMENT/09-phase-G-rtk-observability.md — spec.
  • REALIGNMENT/10-phase-H-python-retirement.md — H1 acceptance gate.