One p99 alert, five slow routes, five different causes

On a product platform at Gambchamp a p99 latency alert fired on the payments service. It said the service was slow and nothing about where. Making the alert per route answered that — and showed that every slow route had a different cause. Some were real problems, some were not what they looked like.

What each route turned out to be

• Deposit initiation: about half the requests took 2.5–5 seconds. They were synchronous calls to external payment gateways, returning HTTP 200 with a redirect URL — no errors at all. The distribution was bimodal: about 5 ms when no gateway call was needed, 2.5–5 s when it was. A p99 of eight seconds was simply the gateways’ normal speed.
• Sign-up: 84% of requests took more than a second. Phase timings in the logs showed the median request spending 1.4 s in processing, most of it in an external captcha verification (about 0.5 s).
• Game launch: 6% slow. One phase, a call to a game provider’s connector, had a median of 1.2 s and p95 of 1.7 s. Everything else was milliseconds.
• Promo page: 10% of requests over a second — but the handler’s own timing never exceeded 0.95 s. The time was spent outside the handler. That one is still not fully pinned down.
• Withdrawal: another gateway route, p99 around 2.5 s. Every other payment route was about 50 ms.

The traps

• Backends were scraped twice, by two jobs. Quantiles do not care, but counters and increase() double unless you pin the job. Always pin it when counting requests.
• The handler’s log timing is not the request duration. It measures the handler only; the histogram measures what the client sees. For SLOs trust the histogram; use logs to find where time goes inside the handler.
• Logs are a sample. 763 log lines against 2,419 histogram observations in the same three hours. “No slow requests in the logs” does not disprove a metric.
• The bucket grid jumped from 1.0 to 2.5 seconds. Anything in that gap interpolates near the top, so a p99 of 2.3 s may mean “somewhere between 1 and 2.5”. Read the buckets before trusting the number.
• A quantile hides bimodality. “p99 is five seconds” sounded like “everything is slow”. The buckets showed two code paths.

I made one wrong call myself: I first dismissed the promo page as a bucket artefact. Per-job buckets agreed with each other — about 10% of requests really were slower than a second. Verify before you declare an artefact.

The queries that did the work

sum by (le) (increase(http_request_duration_seconds_bucket{app="X", route="Y"}[30m]))

The full distribution shows bimodality and where the seconds are. The share of requests above one second per route shows which routes have a real tail. And CPU throttling is worth ruling out before blaming the application.

How the alerting changed

• The latency alert now aggregates by (app, route), so it names the endpoint.
• The traffic floor is more than 3 requests per 10 minutes, not a rate: the deposit route gets about four requests per 10 minutes and is genuinely slow, so a rate-based floor missed it.
• The threshold is 1.5 s rather than 1 s, chosen with the bucket grid in mind.
• Gateway routes are excluded and have their own alert at 12 seconds over 30 minutes. Two to eight seconds is normal there; the alert text says so, so the on-call engineer does not go hunting for a bug in our infrastructure.

Takeaways

• A service-level latency alert should name the route.
• Look at the distribution, not just the quantile.
• Pin the scrape job when you count anything.
• External dependencies get their own thresholds and an explicit note in the alert.