Observability: logs, metrics and traces

Observability is how quickly you can answer a new question about production using data you already collect. That data arrives as three signals: metrics tell you something is wrong and by how much, traces show where one request spent its time, and logs record exactly what happened. A shared trace ID turns three separate tools into one investigation.

Picture it first: a cricket match, three ways

A T20 match is recorded three ways at once.

• The scoreboard shows runs, wickets and the required rate. Tiny, always on, readable from the back row. It tells you the chase is in trouble, not why.
• Ball-by-ball commentary records every delivery: “short and wide, edged to third man”. All the detail, 120-odd entries an innings, and nobody reads it for the score.
• The ball-tracking replay follows one delivery from hand to bat, with speed and timing at each stage. It explains that ball perfectly and says nothing about the rest.

They work together because of the ball number: “over 14.3” appears in the fall of wickets, the commentary and the replay.

Map it back. The scoreboard is metrics, cheap aggregates for dashboards and alerts. The commentary is logs, one detailed record per event. The replay is a trace, one request’s path through every service. The ball number is the trace ID.

Monitoring vs observability

Monitoring watches for failure modes you already know about. Someone decided checkout’s p99 matters, built the dashboard and wrote the alert. It covers known unknowns: you know the question, not today’s answer.

Observability is a property of the system and its telemetry: how well you can work out what is happening inside from what it emits. When something new breaks, can you ask “are the slow checkouts all on app version 8.2, paying through one bank?” and answer it from data you already have, without shipping new code? That is the bar the OpenTelemetry observability primer sets, and how you handle unknown unknowns.

Two things make it possible: context on every record (route, region, version, customer tier), so you can slice a symptom along dimensions nobody pre-aggregated; and correlation, so you move from a metric to its traces to their logs instead of lining up timestamps by eye.

Monitoring doesn’t go away: black-box probes from outside tell you users are hurting now; white-box telemetry from inside tells you why.

One request, three signals

Each signal answers a different question about the same request. The metric says “one more checkout landed in the 2.5-second bucket”, among millions of others. The span says “2.01 of its 2.15 seconds were spent in payment”. The log line says why: payment waited 1.79 seconds for a database connection because its pool was full.

Logs: the detailed record

A log is a timestamped record of one event. Logs are best at detail: the error, the inputs, the branch taken, who asked for what. They are worst at aggregates (counting means scanning) and at cost, since volume grows with traffic times verbosity.

Structured, with a trace ID on every line

Payment failed for order 8812 after 3 retries is easy to write and painful to query. Emit structured records with a stable schema: the same field names and types in every service.

import json, logging
from opentelemetry import trace

log = logging.getLogger("payment")

def log_event(level: int, msg: str, **fields) -> None:
    ctx = trace.get_current_span().get_span_context()
    log.log(level, json.dumps({
        "level": logging.getLevelName(level),
        "service": "payment",
        "msg": msg,
        "trace_id": format(ctx.trace_id, "032x"),   # same ID as the trace
        "span_id": format(ctx.span_id, "016x"),
        **fields,
    }))

log_event(logging.WARNING, "pool wait", wait_ms=1790, pool_max=5, in_use=5)

With an OpenTelemetry SDK or auto-instrumentation active, your existing logging library’s records get the IDs stamped for you. The habits that matter:

• One wide entry per unit of work. Amazon’s Builders’ Library describes one structured log entry per request or queue message, carrying its timers, counters and metadata. It is cheaper than five chatty lines, and it is all you need to read when that request fails.
• Levels with meaning. ERROR: a request failed. WARN: degraded but handled (a retry, a fallback). INFO: lifecycle events. DEBUG: off in production, with a runtime switch to raise verbosity for one host or customer while you investigate.
• IDs everywhere, including request IDs returned by services you called. Nothing sensitive: no card numbers, OTPs or tokens, and truncate caller input.
• Rate-limit error spam, so a bug that throws on every request doesn’t write 5,000 stack traces a second.

Volume is the bill

A service at 5,000 requests a second writing five 500-byte lines per request produces 5,000 × 5 × 500 B = 12.5 MB/s, and 12.5 MB/s × 86,400 s ≈ 1.08 TB a day, about 32 TB a month before replication and indexing. The cost section shows how to cut that by more than 20×.

Metrics: cheap numbers over time

