Debugging with Logs, Metrics and Traces
Open in the interactive app: practice, quiz, mock interview →In one minute
- Metrics tell you that something is wrong and how much. Traces tell you where the time or the error is in a request's path. Logs tell you what exactly happened inside one event.
- Debug as a funnel: start from a metric, slice it by dimensions until the bad population is small, pivot to a trace from that population, then to the logs for that trace.
- The most powerful question is a comparison: what is different about the failing requests compared to the succeeding ones, or about now compared to before?
- Correlation IDs are the glue. Without a trace ID in every log line and exemplars on metrics, you are matching timestamps by eye.
- Observability has a machine cost: every log line is a formatted string and a
write, every metric is an atomic increment and a time series. Design for the questions you will ask under pressure.
How it works
What each signal is good for
A metric is a number aggregated over time and labels: requests per second by route, error ratio by version, p99 latency by region. It is cheap to store and fast to query, which makes it the right place to detect problems and measure impact. It cannot tell you about an individual request.
A trace records one request's path through services as a tree of spans, each with a start, a duration, a status and attributes. It answers "where did these 2 seconds go?" and "which downstream call failed?". Because tracing everything is expensive, most systems sample, so a trace for the exact failing request may not exist.
A log is an event with context, ideally structured (JSON or key-value) rather than free text. It answers "what did the code see and decide?". Logs are the most expensive signal per byte and the hardest to aggregate unless they have a consistent shape.
The debugging funnel
Start with the metric that defines the symptom, such as the 5xx ratio. Slice it by each dimension you have: route, version, region, host, customer tier, upstream. A slice where the ratio is 20x the baseline is a lead; a slice where it is the same as everywhere is a ruled-out hypothesis. Once the population is small ("POST /cart, version 4.12, all regions"), jump to example traces for it. Many metrics systems support exemplars: a trace ID attached to a histogram bucket, so a click on the slow bucket opens a slow trace. In the trace, find the span where time or errors concentrate. Then open the logs filtered by that trace ID and span.
Compare against a baseline
"There are 4,000 timeout errors in the logs" means nothing without a baseline; there might be 4,000 every hour. The useful queries are differences: error templates that are new since the deploy, attributes that are over-represented in failing requests compared to successful ones, and latency distributions before and after. Tools that do this automatically (sometimes called BubbleUp or correlation analysis) are doing simple statistics you can also do by hand: count each value in the failing set and in the baseline set, and rank by the ratio.
Make logs queryable
Free-text logs become queryable by templating: replace the variable parts of a message (IDs, numbers, durations) with a placeholder so that "user 42 timed out after 3000ms" and "user 97 timed out after 2950ms" become one template. Counting templates over time turns millions of lines into dozens of rows, and a template that is new or suddenly 30x more frequent is usually where to look.
Down the stack
Layer 1The contract
The human process promises that every step narrows the population and leaves a link: "5xx ratio 1.2% overall, 14% on POST /cart v4.12 (query link), 0.1% elsewhere". A claim without a query behind it is a hunch. Testable: someone else can follow the links and reach the same population. The signals themselves have contracts too. A Prometheus counter only goes up and resets on restart, so rate() handles resets. A sampled trace set is representative only if sampling is independent of the outcome; tail sampling that keeps all errors is deliberately biased, which is good for finding errors and bad for estimating rates.
Layer 2The mechanism
Prometheus stores each time series as a sequence of (int64 millisecond timestamp, float64 value) samples in two-hour blocks, with the newest block in memory behind a write-ahead log (Prometheus docs). The compression follows Facebook's Gorilla paper, which uses delta-of-delta timestamps and XOR-encoded values and reports 1.37 bytes per point on average (Pelkonen et al., VLDB 2015); the Prometheus docs quote roughly 1 to 2 bytes per sample. Each unique label combination is a separate series, so a user_id label on a busy service can create millions of series and take down the monitoring system. Latency is usually stored as histogram buckets, so a p99 is interpolated within a bucket: with buckets at 100 ms and 250 ms, a "p99 of 180 ms" means somewhere between 100 and 250. Newer native histograms bound the error by a configured resolution instead of by hand-picked bucket edges, and the docs call averaging per-instance quantiles statistically nonsensical while summing histogram buckets first is valid (Prometheus docs).
Traces depend on context propagation. The W3C traceparent header carries 00-<32 hex trace-id>-<16 hex parent span-id>-<2 hex flags>, where the sampled bit is the least significant bit of the flags, so test it with a mask rather than comparing the whole byte. Trace Context has been a W3C Recommendation since November 2021 (W3C). Each service reads it, creates a child span with a new span ID, and writes a new header on outbound calls. Any hop that drops the header (a queue, a proxy, a thread pool that loses the context) breaks the tree into separate traces.
Log templating at scale uses algorithms such as Drain, which groups lines by token count and leading tokens in a fixed-depth parse tree, then merges lines whose tokens are mostly equal, turning differing positions into wildcards.
Layer 3The machine
A log line costs formatting (string building and allocation), then a write(2) to a file descriptor. In containers, stdout is usually a pipe to the runtime, which writes JSON-wrapped lines to a file on the node. If the reader falls behind and the pipe buffer (65,536 bytes by default on Linux) fills, the application's write blocks unless the descriptor is non-blocking (pipe(7)), and a logging burst becomes request latency. A metric increment is an atomic add on a shared counter: a few nanoseconds uncontended, but many cores incrementing the same cache line force it to bounce between cores, which is why high-performance libraries shard counters per CPU and sum on scrape.
Where the code has no instrumentation, the kernel does. eBPF programs on tracepoints like syscalls:sys_enter_connect or uprobes on a TLS library can count, time and sample events without redeploying, and /proc/<pid>/ exposes file descriptors, memory maps and per-thread CPU time. These are the signals of last resort when application telemetry is missing.
Why it's built this way
- You cannot predict the questions an incident will ask, so you keep events with rich dimensions rather than only pre-aggregated numbers.
- Raw events are expensive to keep, so you aggregate into metrics for detection and sample traces for depth.
- Signals are only useful together, so IDs (trace ID, request ID, exemplars) link them.
- Telemetry competes with the workload for CPU, memory and I/O, so formats, sampling and per-CPU counters exist to keep its cost bounded.
Diagram
flowchart LR
A["Alert: 5xx ratio up"] --> S["Slice metric by route, version, region"]
S --> P["Small bad population"]
P --> X["Exemplar trace ID"]
X --> T["Trace: find slow or failing span"]
T --> L["Logs filtered by trace ID"]
L --> D["Diff log templates vs baseline"]
D --> H["Hypothesis with evidence links"]Worked example
At 09:40 the 5xx ratio of a shop API rises from 0.1% to 1.2% of 50,000 requests per minute, about 600 errors per minute. Slicing by route: POST /cart is at 14%, every other route is normal. By version: both the old and the new version fail equally, which rules out the morning deploy of the API itself. By region: all regions. So the cause is probably shared and downstream.
A histogram exemplar from the slow bucket opens a trace: the inventory.reserve span takes 2,000 ms and ends in a timeout, while normally it takes 15 ms. The inventory service's own trace spans show 1,990 ms spent before the database query even starts.
Logs filtered to inventory for the last 30 minutes, templated and compared with the same window yesterday:
| Template | Yesterday | Now | Ratio |
|---|---|---|---|
pool exhausted waiting for connection after <*> | 0 | 4,100 | new |
reserve sku <> qty <> | 92,000 | 95,000 | 1.0 |
slow query <*> | 40 | 160 | 4.0 |
The new template points to the connection pool. The inventory config history shows the pool size went from 50 to 5 at 09:38 in a change meant for a staging environment. Reverting it brings the error ratio back to 0.1% within two minutes. Total time from alert to mitigation: 14 minutes, and every step has a query link for the postmortem.
In the wild
- Meta, 2021: the tools were down with the network. A backbone maintenance command disconnected every data centre, and DNS servers withdrew their routes. The post says the loss of DNS broke many of the internal tools engineers normally use to investigate and resolve outages, and with remote access gone people had to travel on site, where physical security slowed access further (Meta Engineering).
- Slack, 2021: dashboards behind the failing gateway. On 4 January an overloaded AWS Transit Gateway dropped packets and message success fell to 99% from over 99.999%. Dashboards and alerting also failed because they sat in a different VPC from their databases, so engineers queried metrics backends directly, which was much less efficient. The fix was to run the monitoring instances in the same VPC as their databases (Slack Engineering).
Trade-offs
| Signal | Strengths | Weaknesses | Choose when |
|---|---|---|---|
| Metrics | Cheap, fast, good for alerts and impact | Low cardinality, no per-request detail | Detecting and slicing |
| Traces | Shows causality and timing across services | Sampled, needs propagation everywhere | Latency and cross-service failures |
| Structured logs | Full context per event | Expensive, noisy without templating | Explaining one decision or error |
| Wide events (one rich event per request) | Arbitrary slicing at high cardinality | Needs a columnar store, cost grows with traffic | Teams that debug unknown unknowns often |
eBPF and /proc | No code change, kernel truth | Low-level, needs expertise and privileges | Missing instrumentation, system-level issues |
Pitfalls in production
- Searching logs before scoping with metrics, and drowning in noise. Fix: narrow the population with metrics first, then filter logs to it.
- Counting errors without a baseline. Fix: always compare to a previous window or to successful requests.
- Broken trace propagation through queues or thread pools, so traces stop at the first async hop. Fix: propagate context in message headers and wrap executors to carry context.
- High-cardinality labels on metrics exploding series count. Fix: put IDs in traces and logs, keep metric labels bounded.
- Logging that blocks the request path when the log pipeline backs up. Fix: asynchronous, bounded log buffers that drop with a counter rather than block.
- p99 from averaged per-host percentiles. Fix: aggregate histograms, then compute the quantile.
Leadership lens
- Set conventions: every log line carries trace ID, request ID, version and tenant; every service propagates
traceparent. - Review dashboards for the questions you will ask in an incident: error ratio by version and by dependency, not just totals.
- Budget telemetry cost explicitly and make sampling policy a deliberate decision (for example, keep 100% of errors, 1% of successes).
- Ask agents to produce the query, not just the conclusion, so humans can verify each narrowing step.
Check yourself
Why is "4,000 timeout logs in the last hour" not evidence by itself?
Show answer
Without a baseline you do not know whether that is normal. The useful evidence is the change relative to a previous window or to successful requests.
A trace shows the API span but no child spans for a call you know happened through a queue. What is the likely cause?
Show answer
Context was not propagated across the queue, so the consumer started a new trace. The message needs to carry
traceparentin its headers.Why can a tail-sampled trace store mislead you about error rates?
Show answer
Tail sampling keeps errors preferentially, so the stored set is biased toward failures. Use metrics for rates and traces for examples.
Why can heavy logging increase request latency in a container?
Show answer
Writes go to a pipe read by the runtime. If the reader falls behind and the pipe fills,
writeblocks the request thread.
Sources and further study
Primary
- W3C Trace Context: the
traceparentheader format and the sampled flag. - Pelkonen et al., Gorilla: A Fast, Scalable, In-Memory Time Series Database (VLDB 2015): the compression behind modern metric stores.
Systems docs
- Prometheus: storage: two-hour blocks, the WAL and the bytes-per-sample budget.
- Prometheus: histograms and summaries: how quantiles are estimated and why you cannot average them.
- Linux pipe(7): the default 64 KiB capacity behind the blocking log write.
Books
- Observability Engineering, Majors, Fong-Jones and Miranda, chapter 5 "Structured Events Are the Building Blocks of Observability" and chapter 8 "Analyzing Events to Achieve Observability": the wide-event argument and debugging from first principles.
- Site Reliability Engineering, Beyer et al., chapter 6 "Monitoring Distributed Systems": symptoms versus causes and white-box versus black-box monitoring.
Other curricula
- Azure Architecture Center: monitoring and diagnostics guidance: guidance on tracking usage, tracing resource utilisation and monitoring health and performance of distributed applications.
- donnemartin/system-design-primer: lists Dapper among its tracing references but does not teach a debugging workflow.
Watch
- Is It Time To Version Observability? (Charity Majors, GOTO 2024): wide events versus the three pillars and why it matters for debugging.
- Turnkey Distributed Tracing (Ben Sigelman, PyBay 2016): how traces are built and propagated, from a Dapper co-author.
Free resources
- Monitoring Distributed Systems (Google SRE book): the four golden signals and symptom-based alerting.
- W3C Trace Context: the
traceparentandtracestateheader formats. - OpenTelemetry signals: traces, metrics, logs and how they correlate.
- Instrumenting distributed systems for operational visibility (AWS Builders' Library): what to log per request and why.
- Dapper (Google Research): the paper that defined modern distributed tracing.