Distributed Tracing

A trace is identified by a 128-bit trace id. Each unit of work along the way is a span: a name, a start time, a duration, a service, attributes (http.route, db.statement), a status, and a parent span id. The gateway starts the root span; every downstream call creates a child span whose parent is the caller’s span. The result is a tree, rendered as a waterfall: each span a horizontal bar, indented under its parent, positioned by start time. Reading the waterfall is the skill: gaps between a parent’s start and its first child are *own time* (deserialisation, business logic); children laid end to end are *serial* calls; children stacked at the same x-position are *parallel*.

What a trace shows that logs cannot: fan-out (this request touched nine services); serial versus parallel (three 50 ms calls took 150 ms instead of 50 ms because they were awaited one at a time); the long tail’s cause (p99 is slow because 1% of requests hit a cold cache and cascade into a database storm); and who is waiting on whom during an outage (every trace ends in a span to the same slow dependency). A log search can find the lines; it cannot tell you the second call started after the first one ended.

The tree only forms if every hop passes the context along. The standard is W3C Trace Context: a traceparent header of the form 00-{trace-id}-{parent-span-id}-{flags}, where the last byte says whether this trace is sampled. HTTP clients inject it; HTTP servers extract it and make it the parent of their first span. For queues, the same values go in message headers so a consumer’s span is a child of the producer’s — hours later, if that is when the message is processed. The most common tracing bug is a broken chain: a hand-written HTTP client, a thread pool, or a queue library that drops the header, and the trace ends at that hop while a fresh, orphaned trace starts on the other side.

Here is the trace that motivates all of this. The gateway span is 235 ms. Under it, user service 35 ms, order service 180 ms. Under the order service, a single database span would be unremarkable — but there are 38 of them, 3–5 ms each, one after another. The order service fetched an order, then looped over its 37 line items and fetched each product by id. In the code that is one innocent for loop with an await inside; in a log search it is 38 lines that look like healthy fast queries; in the trace it is an unmistakable staircase. The fix is one query with WHERE id = ANY($1) (see Joins: INNER, LEFT, RIGHT, FULL, CROSS, SELF) or a batched lookup — and the trace shows the 140 ms collapsing to 6 ms the moment it is deployed. Across a service boundary the same pattern is worse: 38 HTTP calls at 20 ms each is 760 ms, which is the challenge the-140ms-database-span in its full form.

Beyond latency, traces show failures with their shape. A retry storm appears as a span with three identical children, each with three identical children (Circuit Breaker). A timeout mismatch appears as a caller span that ends at exactly 2,000 ms while its child keeps running for 5,000 ms — the work completed after the caller gave up, which is how a payment gets charged after the client saw an error. A cascading failure appears as every trace in the last five minutes ending in a red span to the same dependency. A missing bulkhead appears as unrelated routes sharing a queueing gap before their first span, because they share an exhausted pool (Reliability Patterns).

Tracing every request costs more than serving it — a request with 40 spans at 300 bytes each is 12 KB of telemetry for a 2 KB response. So traces are sampled. Head sampling decides at the root (the gateway keeps 5% by trace id, and the sampled flag propagates so every hop agrees), which is cheap and consistent but blind: the one slow request in a thousand is probably not in the sample. Tail sampling buffers every span at the collector for a few seconds and then keeps the whole trace if it was slow, errored, or otherwise interesting — which is what you want for debugging, at the cost of a stateful collector that must see all spans of a trace. Most production setups combine them: head-sample a baseline for latency distributions, tail-sample 100% of errors and everything over the p99 threshold.

The remaining cost is human: instrumenting hand-rolled clients, keeping span names low-cardinality (GET /orders/{id}, not GET /orders/81723), and resisting the urge to record request bodies in attributes. A trace is a diagnostic tool for the request you are looking at; it is not a log, and it is not a metric. The three signals in Logs, Metrics and Traces each keep their own job.