A metric is a number sampled over time, identified by a name and labels; each label combination is a separate time series. Metrics are best at alerts, dashboards, trends and SLOs: tiny, fast, and priced by series count, not traffic. They are worst at explaining one request and at high-cardinality dimensions like user IDs.

Counters, gauges and histograms

Prometheus, the widely used open-source metrics system, defines four types:

• Counter: only goes up, resetting to zero on restart. Requests, errors, bytes sent. You read its rate() per second, never the raw value.
• Gauge: goes up and down. In-flight requests, queue depth, pool connections in use. If it can go down, it’s a gauge.
• Histogram: counts observations into buckets (at most 50 ms, at most 100 ms …) plus a sum and a count. You compute any percentile later, over any window, across any set of instances.
• Summary: computes fixed quantiles such as p99 inside each process. Accurate per instance, but chosen at instrumentation time and impossible to combine across instances.

Space buckets roughly exponentially (the SRE book suggests steps of about 3×: 10, 30, 100, 300 ms), and put a boundary exactly at your SLO threshold so “requests under 300 ms” is a count, not an interpolation. Name metrics with base units: http_request_duration_seconds, http_requests_total.

Labels and the cardinality explosion

Every label combination is its own series, with its own memory, index entries and storage, so series count is a product.

Checkout’s latency histogram has 12 buckets. A classic Prometheus histogram stores 12 bucket series (including +Inf) plus _sum and _count: 14 series per label set. Label it by route (20 values), status class (5) and pod (50): 20 × 5 × 50 = 5,000 label sets × 14 = 70,000 series. Fine.

Now someone adds user_id “to debug one customer”. If 2 million users check out in a day and each touched just one route on one pod, that is 2,000,000 × 14 ≈ 28 million series from one metric, 400 times more, most written once and never again. Prometheus’s guidance: keep most metrics below a cardinality of 10, investigate anything that could pass 100, and never label with unbounded values like user IDs or emails.

Why you can’t average percentiles

A percentile is a rank, not a sum, so it does not survive averaging. Ten pods each serve 100 requests a second. Nine have a p99 near 100 ms; pod 7 sits on a bad host and every request it serves takes about 1 second.

The average of the ten p99s is (9 × 100 + 1,000) ÷ 10 = 190 ms. But pod 7 carries 10% of all requests, so the fleet’s slowest 1% are all on pod 7 and the true p99 is about 1 second. Averaging hid the incident. It can mislead the other way too: a canary taking 1% of traffic with a terrible p99 drags the average up while barely touching users.

Histogram buckets add, so sum them across pods and compute the percentile once:

# Wrong: averages each pod's precomputed p99 (a summary)
avg(checkout_latency_seconds{quantile="0.99"})

# Right: add every pod's bucket rates, then take the 99th percentile
histogram_quantile(0.99,
  sum by (le) (rate(checkout_duration_seconds_bucket[5m])))

The Prometheus docs call the first form statistically nonsensical. The same trap catches dashboards that average p99 across regions, or roll one-minute p99 points into an hourly figure. And the mean is no rescue: as the SRE book notes, a service averaging 100 ms can easily have 1% of requests taking 5 seconds.

Traces: one request’s journey

A trace is the tree of work done for one request. Each node is a span: one operation with a name, start time, duration, attributes, status and parent span ID. Traces are best at showing where time went across services, and worst at aggregate questions; keeping them all is expensive, so most are sampled away.

Reading a waterfall

The root span covers the whole request; children nest inside parents. Shapes worth learning:

• One long child: a slow dependency, or, as here, waiting for a scarce resource before the real work starts.
• A staircase of many short, sequential children: chatty I/O, such as 200 queries in a loop.
• The same call repeated: retries, often hiding a timeout.
• A gap inside a parent with no child: the service’s own CPU work or uninstrumented code. Profiles, covered below, explain those.

Context propagation: the traceparent header

For spans from different services to join one trace, every hop passes the context along in the header defined by W3C Trace Context (a Recommendation since February 2020, and OpenTelemetry’s default):

traceparent: 00-5a1e3c9b7f2d4e60a8c4b2f1d9e07c3a-c4f2a8e61b9d3075-01
#            │  │                                │                └ trace-flags: 01 = sampled
#            │  │                                └ parent-id: 8 bytes, 16 hex, the caller's span ID
#            │  └ trace-id: 16 bytes, 32 hex, same for every span in the trace
#            └ version: 00

