Distributed tracing

A trace is the full journey of one request across services. A span is one timed step inside that journey, such as the HTTP handler, a SQL query or a call to a payment provider. Spans nest. A parent span owns its children. The resulting tree is the waterfall you read during an incident, and it shows where the time went.

The big idea

Think of a restaurant order that passes through several stations. Each station stamps the ticket with its start and end time, and the ticket carries the same order number throughout. The order number is the trace ID. Each stamp is a span. Without the order number on every ticket, the kitchen gets a pile of unrelated slips.

Walking through it

A checkout request crosses four services. Each box is a span, and the numbers are the time each one took:

The waterfall makes the slow step obvious. Here is how to find it during a regression. Say p99 for POST /v1/checkout jumped from 180 ms to 900 ms after a midday deploy:

1. The metrics show the regression. The rate is steady, the errors are flat, and p99 is up.
2. In the trace backend, filter for service=checkout, the route, and duration over 500 ms, since the deploy.
3. Open a slow trace. The gateway takes 12 ms, the checkout handler 880 ms, inventory 11 ms, and the payments call 860 ms. Inside payments, the Postgres span takes 840 ms on a SELECT ... FOR UPDATE.
4. Compare with a fast trace from earlier. The same query took 40 ms.
5. The hypothesis is lock contention or a missing index from a schema migration. Check the recent migrations and the blockers in pg_stat_activity.
6. Mitigate first. Roll back the migration, or switch off the new code path, and confirm p99 recovers. Find the root cause afterward.

Without a span around the database call, that hour goes to grepping logs and blaming the wrong service.

Context has to travel

For the trace to stitch across services, each service must forward the trace context. The W3C standard header is traceparent:

traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

The parts are the version, the trace ID (32 hex characters), the parent span ID (16 hex characters), and the flags, which say whether the trace was sampled. Frameworks and service meshes often inject the header automatically. Custom HTTP clients, queues and workers often need it added by hand. If one hop drops the header, the waterfall splits into orphan traces.

Async work needs the same care. Put the context in the message headers for Kafka, SQS or Pub/Sub. A job that starts with a fresh trace ID cannot show which user click queued it.

Common mistakes

• No spans around database and cache calls. The gap then shows up as "the app is slow" with no cause.
• Losing the header at a queue. The worker's trace starts from nothing, and the link to the user request is gone.
• Only generic spans. "HTTP 200 in 90 ms" does not say which domain step was slow. Add a few manual spans for business steps.

Check yourself

1. A trace shows the gateway and checkout, but the payments service appears as a separate, unrelated trace. What is missing? The traceparent header was not forwarded on the call from checkout to payments.
2. Why does a span around the Postgres call matter in this waterfall? It shows that the 840 ms went to one query, which points to the lock, not to the application code.

Key takeaways

• A trace is a tree of timed spans for one request.
• The traceparent header and message metadata connect spans across services and queues.
• In an incident, filter for slow traces, open one, and find the widest span.

Further learning

Deciding which traces to keep is in trace sampling. The instrumentation library is in OpenTelemetry.

Google's Dapper paper is the origin of production tracing, and it introduced the trace and span model most systems still use.

Dapper, a Large-Scale Distributed Systems Tracing Infrastructureresearch.google