The scenario is common enough to be cliché: a service that looks fast in isolation. Low CPU, reasonable memory, millisecond-level average latency. But the p99 is an order of magnitude worse. You add more instances; p99 doesn't budge. You look at your service's metrics dashboard; everything looks fine. The problem is upstream, downstream, or sideways, and your tools aren't built to find it.
Why aggregated metrics lie
Averages are almost useless for diagnosing latency problems. A p50 of 20ms with a p99 of 800ms means that 99% of your requests complete in under 800ms. It also means that 1% (1 in every 100 requests) takes over 800ms. At 1,000 requests per second, that's 10 slow requests every second. Your average looks fine because the fast 99% dominate it.
The shape of a latency distribution tells you a lot about the cause. A distribution with a low median and a heavy tail usually means an occasional slow path, not systemic slowness. Common triggers: a garbage collection pause that delays a thread serving an unlucky request, a downstream call that occasionally times out and retries, connection pool exhaustion when traffic spikes briefly, a database query that hits a missing index on an infrequently used code path.
None of these show up in your average. They may not even show up clearly in your p99 if your telemetry is aggregating across multiple instances with different traffic patterns. An average of p99s is not the same as the actual p99 of the aggregate. This is a surprisingly common mistake in dashboards: the number looks meaningful but isn't.
The other problem with metrics is that they're aggregates without causal structure. A metric tells you that database query latency is high. It doesn't tell you which request triggered which query, which service made the call, or whether the slow query was on the critical path or a background operation. For that, you need tracing.
Distributed tracing
A distributed trace follows a single request through every service it touches, recording latency at each step. The key concept is a span: a named, timed operation, like "process payment" or "query user database." Spans have a parent-child relationship: the span for "process payment" might contain child spans for "validate card," "call fraud service," and "update ledger." A complete trace is a tree of spans that tells you exactly where time was spent for that specific request.
The mechanism is a trace ID: a unique identifier generated at the entry point (usually the API gateway or the user-facing service) and propagated to every downstream call via HTTP headers or gRPC metadata. Each service records its own spans and emits them to a centralized trace collector (Jaeger, Zipkin, Honeycomb, Datadog APM) which assembles the tree.
The distinction from logs: logs are per-event strings with timestamps. They have no inherent causal structure. You can reconstruct causality from logs if you're diligent about including trace IDs in every log line, but you're doing by hand what tracing does automatically. The distinction from metrics: metrics are aggregates over time. They have no per-request detail. A trace is a per-request record with full causal structure.
These three tools (metrics, logs, and traces) are sometimes called the three pillars of observability. Each answers different questions. Metrics tell you something is wrong. Logs tell you what happened on a specific server. Traces tell you why a specific request was slow.
Reading a trace
A distributed trace is typically visualized as a waterfall, the same layout as a browser network waterfall, but across services instead of HTTP requests. The horizontal axis is time. Each row is a span. Child spans are indented under their parents. The width of a row shows how long that span took.
The first thing to look for: which span is widest? If the root span (the whole request) takes 800ms and one child span takes 750ms, everything else is noise. Dive into that child. Is it doing CPU work or waiting? If the span contains no child spans but takes a long time, it's either CPU-bound or blocking on IO without instrumentation (add instrumentation). If it contains child spans that account for most of its time, follow the chain down.
The second thing to look for: serial calls that could be parallel. If you see three 100ms
spans executing back to back (A completes, then B starts, then C starts) and they're
all reads from independent services, you have an opportunity. Run them in parallel and your
800ms becomes 100ms. This pattern is surprisingly common because it's easy to write:
await serviceA(); await serviceB(); await serviceC(); looks harmless until
you realize all three are independent.
The third: gaps. Time unaccounted for by any span. If the root span is 800ms but the child spans sum to 200ms, you have 600ms of mystery. That could be thread scheduling overhead, connection pool wait time, request queue time, or a missing instrumentation boundary. Gaps are where GC pauses show up: the JVM stops all threads, the trace records a gap, and there's no span to blame it on.
The common culprits
The N+1 query problem deserves its own sentence because it's so common and so invisible in code review. An ORM loads a list of orders, then lazily loads the line items for each order on first access. The code looks like: fetch orders, iterate over orders, access line items. What actually happens: one query to fetch 100 orders, then one query per order to fetch its line items: 101 queries total. In a trace, this shows up as 100 identical database spans each taking a few milliseconds, dominated by network round-trip time. The fix is a join or an explicit eager load; the ORM will do it, you just have to ask. But the code doesn't make it obvious you need to ask.
Serial HTTP fan-out is a close cousin. A service calls five upstream services in sequence to assemble a response. Each call takes 50ms. Total: 250ms on the critical path. If the calls are independent, they should be parallel: fire all five, wait for all five to return. Total: 50ms. Traces make this visible: you see five spans end-to-end instead of overlapping. Code review often doesn't catch it because the sequencing looks like normal control flow.
Connection pool exhaustion is subtler. A pool of 10 database connections serves a service running at 100 requests per second. If each request holds a connection for 20ms, you can support 10 / 0.020 = 500 requests per second in theory. But traffic is bursty. During a spike, requests arrive faster than connections are returned, and new requests queue. In traces, this shows up as a span that says "acquire database connection" taking an unexpectedly long time, sometimes longer than the query itself.
The tail latency amplification effect
This is the most important math in distributed systems performance. Suppose your service calls five upstream services in parallel, and each has a p99 latency of 10ms. What's your combined p99?
Not 10ms. The combined response is the maximum of five independent draws from a distribution. The probability that all five complete within 10ms is 0.99 raised to the fifth power, which is about 0.951. So there's about a 5% chance that at least one is slower than 10ms, which puts your combined p95 at the upstream p99. Your p99 will be wherever the upstream p99.5 or p99.9 is.
If each of those five services itself calls three more services, and those call two more, you're multiplying. A system with two hops of fan-out has a p99 that's the maximum of roughly 15 draws from each upstream distribution. The tails compound with every layer.
This is why microservices architectures are hard to make fast at p99. It's not that any individual service is slow. It's that the composition of many fast-on-average services produces a slow-at-tail aggregate. The only levers are: reduce fan-out on the critical path, improve the upstream tail latency (not just p50), or use hedged requests (resend the request if it hasn't returned by p75 and take whichever returns first. It's expensive in upstream load, effective for the user-facing tail).
Distributed profiling requires distributed observability
A service can look fast in isolation and be the proximate cause of slow user experience. The service that called it added latency on top. The service that called that one added more. The user-facing service that assembled everything made them serial when they could have been parallel.
Profiling a distributed system means tracing individual requests through the full call graph, reading the resulting waterfall, and being willing to follow the spans into services you don't own. The bottleneck is almost never where you initially think it is, usually because the place where symptoms appear isn't where the cause lives.
The tools exist. Instrumenting your service for tracing is an afternoon of work. Reading traces fluently takes practice. The investment pays off the first time you spend two hours on a tracing dashboard instead of two weeks on a hunch.
Back to writing