Fields are lowercase hex and all-zero IDs are invalid. Each service keeps the trace-id, parents its span on the incoming parent-id, and sends its own span ID onward. The only defined flag, sampled, is a recommendation to the receiver. A companion tracestate header carries vendor data, and neither may hold personal data.

Libraries handle HTTP and gRPC automatically. Traces break at async hops (thread pools, cron jobs, message queues), where you must copy the context into message headers yourself or get orphan traces.

Head vs tail sampling

At 5,000 requests a second with 25 spans each, full tracing means 125,000 spans a second, nearly all boring. You sample.

Head sampling decides at the root, usually by hashing the trace ID against a rate so every service agrees, and passes the verdict on in the sampled flag. Cheap and blind: it can’t know this request will fail. Google’s Dapper sampled 1 in 1,024 traces by default and found that enough for high-volume services; tracing every request added 16.3% to a web-search cluster’s average latency.

Tail sampling decides after the trace finishes, in a collector: keep every error, every trace over 1 second, and 1% of the rest. You keep exactly the traces you want, but the collector buffers every span until it decides (30 seconds by default in OpenTelemetry’s tail-sampling processor), and every span of a trace must reach the same instance.

Many teams combine them: a generous head rate protects the pipeline, then tail rules choose. Anything dropped at the head never reaches the tail.

Logs vs metrics vs traces

What to measure: golden signals, RED and USE

Three checklists, each aimed at a different thing:

RED says whether a service is healthy for its callers; USE says which resource is the bottleneck, and pools and queues count as resources. Three details catch teams out:

• Measure failed-request latency separately. A 500 from a dead database can return in 2 ms, so mixing errors in makes latency look better while users fail. And a slow error is worse than a fast one.
• Short windows for saturation. Gregg describes five-minute averages that never showed CPU above 80% while it hit 100% for seconds at a time.
• Measure both ends of every call. If the client sees 2 s and the server 20 ms, the time went to the network, a queue or the client’s own pool.

OpenTelemetry: instrument once, send anywhere

OpenTelemetry (OTel), a CNCF project formed from OpenTracing and OpenCensus, standardises how telemetry is produced and shipped. It is not a backend.

• API: what code calls to start a span or record a metric. Without an SDK the calls are no-ops, so libraries can instrument without picking a vendor for you.
• SDK: installed by the application owner: samplers, batching, exporters, and resource attributes such as service.name, version and region.
• Auto-instrumentation: wraps HTTP, gRPC, database and messaging clients, producing spans, metrics and propagation without code changes.
• OTLP: one protocol for all signals, over gRPC (port 4317) or HTTP (4318).
• Semantic conventions: shared names (http.route, http.response.status_code) so one query works across services and languages.
• Collector: a vendor-neutral proxy that receives, processes and exports telemetry.

The agent runs beside the app, so the app offloads data locally and never blocks on a slow backend. The gateway tier does the heavy work, and because tail sampling needs a whole trace on one instance, agents route spans to gateways by trace ID.

Joining the signals

• Exemplars attach a sample measurement, with its trace and span ID, to a metric data point, so a heatmap’s 2.5-second bucket points at a real slow request.
• Trace IDs in logs let you open a span’s logs, or a log line’s trace.
• Shared resource attributes (service.name, version, region) make one filter work on all three stores.

Alerting on symptoms, not causes

The SRE book frames monitoring as what is broken (the symptom) and why (the cause). Page on symptoms users feel: checkout failing or slow. Causes such as CPU at 90% or a replica down belong on dashboards, unless definite and imminent, like “the disk fills in 4 hours”. Every page should be urgent, actionable and need judgement; robotic responses should be automated.

Burn rate

The cleanest symptom alert comes from your SLO (the theory lives in SLIs, SLOs and error budgets). With a 99.9% SLO over 30 days, the error budget is 0.1% of requests. Burn rate is the observed bad-event ratio divided by that budget: at 1 the budget lasts exactly 30 days, at 14.4 it lasts 720 h ÷ 14.4 = 50 h.

Decide how much budget is worth a page in a given window, then solve: burn rate = budget fraction × 720 h ÷ window.

These are the starting values the SRE Workbook recommends. For a total outage, the 1-hour ratio crosses 1.44% after 0.0144 × 60 min ≈ 52 s.

Multi-window, multi-burn-rate

A long window alone resets slowly: after the fix, a 1-hour average stays high for up to an hour. So each condition also requires a short window, 1/12 of the long one, to be burning now.

