Why Tracing
A checkout request at Harborline touches five processes before the customer sees a confirmation. web terminates the browser call, bookings reserves the seat against db-01, checks the session in cache-01, and calls payments, which talks to the card processor. When that request takes 9 seconds, the question is not whether it was slow — Chapter 5's histogram already says so — but where the time went across those hops, and neither metrics nor logs can answer it.
A trace is the record of one request's full path, timed at every boundary it crosses. This chapter builds that third signal for Harborline, and by its last topic the trace exists that ends the Saturday mystery. First, the case for why the two signals you already have cannot do the job.
One Request, Five Services
Walk the checkout path once, slowly: the browser hits web, web calls bookings on port 8000, and bookings fans out mid-request — a session lookup in cache-01, an INSERT into db-01, then a synchronous call to payments on 8002. That is five network boundaries inside one user-visible operation, and every one of them is a place latency can hide. The rule that makes this hard: a caller's duration is the sum of its own work plus every downstream wait, so bookings reporting 9 seconds tells you the time passed through bookings, not that bookings spent it.
The Structural Blindness of Metrics
Metrics are aggregates. harborline_checkout_duration_seconds says the p99 hit 9 s on Saturday morning, which is exactly what a histogram is for — but the histogram earned its cheapness by throwing the individual request away at observation time. There is no bucket you can open to find the one checkout that took 9,310 ms; there are only counts of how many requests landed in each latency range.
Slicing by job does not rescue you. Each service self-reports latency that includes its downstream waits, so bookings at 9 s and payments at 190 ms is consistent with the problem living in bookings code, in the network, in db-01, or in cache-01 — the aggregate cannot say which hop inside one request ate the budget. Per-service latency panels look like request visibility and are not.
The Structural Blindness of Logs
Logs have the opposite problem: full detail, no connective tissue. On the slow Saturday, the two most relevant lines in Loki look like this — and even with the shared request_id joining them, nothing in them says who waited on whom, or for how long.
# bookings, on app-01
{"ts":"09:12:41.310","svc":"bookings","request_id":"c81f","msg":"checkout completed","duration_ms":9310}
# payments, on app-02
{"ts":"09:12:41.170","svc":"payments","request_id":"c81f","msg":"charge ok","duration_ms":190}
Reconstructing the path by timestamp fails precisely when you need it. At 200 concurrent checkouts the lines from every request interleave, and the clocks on app-01 and app-02 drift enough that "the payments line nearest in time" is routinely a different customer's charge. Chapter 7 gave each line rich local detail and a shared request_id; what the lines still lack is timing structure — parent, child, and where the clock ran.
The Trace
A trace renders one request as a timed tree: a root span covering the whole checkout, and a child span for every downstream call — the cache-01 lookup, the db-01 INSERT, the payments charge. Laid out as a waterfall, the 9,310 ms total decomposes visually, and 9,020 ms of it sits in a single bar inside bookings. The "where did the time go" question is answered by construction, not by correlation: the tree structure is recorded when the request runs, so there is nothing to reconstruct afterward.
The Third Signal's Question
This completes the book's division of labor. Metrics say something is wrong — cheap, aggregated, alertable. Logs say what happened at that moment — one event, full detail. Traces say where in the request path it happened — one request, timed across every service it touched. Traces are also the most expensive signal per request, which is why Topic 42 exists to control that bill; you pay the premium because they answer the question the cheap signals structurally cannot.
The Saturday Mystery, One Signal Short
Take stock of where seven chapters have left Mara. Chapters 5 and 6 proved the complaint real: weekend checkout p99 breaches the 500 ms target, visibly, on a dashboard. Chapter 7's logs named the error — connection pool timeout — but not where the time went inside each request; plenty of slow checkouts still complete, just late. She has when and how bad. She does not have where, and this chapter builds the signal that finishes the job.
- Reconstructing request flow by grepping timestamps across five services' logs — at 200 concurrent checkouts the lines interleave,
app-01andapp-02clocks drift, and the "match" you find is a different customer's request. - Adding per-service latency panels and calling it request visibility — each service self-reports time that includes its downstream waits, so
bookingsat 9 s andpaymentsat 180 ms still doesn't say whether the 9.1 s gap isbookingscode, the network, or a queue. - Logging entry/exit lines with durations in every service as a homemade trace — you rebuild tracing badly, pay Loki for every request at 100% retention, and still reconstruct parent-child timing by hand from timestamps that skew across hosts.
- Expecting traces to replace metrics for alerting — traces are sampled and per-request, so computing a p99 or an error ratio from them is slow and incomplete; the alert (Chapter 9) stays on the metric.
- Reach for a trace when the question contains "across" — across services, across a queue, across a retry — and keep single-service questions on metrics and logs, which are cheaper to store and query.
- Instrument the request path end to end before trusting any trace — a trace that covers only
bookingsshows one span and answers nothing about thepaymentshop. - Keep the three signals joined by shared identity —
service.namematching the Prometheusjoblabel, and thetrace_idwritten into every log line — so Topic 43's metric-to-trace-to-logs jump works without re-typing timestamps. - Start tracing on the highest-value path first: Harborline traces checkout before search, because checkout latency is money and the Saturday mystery lives there.
Knowledge Check
Saturday's p99 for harborline_checkout_duration_seconds shows 9 s. Why can't the histogram say where those 9 seconds went?
- Histograms track averages, so tail latency like a 9 s request is invisible to them
- Aggregation discarded the individual request; only bucket counts remain
- The 15 s scrape interval is too coarse to capture a request that only took 9 s
- Prometheus silently drops observations that exceed the largest bucket boundary
Why does matching log lines across services by timestamp fail as a way to reconstruct one request's path?
- Loki stores lines out of order, which makes timestamps unreliable at query time
- Log timestamps are truncated to whole seconds, too coarse to match on
- Concurrent requests interleave and clocks drift between hosts
- Each service logs in its own timezone and the conversion loses precision
Mara needs to know whether a 9 s checkout spent its time in bookings code, in the payments call, or waiting on db-01 — within that one request. Which signal answers this?
- Per-service p99 latency panels, compared side by side
- The bookings error logs, filtered to the slow minute
- A trace of that request
- A per-service request counter sliced by job
For the same checkout, payments reports 190 ms while bookings reports 9.2 s. What explains the gap?
- Network latency between app-01 and app-02 accounts for the missing time
- bookings' self-reported duration includes all its downstream waits
- payments drops its slowest requests from the histogram, hiding its real latency
- Clock skew between the hosts inflates the bookings measurement
You got correct