Distributed tracing

Follow one request across every service it touches: spans and the tree they form, trace context carried in headers and through queues, collectors that stay off the request path, why traces are sampled and what tail sampling demands, and the stored traces and dependency map that come out the other end.

Quote Q-88412 took three seconds

Support forwards a complaint with one detail: quote Q-88412 hung for seconds before the page showed a price. That request crossed the gateway, the quote service, pricing, risk scoring, a third-party claims-history provider, and a worker that emails the quote as a PDF. Every one of them logs, but on its own machine, by its own clock, and only the gateway's lines mention the quote number. Lining up six files by timestamp and guessing which lines belong to this request is the job nobody wants.

Instead, the engineer on call copies the trace id the gateway logged for the request, 4bf92f35…, and the tracing UI turns it into this:

  • gateway POST /quotes, 0 to 3,140 ms
  • quotes build quote, 8 to 3,132 ms, under the gateway
  • pricing price policy, 20 to 175 ms, under quotes
  • risk score driver, 20 to 3,105 ms, under quotes
  • risk GET claims-history, 30 to 1,030 ms, under score driver: timeout
  • risk GET claims-history, 1,080 to 2,080 ms: timeout
  • risk GET claims-history, 2,130 to 3,090 ms: 200 OK
  • pdf-worker render and email, 3,900 to 4,600 ms, follows quotes

Risk scoring's one-second timeout on the claims provider fired twice, and the third attempt answered. Pricing was never the problem.

Spans, and the tree they make

Each line is a span: one named unit of work, timed by the process that did it. A span carries its trace id, its own span id, the id of its parent span, a start time, a duration, a status, and attributes, key-value pairs such as the route, the response code or the quote id. Parent ids turn the spans of one trace into a tree whose root, the gateway's span, has no parent. That tree is a distributed trace: one request, every hop, one picture.

Reading it means finding the critical path, the chain of spans the request actually waited on. Pricing and risk ran in parallel under quotes, so only the one that finished last held quotes up: a pricing service twice as fast would have saved the customer nothing. The retries show as three sibling spans, where risk's own log line, scored driver in 3.1 s, hides them. The claims provider appears although nobody here instrumented it, because risk recorded a client span around each call. Why one slow dependency drags up the slowest percentiles of its callers is the subject of Latency percentiles & tail latency; better timeouts and retries belong to Resiliency: timeouts, retries & circuit breakers.

One caution: each start time comes from its own host's clock, and hosts can disagree by milliseconds or more, so a child can appear to start before its parent. The tree is still right, because it is built from ids, not timestamps.

How every hop learned the trace id

Nothing in HTTP tells risk it is working on the gateway's request, so each service passes on the trace context: the trace id plus the id of the span making the call. The common format is the W3C Trace Context traceparent header, such as 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01: a version, the 16-byte trace id, the 8-byte id of the calling span, and flags, one of which says whether the trace is sampled. The gateway, finding none on the incoming request, creates the trace id and root span; every later service starts its span as a child of the caller's and sends its own span id onward. Instrumentation libraries, today often OpenTelemetry's, do this inside the HTTP and message clients, mostly without touching business code.

The PDF needs more care. Quotes publishes a message to a queue and answers the customer, and a message has no request headers to inherit. So the producer writes the trace context into the message's metadata, a Kafka record header for example, and the worker reads it when it picks the message up, maybe minutes later: its span joins the trace after the customer has the price. A consumer handling a batch from many traces cannot have many parents, so its span can carry links to each message's context instead.

Propagation is only as good as its weakest hop. One hop that does not pass the context on, such as an uninstrumented service or a hand-off to a thread pool that drops it, and everything after it starts a fresh trace: two half-trees and no error anywhere. Nor is a trace context a Correlation Identifier, which matches one reply to one pending request; the parent id changes at every hop so the whole tree can be rebuilt.

Recording all this must not slow the quote down. Finished spans wait in a buffer inside the service and a background task ships them in batches to a collector nearby; when the collector is down and the buffer fills, a typical SDK drops spans rather than block the request, so traces get holes exactly when the system is under stress.

The context rides along

Diagram components: API Gateway, Application Service, Application Service, Third-Party API, Kafka, Worker Service, OpenTelemetry, Jaeger.

Every HTTP hop carries traceparent, and across the queue the context travels in the message. Spans leave each service in the background; only risk's export is drawn.

Why that trace was still there

Keeping every trace is rarely affordable. At 20,000 requests a second at the edge, 30 spans per request and about 500 bytes per span, that is 600,000 spans and 300 MB a second, roughly 26 TB a day. So traces are sampled.

Head sampling decides at the root, keep 1% for example, and writes the decision into the sampled flag of traceparent, so every service that honours it records or skips its spans to match, and traces are not kept by halves. A dropped trace's spans are not exported at all, so the saving starts inside the service. But at the first millisecond nobody knows this request will hit two timeouts: at 1%, Q-88412 would most likely have been thrown away with the healthy ones.

Tail sampling decides at the end. Every span is exported, a collector holds each trace's spans until the trace looks finished, then applies rules: keep every error, every trace whose root span took over two seconds, and a small random share of healthy ones as a baseline. Q-88412 survived on the latency rule. The price is that all spans of a trace must reach the same decider, since a collector holding only the gateway's span cannot know risk timed out, so spans are routed by their trace id, through a Kafka topic keyed by it, for example. And because a trace has no end marker, the decider typically waits a fixed time, holding spans in memory; a span that arrives later, like a PDF job stuck in the queue, can miss the decision. Storage shrinks; the traffic into the collectors does not.

What the kept traces are for

Kept spans answer two questions. Give me trace 4bf92f35… is one lookup by key, which a wide-column store such as Cassandra, partitioned by trace id, handles well. Which traces through risk took over two seconds last hour? is a search by service, duration and attributes, which needs a search index. Had the quote id been an attribute, support could have searched for it directly.

Millions of traces together also describe the system. Every client span is a call to a dependency, whether or not the dependency records spans of its own, and counting them with their durations and errors gives a dependency map: who calls whom, how often, how often it fails, and each edge's latency percentiles, including the calls a team forgot it makes. Compute those numbers from every span the collectors receive, before the tail sampler decides: the traces it keeps were kept because they were slow or failed, so every edge would look worse than it is. How traces sit beside metrics and logs is covered in Observability: metrics, logs & alerting.

Where Q-88412 would have been lost

The Distributed Tracing challenge asks for this system, built in-house; its palette has no application services, so what you build is everything after the instrumentation. A design breaks a trace like Q-88412 apart when its spans land on different samplers: each decides on the spans it holds, so the root can be kept while the spans that explain the delay are dropped; and one that keeps it whole can still mislead, if the dependency map is fed only by the traces that were kept.

All Learn articles