The arithmetic: at 6% errors the 1-hour ratio grows 0.1 points a minute and crosses 1.44% at 10 + 14.4 = 24.4 minutes. By then 6% × 14.4 min ≈ 0.86 minutes of full outage are spent, out of a monthly budget of 0.1% × 43,200 min = 43.2: exactly 2%. As Prometheus rules (the ratios are recording rules you define):

- alert: CheckoutBudgetFastBurn
  expr: |
    (checkout:bad_ratio:rate1h > 14.4 * 0.001 and checkout:bad_ratio:rate5m > 14.4 * 0.001)
    or
    (checkout:bad_ratio:rate6h > 6 * 0.001 and checkout:bad_ratio:rate30m > 6 * 0.001)
  labels: { severity: page }
- alert: CheckoutBudgetSlowBurn
  expr: checkout:bad_ratio:rate3d > 0.001 and checkout:bad_ratio:rate6h > 0.001
  labels: { severity: ticket }

A latency SLO works identically: a request slower than the threshold counts as a bad event.

Fewer, better pages

Pages that fire too often get skimmed until a real one is missed. Suppress duplicates (a fast burn also trips the slower windows), link each alert to a runbook, and remove rules nobody acts on.

Give every service the same dashboard: RED against the SLO on top, client-side RED per dependency below, USE for CPU, memory and pools at the bottom, and deploy markers on every graph.

A worked investigation: checkout p99 doubles

Checkout’s SLO: 99.9% of requests within 1.5 seconds. Its p99 is normally about 1 s.

1. The page. At 19:57 the fast-burn alert fires. About 4% of checkouts exceed 1.5 s, a burn rate of 4% ÷ 0.1% = 40; the 1-hour ratio needs 1.44 ÷ 4 × 60 ≈ 22 minutes to cross 1.44%, so trouble began around 19:35.
2. RED for checkout. Rate is normal for the hour. Errors are flat (the 3-second timeout to payment isn’t being hit). p99 is 2.1 s while checkout’s CPU sits at 45%: it is waiting on something.
3. Dependencies. Checkout’s client-side histograms show cart, pricing and inventory flat, and payment’s p99 up from 300 ms to 2 s. Payment’s own dependencies are flat (Postgres 12 ms, the bank near 200 ms), and a deploy marker sits at 19:35: payment v2.14.
4. Exemplar to trace. A dot in the heatmap’s 2.5-second bucket opens trace 5a1e…7c3a (Fig. 3): db.pool.acquire takes 1.79 s, the query 9 ms.
5. Trace to logs. Payment’s logs for that trace ID hold the WARNING line from Fig. 1: pool_max=5, in_use=5. The pool used to hold 50; v2.14’s config changed it to 5.
6. Fix and follow-up. Roll back; the 5-minute ratio drops and the page clears. Half an hour at 4% slow spent 4% × 30 min ÷ 43.2 min ≈ 2.8% of the month’s budget. Add pool wait time to payment’s dashboard, and gate config changes behind a canary that watches p99.

Nobody had a dashboard for “time waiting on the pool”. The span, the exemplar and the trace ID in the log answered an unplanned question, which is what observability means.

Cost and scale

Per-service telemetry budget at 5,000 requests a second:

The 500-byte span is close to Dapper’s measured 426 bytes. Sampling logs has a price: you can’t look up an arbitrary successful request, and some audit rules forbid it. Record the rate on each kept entry so counts scale back up.

Retention is a policy choice: often raw metrics for weeks (Prometheus’s local default is 15 days) and downsampled ones for a year, logs searchable for days then archived, traces for about a week. Keep high-cardinality questions (“which app version and bank hit the slow path?”) on events, traces and logs, and count unique users with HyperLogLog, not a user_id label.

Profiles: the emerging fourth signal

A profile samples stack traces to show which code burns CPU, allocates memory or blocks, explaining the “gap with no child span” in a waterfall. OpenTelemetry’s profiles signal is at Alpha status: an eBPF profiler for Linux needs no code changes, exports over OTLP, and can tag samples with trace IDs so a slow span links to the functions behind it.

Going deeper: how observability fails

• It dies with the system. Telemetry in the same cluster or region as the outage goes blank when you need it. Alert from separate infrastructure, alert on missing data, and page when a heartbeat alert stops firing.
• A label melts the metrics store. One deploy labelling by raw URL or user ID can multiply series by thousands and exhaust the database’s memory. Cap series per metric at ingestion.
• Log storms. Stack traces multiply volume exactly when you need the logs. Rate-limit per call site and load-test log shipping at peak.
• Clock skew. Spans from drifting hosts can start before their parents. Synchronise clocks, and trust same-host durations over cross-host timestamps.

