fix(proxy): exclude streaming sessions from latency metrics - #514
Merged
Conversation
`ProxyMetrics::record` derives proxy self time as `elapsed - upstream`, where `elapsed` is read in Pingora's `logging` hook. That hook fires when the session ends, not when the response is served, so for an established WebSocket tunnel or an SSE stream it measures a connection lifetime rather than a latency: a WebSocket held open until the 1h idle timeout set in `upstream_peer` booked an hour of "proxy overhead" the proxy never spent. The interval averages are unweighted, so a small number of such sessions ending together can dominate `proxy.self_duration_avg_ms`. Because those observations sit far out in the tail, the percentiles stay flat while the mean moves — on a chart that is indistinguishable from a genuine latency regression. Streaming sessions are still counted as requests, so the status-class and destination counters continue to partition `proxy.requests`, but they are excluded from every duration histogram and reported separately via `proxy.streaming_sessions` and `proxy.streaming_duration_avg_ms`. Latency averages now divide by a new `duration_count` instead of the request total so the carve-out cannot dilute them. Adds a "Proxy overhead percentiles" console panel: `self_duration_p50/p95/ p99` were already sampled and stored but never charted, which is what made a single-outlier artifact indistinguishable from a real regression.
📓 Changelog previewThis is what your commits will add to the generated ## [Unreleased]
### Fixed
- **proxy:** Exclude streaming sessions from latency metrics |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Problem
ProxyMetrics::recordderives proxy self time aselapsed - upstream, whereelapsedis read in Pingora'slogginghook. That hook fires when the session ends, not when the response is served. For an established WebSocket tunnel or an SSE stream that is a connection lifetime, not a latency — a WebSocket held open until the 1h idle timeout set inupstream_peerbooked an hour of "proxy overhead" the proxy never spent.The interval averages are unweighted, so a small number of such sessions ending together can dominate
proxy.self_duration_avg_ms. Because those observations sit far out in the tail, the percentiles stay flat while the mean moves — on a chart that is indistinguishable from a genuine latency regression.Change
status 101, or an upstream that returnedtext/event-stream) are still counted as requests, so the status-class and destination counters continue to partitionproxy.requests— but they are excluded from every duration histogram.proxy.streaming_sessionsandproxy.streaming_duration_avg_ms.duration_countrather than the request total, so the carve-out cannot dilute them.self_duration_p50/p95/p99were already sampled and stored but never charted, which is what made a single-outlier artifact indistinguishable from a real regression.Evidence
Unit-level — the new regression test fails without the carve-out:
Runtime — a real
temps proxyforwarding to a container serving/,/sse(text/event-stream) and/ws(101 Switching Protocols). 24,027 background requests, plus one WebSocket and one SSE session each held exactly 45s, isolated into separate sampler windows. Raw 30s samples fromservice_metrics:Recorded lifetimes are 45004 ms / 45001 ms against a held time of exactly 45s.
self_duration_avg_msstays inside its neighbours' noise band and p99 never leaves the<=5msbucket.Without the carve-out those same samples would have read:
...with p99 unmoved in both cases, since one outlier in ~3000 sits above the 99th percentile.
Console verified in a browser: all four panels render with the expected series counts — Latency breakdown (3), Proxy overhead percentiles (3), Streaming sessions (1), Streaming session lifetime (1).
Not covered
Both runtime tests drove traffic through the console-fallback path, so
destination = Console. A deployed project route was not exercised: deployments are queue/webhook-driven with no REST trigger, and hand-inserting route-table rows would have tested the fixture rather than the product. The carve-out is destination-independent by construction —is_streamingcomes from the status code and the upstream content-type, andrecord()treats all three destinations identically — but that is reasoning, not evidence.Test plan
cargo test --lib -p temps-proxy— 433 pass. One unrelated pre-existing failure:test_proxy_route_resolutionhardcodes a port base of 9000 andunwrap()s the bind, so it fails withAddrInUsewhenever anything occupies that range locally. Passes on a free port; worth fixing separately by binding port 0.cargo clippy -p temps-proxy --all-targets -- -D warnings— clean.tsc --noEmit— clean.