Skip to content

feat(proxy): let extensions report cost savings and their own latency - #3051

Open
chopratejas wants to merge 1 commit into
mainfrom
feat/extension-attribution-perf
Open

feat(proxy): let extensions report cost savings and their own latency#3051
chopratejas wants to merge 1 commit into
mainfrom
feat/extension-attribution-perf

Conversation

@chopratejas

Copy link
Copy Markdown
Collaborator

What

Two changes that let a proxy extension report what it saved and what it cost, so both show up under /stats, the dashboard, and Prometheus.

record_scope_savings already existed and already accepted usd — the one channel in the proxy that can express savings without tokens. Two things stopped it working end to end.

1. Savings were silently dropped on Gemini traffic (bug)

bind_scope shares one attribution ledger between ASGI middleware and the request handler. Anthropic and OpenAI call it; Gemini never did, so anything an extension recorded into the request scope was discarded for Gemini traffic only — silently, because an empty ledger and an unbound one are indistinguishable at the outcome funnel. Now bound at all four Gemini tag sites.

2. An extension's own latency was invisible (gap)

overhead_ms is measured inside the handler, and an ASGI extension wraps that handler — so every millisecond it spends reaches the client while every timing surface stays flat. An extension that halves the bill and adds 200 ms per request is a trade the operator has to see both halves of, and only one half was reaching the dashboard.

record_scope_timing(scope, stage, ms) is the symmetric counterpart to record_scope_savings, carried on the same bound ledger and merged into RequestOutcome.pipeline_timing at the outcome funnel — one place, so every provider picks it up at once.

API surface

from headroom.proxy.savings_attribution import record_scope_savings, record_scope_timing

record_scope_savings(scope, "my_extension", tokens=0, usd=0.004)   # money without tokens
record_scope_timing(scope, "my_extension", elapsed_ms)

Both take the ASGI scope, because middleware has no other way in. Documented in extensions.py — the module extension authors actually read, and the stability contract for this interface.

  • Savings → /stats savings.by_source, dashboard card, headroom_savings_attributed_usd_total{source=...}
  • Timing → /stats pipeline_timing, dashboard Performance panel, headroom_transform_timing_ms_*

Attribution only. These rows explain the headline total; they are never added to it.

Changes to existing behavior

  • public_tags now strips _headroom_stage_timing as well as _headroom_savings_attribution. Both ride on tags because that is the one dict reaching the outcome funnel from every handler, and a list and a dict must not land in a string-keyed label store.
  • pipeline_timing passed to metrics.record_request is merged rather than passed through only when an extension contributed timings; with no extension the handler's own dict is passed through unchanged (asserted by identity in the tests).
  • Stage names are extension-supplied, so they are capped at 16 and namespaced ext:deep_copy reported by a plugin must never accumulate into the same series as deep_copy measured by the pipeline. A handler's own timing wins a collision (unreachable while the prefix stands; the safe way round if it ever goes).

Failure modes

Both calls are bounded (32 sources, 16 stages), never raise, and never change a response — telemetry from a plugin must not be able to break the request it is describing. Non-positive and non-numeric durations are ignored: a zero is a clock artifact, not an observation, and averaging it in would drag the mean down exactly where the stage is cheapest to skip. timings_from_tags tolerates junk on the tag.

Test-double fix

Three Gemini test fakes (FakeRequest, _FakeRequest, _VertexGeminiImageRequest) had no .scope, which every real Starlette Request has. They now do. This is a double that had drifted from the type it stands in for; the alternative was weakening the handler to tolerate a request shape that cannot occur in production.


Real behavior proof

Setup: macOS 15.4 (darwin 25.4.0), Python 3.12.13, this branch at c814b950, real create_app proxy with respx-mocked Anthropic upstream, a demo ASGI extension added via app.add_middleware.

The extension — written as a third party would, reporting tokens=0 because it re-routed claude-opus-5claude-haiku-4-5: same tokens, cheaper model. That is precisely the case no existing Headroom savings channel can express, since all of them compute saved = before - after.

class DemoRouter:
    def __init__(self, app): self.app = app
    async def __call__(self, scope, receive, send):
        if scope.get("type") != "http":
            return await self.app(scope, receive, send)
        started = time.perf_counter()
        record_scope_savings(scope, "routemegood", tokens=0, usd=0.173)
        record_scope_timing(scope, "routemegood", (time.perf_counter() - started) * 1000)
        await self.app(scope, receive, send)

Ran: three POSTs to /v1/messages, then GET /stats and GET /metrics.

Observed:

upstream call -> 200
upstream call -> 200
upstream call -> 200

=== /stats  savings.by_source  (what the dashboard renders) ===
[
  {
    "source": "routemegood",
    "realized": true,
    "events": 3,
    "tokens": 0,
    "usd": 0.519
  }
]

=== /stats  pipeline_timing  (dashboard Performance panel) ===
{
  "ext:routemegood": {
    "average_ms": 0.01,
    "max_ms": 0.02,
    "count": 3
  }
}

=== /metrics ===
# HELP headroom_savings_attributed_tokens_total Tokens attributed to a savings source
# TYPE headroom_savings_attributed_tokens_total counter
headroom_savings_attributed_tokens_total{realized="true",source="routemegood"} 0
# HELP headroom_savings_attributed_usd_total Cost savings attributed to a source; may be negative
# TYPE headroom_savings_attributed_usd_total gauge
headroom_savings_attributed_usd_total{realized="true",source="routemegood"} 0.519
headroom_transform_timing_ms_sum{transform="ext:routemegood"} 0.03