Cheat sheet

How to say it in the interview

“I’d instrument every service with OpenTelemetry and ship through a collector tier. Metrics give RED per service and USE per resource, latency as histograms so percentiles aggregate, and no high-cardinality labels. Traces propagate W3C traceparent; I head-sample lightly and tail-sample every error and slow trace. Logs are structured JSON, one wide entry per request, with the trace ID on every line. I page only on SLO burn rate, and debug from metric to exemplar to trace to logs.”

How would you find why p99 doubled? Confirm it on RED, split by dependency, endpoint, region, version and deploy. Open an exemplar trace from a slow bucket, find the longest span or gap, and read that trace’s logs.

What’s wrong with averaging p99s? Percentiles are ranks, so their average means nothing. Nine pods at 100 ms and one at 1 s average 190 ms while the fleet p99 is 1 s. Sum histogram buckets, then compute once.

Head or tail sampling? Head decides at the root: cheap, consistent, blind to errors that haven’t happened yet. Tail decides after the trace completes, so it keeps every error and slow trace, but buffers every span and needs each trace on one collector. At scale, use both.

What do you alert on? Symptoms, as SLO burn rate: page at 14.4× over 1 hour (and 5 minutes) or 6× over 6 hours (and 30 minutes), ticket at 1× over 3 days. CPU and lag go on dashboards unless a cause is definite and imminent, like a disk filling within hours.

Why not put user_id on a metric? Each value creates series: 2 million users × 14 histogram series is 28 million from one metric. Put user IDs on spans and logs, and use exemplars to hop from metric to request.

Where to go next

• Reliability: SLIs, SLOs and error budgets: the SLIs and targets these alerts defend.
• Backend failure modes: the slow and gray failures telemetry must reveal.
• Health checks done right: probes, outlier detection and what they miss.
• Deployment strategies: canaries gated on RED metrics.
• Autoscaling done right: which saturation signals to scale on.
• Design metrics, monitoring and alerting: building the time-series backend.
• Design a distributed logging system: ingesting terabytes of logs a day.

References and further reading

1. Monitoring Distributed Systems (Google SRE book, chapter 6)sre.googleSymptoms versus causes, black-box and white-box monitoring, the four golden signals, separate latency for failed requests, and what makes a page worth sending.
2. Alerting on SLOs (Google SRE Workbook, chapter 5)sre.googleBurn rate, the multiwindow multi-burn-rate recipe (14.4× over 1 hour, 6× over 6 hours, 1× over 3 days), short windows at 1/12 of the long one, and low-traffic caveats.
3. Trace Context (W3C Recommendation)w3.orgThe exact traceparent format (version, 16-byte trace-id, 8-byte parent-id, trace-flags with the sampled bit), the tracestate header and the privacy rules.
4. OpenTelemetry documentation: Samplingopentelemetry.ioHead versus tail sampling, consistent probability sampling on the trace ID, and the operational costs of a stateful tail-sampling tier.
5. Prometheus: Histograms and summariesprometheus.ioWhy summary quantiles cannot be aggregated, why averaging them is statistically meaningless, and how histogram buckets are summed before histogram_quantile.
6. Prometheus: Instrumentation best practicesprometheus.ioCounter versus gauge, a counter per log line, and the label cardinality guidance with the 10,000 users on 10,000 nodes example.
7. The USE Method (Brendan Gregg)brendangregg.comUtilization, saturation and errors for every resource, including software resources, and how five-minute averages hid CPU saturation.
8. The RED Method: How to instrument your services (Grafana Labs, 2018)grafana.comTom Wilkie’s rate, errors and duration for every service, and how RED and USE complement the golden signals.
9. Dapper, a Large-Scale Distributed Systems Tracing Infrastructure (Sigelman et al., Google, 2010)static.googleusercontent.comSpans and trace trees, the 1-in-1,024 default sampling rate, measured tracing overhead by sampling rate, and about 426 bytes per span.
10. Instrumenting distributed systems for operational visibility (Amazon Builders’ Library)aws.amazon.comOne structured request log per unit of work, separate timers for successful responses, trace IDs in every log, log sampling and rate-limiting error spam.