Distributed Tracing

The problem

"One request to our shop crosses 10 services. Design the system that shows where its time went." Metrics can say that checkout got slow; a trace of one request says which service made it slow.

This practice problem reuses the pattern of Design Metrics and Alerting. What's new: tying one request's pieces together across 10 services, pieces that arrive out of order from many machines, far too many requests to keep, and a view of where the time went. Park alerts and log lines.

The numbers

From the interviewer: 100,000 requests a second, each crossing 10 services that each record one span. Say a span is about 500 bytes, and round a day to 100,000 seconds (86,400 really).

what              estimate
spans a second    100,000 × 10 = 1 million
bytes a second    1 million × 500 bytes = 500 MB
a day, all kept   500 MB × 100,000 s ≈ 50 TB (about 43 TB with 86,400)

That's over 300 times the metrics system's 140 GB a day. One span per request, the usual slip, gives 5 TB.

What a span records

A span is one service's piece of a request: the trace id, its own span id, the id of the span that called it (the parent span id), a name such as payments POST /pay, start and end times, and whether it failed. Leave out request bodies (big, often private) and log lines (the log system's job). The parent ids make a tree:

span          trace   parent   start–end (ms)
edge e1       4bf9    –        0–900
checkout c1   4bf9    e1       10–890
payments p1   4bf9    c1       710–880

Passing the trace id on

About 100 requests start every millisecond, so spans can't be matched by time, and ids made up by each service would never match. Instead the edge makes the trace id, and every call passes it on in a header with the caller's span id. The common standard is OpenTelemetry, which uses the W3C traceparent header:

POST /pay
host: payments
traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

Its parts: a version, the 16-byte trace id, the caller's 8-byte span id, and flags (01: "sampled"); the table above shortens the ids. Payments records its span under that trace and parent, then passes the trace id and its own span id on.

Putting a trace together

Each span goes to a collector picked by a hash of its trace id, so all spans of a trace meet at one collector; round robin would scatter them. Services send spans in batches every 5 seconds, so they arrive out of order. Trace 4bf9 at collector 7:

span          arrives
pricing       1.4 s
edge (root)   2.0 s
cart          2.6 s
checkout      3.1 s
payments      3.3 s
stock db      5.6 s
stock         5.6 s

Writing it when the root arrives would miss five spans: the root ends last but isn't sent last. Waiting for 10 spans fails too: this request crossed 7 services. What works: the trace is complete once no new span has come for 30 seconds, here at 35.6 s. The price is memory: 1 million spans a second × 500 bytes × 30 s = 15 GB across the collectors.

Sampling: head or tail

Keeping everything is 50 TB a day. Say 1 in 100 requests is slow (over half a second) or fails: those are the traces engineers open.

• Head sampling decides at the start: the edge keeps 1 in 100 and sets the sampled flag, so the other services skip the rest. Cheap, about 500 GB a day, but nobody knows yet which request will be slow: 99 in 100 slow or failed ones are thrown away.
• Tail sampling decides at the end, once the trace is complete: keep every slow or failed trace and 1 in 100 of the rest. That's 1,000 + 990 = 1,990 traces a second, about 2%, so about 1 TB a day. The cost: every service sends every span, and each trace waits 30 s for the decision.

The trace store looks a trace up by its id, with a small index by service, duration and status to find "slow checkouts in the last hour".

Finding the slow span

The viewer draws a trace as a waterfall: one bar per span, each under the span that called it. Trace 4bf9, in milliseconds:

span       start–end   own time on the critical path
edge       0–900       20
checkout   10–890      30
cart       20–220      off the path
pricing    20–300      off the path
stock      20–700      40
stock db   40–680      640
payments   710–880     170

A bar includes the calls it waits for, and calls side by side cost only the slowest: the request waits for stock, not cart or pricing. The critical path is the chain the request waited for: edge, checkout, stock, stock's database query, then payments. Its pieces add up to 900 ms; the biggest is stock db, 640 ms. A faster cart or pricing wouldn't save a millisecond.

Same pattern as Metrics and Alerting

A library in every service sends in batches, like the metrics agents; ingest is the busy path, mostly never read; collectors take the writes apart from the viewer's reads; and data is cut down before it's kept, by rollups there and by sampling here. Together: metrics say when, a trace says where, and logs tagged with its trace id say why.

Summary

• Scope: tie one request's spans together, keep some, show where time went.
• Numbers: 1 million spans, about 500 MB, a second; 50 TB a day if all kept.
• Span: trace id, span id, parent span id, name, start, end, status.
• Trace id: made at the edge, passed in the traceparent header on every call.
• Assembly: spans routed by trace id; complete after 30 s with no new span.
• Sampling: at the tail, every slow or failed trace and 1 in 100 of the rest: about 1 TB a day.
• Waterfall: the slow span is the biggest piece of the critical path.