$0.519 = 3 × $0.173 — three requests, correctly accumulated, with tokens: 0 throughout.

Also have (not a substitute for the above): 22 new unit tests in tests/test_extension_attribution.py, including four that drive the real _record_request_outcome funnel via the same descriptor-binding harness test_request_outcome.py uses.

Full suite on this branch: 10,989 passed, 578 skipped. Three failures — test_graceful_shutdown.py::test_run_server_installs_cancelled_error_filter (full-suite ordering; passes in isolation), test_learn/test_integration.py::TestCodexIntegration::test_full_pipeline, and test_release_workflows.py::test_no_native_tls_in_wheel_build_tree (needs cargo) — reproduce identically on clean main (2f4d001c, 10,967 passed, same 3 failed). Verified by stashing this branch and re-running the full suite on main in the same tree.

What I did not test: a live provider (upstream is respx-mocked); the Gemini bind_scope fix against real Google traffic (covered by the existing 114 Gemini tests, which all pass); the dashboard rendered in a browser — I verified the JSON shape its templates bind to (stats.savings?.by_source, stats.pipeline_timing) rather than the pixels.


🤖 Generated with Claude Code

An extension that changes the bill has to be able to say so, or the operator
sees a different total with nothing to explain it. Two gaps stopped that.

SAVINGS WERE DROPPED ON GEMINI TRAFFIC
    `bind_scope` shares one attribution ledger between ASGI middleware and the
    request handler. Anthropic and OpenAI call it; Gemini never did, so
    anything an extension recorded into the request scope was discarded for
    Gemini traffic only -- silently, because an empty ledger and an unbound one
    are indistinguishable at the outcome funnel. Bound at all four Gemini tag
    sites.

AN EXTENSION'S OWN LATENCY WAS INVISIBLE
    `overhead_ms` is measured inside the handler, and an ASGI extension wraps
    that handler, so every millisecond it spends reaches the client while every
    timing surface stays flat. An extension that halves the bill and adds 200ms
    per request is a trade the operator has to see both halves of, and only one
    half was reaching the dashboard.

    `record_scope_timing(scope, stage, ms)` is the symmetric counterpart to the
    existing `record_scope_savings`, carried on the same bound ledger and merged
    into `RequestOutcome.pipeline_timing` at the outcome funnel -- one place, so
    every provider picks it up at once. It lands in `/stats.pipeline_timing`,
    the dashboard's Performance panel, and `headroom_transform_timing_ms_*`.

    Stage names are extension-supplied, so they are capped (16) and namespaced
    `ext:` -- `deep_copy` reported by a plugin must never accumulate into the
    same series as `deep_copy` measured by the pipeline. A handler's own timing
    wins a collision, which is unreachable while the prefix stands and is the
    safe way round if it ever goes.

Both ledgers are now stripped by `public_tags`: they ride on `tags` because
that is the one dict reaching the outcome funnel from every handler, and a list
and a dict must not land in a string-keyed label store.

`extensions.py` documents both calls. `record_scope_savings` already accepted
`usd`, which is the one channel in the proxy that can express savings WITHOUT
tokens -- routing a request to a cheaper model sends the same tokens for less
money -- but nothing in the extension-facing contract said so, and the module
is where extension authors look.

Real behavior proof in the PR body: a demo ASGI extension reporting
`tokens=0, usd=0.173` shows up on /stats as `savings.by_source`, in
`pipeline_timing` as `ext:routemegood`, and in /metrics as
`headroom_savings_attributed_usd_total{source="routemegood"} 0.519`.

Test suite: 10,989 passed, 578 skipped. The 3 failures on this branch
(test_graceful_shutdown ordering, test_learn integration, release-workflow
cargo) reproduce identically on clean main.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@github-actions

Copy link
Copy Markdown
Contributor

PR governance

This PR does not yet satisfy the required template fields:

  • Missing required section Description.
  • Missing required section Type of Change.
  • Missing required section Changes Made.
  • Missing required section Testing.
  • Missing required section Real Behavior Proof.
  • Missing required section Runtime Rollout Safety.
  • Missing required section Review Readiness.
  • Check I have performed a self-review before requesting human review.
  • Check This PR is ready for human review or convert the PR back to draft.

Please update the PR body, or move the PR back to draft while it is still in progress.

@github-actions github-actions Bot added the status: needs author action Pull request body or readiness checklist still needs author updates label Aug 16, 2026
@codecov-commenter

codecov-commenter commented Aug 16, 2026

Copy link
Copy Markdown

⚠️ Please install the 'codecov app svg image' to ensure uploads and comments are reliably processed by Codecov.

Codecov Report

❌ Patch coverage is 94.11765% with 3 lines in your changes missing coverage. Please review.

Files with missing lines Patch % Lines
headroom/proxy/handlers/gemini.py 75.00% 2 Missing ⚠️
headroom/proxy/savings_attribution.py 97.50% 0 Missing and 1 partial ⚠️

📢 Thoughts on this report? Let us know!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

status: needs author action Pull request body or readiness checklist still needs author updates

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants