Backend / Observability / 08_three_pillars.md

The Three Pillars of Observability

Updated 4 interview angles 12 min read source
On this page11
  1. What each signal stores
  2. How the signals link
  3. Why the dashboard said 490 ms
  4. Who monitors the monitoring
  5. What it costs, with numbers
  6. The method on top: RED, USE and SLOs
  7. Instrumentation: SDK or eBPF
  8. Where it breaks in production
  9. The trade not taken
  10. Related
  11. Interview angle

The Three Pillars of Observability

Article.

Metrics, logs and traces, plus profiles as a fourth signal. Every interviewer asks for the list; the senior version of the question is “users say checkout times out, and the dashboard says p99 is 490 ms. How can both be true, and how do you find the cause?”

Answering it needs what each signal physically stores, how they link to each other, where a number on a dashboard stops meaning what it says, and whether the telemetry itself is being dropped.

Depth lives elsewhere and is linked rather than repeated: sampling in Sampling Strategies for Tracing, SLO maths in SLO, SLI, SLA, and Error Budgets, log format in Structured logging in Python, the OpenTelemetry SDK in OpenTelemetry, metric types and cardinality in Prometheus.

What each signal stores

Signal One record is Answers
Metric a number per series per scrape how much, how often, is it worse
Log one event with fields what exactly happened here
Trace a tree of timed spans for a request where the time went, across services
Profile sampled stacks over time which code burns CPU or memory

Metrics: cheap per event, expensive per label

A counter costs the same at 10 or 10,000 requests per second: the app adds in memory and Prometheus scrapes one number per series every 15-60 s. The cost is the number of series, which is the product of every label’s distinct values.

Prometheus keeps active series in memory, a few KB each, so a million active series is several GB of RAM on one server. A user_id label turns one series into one per user; that is why per-user detail goes to logs or traces. Mechanics and recording rules: Prometheus.

What metrics cannot do: tell you which request failed, or anything about a value you did not decide to count in advance.

Logs: cheap to add, priced by the byte

Every line is stored, so cost scales with traffic times verbosity. Logs are the only signal that keeps arbitrary detail (the exact SQL error, the payload id), which is why they are the last step of an investigation, not the first. Structured (JSON) lines with consistent field names are what make them queryable; see Structured logging in Python.

Traces: one request across services

A span records an operation with a start, a duration, attributes and its parent. Spans from different processes join into one trace because the caller sends the context in a header:

text
traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

The four dash-separated fields are the version (00), the 16-byte trace id, the caller’s span id (the new span’s parent), and flags (01 means sampled).

That is the W3C Trace Context standard, used by OpenTelemetry and every major vendor. A service that does not forward it (a hand-written HTTP client, a message on a queue without the header in its metadata) breaks the trace into two unrelated halves. Traces are sampled, because storing every span of every request costs more than the logs; see Sampling Strategies for Tracing.

Profiles: the signal for “where is the CPU going”

A sampling profiler records the call stack many times a second (py-spy defaults to 100 samples per second) and aggregates the stacks into a flame graph. A trace says the price_cart span took 900 ms; a profile says 600 ms of it was in json.dumps on a 4 MB dict.

Since 2025-26 this is mainstream rather than niche: Grafana Pyroscope 2.0 (April 2026), the OpenTelemetry Profiles signal in public alpha (March 2026, with an eBPF profiler that runs as a Collector receiver), and Python 3.15’s built-in sampling profiler, profiling.sampling (PEP 799), which can attach to a running process. Profiles link to traces through span ids, so a slow span opens the flame graph for exactly that time.

The point of having all of them is moving from one to the next without searching. Three mechanisms make that work.

1. The trace id in every log line

With OpenTelemetry’s logging instrumentation, each record carries the active trace and span id:

python
from opentelemetry.instrumentation.logging import LoggingInstrumentor

LoggingInstrumentor().instrument(set_logging_format=True)
log.warning("bank-api returned 503", extra={"order_id": order.id})
text
2026-10-14 09:12:03,118 WARNING [checkout] [payments.py:88]
[trace_id=4bf92f3577b34da6a3ce929d0e0e4736 span_id=00f067aa0ba902b7
resource.service.name=checkout trace_sampled=True] - bank-api returned 503

In a JSON logger, emit trace_id and span_id as fields. Loki, Elastic and Datadog then link a log line to its trace and a span to its logs.

2. Exemplars: from a metric spike to one trace

A histogram sample can carry the trace id of one request that landed in that bucket. In the OpenMetrics exposition it follows a #:

text
http_request_duration_seconds_bucket{le="2.5"} 4182 # {trace_id="4bf92f35"} 2.04

The prometheus_client library attaches it with observe(elapsed, exemplar={"trace_id": ...}). Prometheus stores exemplars only with --enable-feature=exemplar-storage, and Grafana shows them as dots on the latency panel that open the trace in Tempo. This is the step that turns “p99 went up” into “here is one of the slow requests”.

3. The same names everywhere

service.name, deployment.environment.name and the route must be spelled identically in metric labels, span attributes and log fields, or none of the links resolve. OpenTelemetry’s semantic conventions are that shared vocabulary, and they changed in 2023-25:

Old name Stable name
http.method http.request.method
http.status_code http.response.status_code
http.url / http.target url.full / url.path
db.statement db.query.text
deployment.environment deployment.environment.name

Instrumentation libraries switch over with OTEL_SEMCONV_STABILITY_OPT_IN (http/dup emits both during a migration). Dashboards and alerts keyed on the old names go quietly empty after an upgrade.

Why the dashboard said 490 ms

Back to the opening question. A simulation of two pods behind one service: pod A is healthy, while on pod B 30 requests hang for about 2 s (a stuck connection to the bank API). Buckets are prometheus_client’s defaults; histogram_quantile is reimplemented in Python exactly as Prometheus computes it.

python
def histogram_quantile(q, cum):          # cum: cumulative bucket counts
    rank = q * cum[-1]
    lo, prev = 0.0, 0
    for edge, count in zip(EDGES, cum):
        if count >= rank:                # linear interpolation in bucket
            return lo + (edge - lo) * (rank - prev) / (count - prev)
        lo, prev = edge, count
text
pod-a: true p99 0.297  reported 0.486
pod-b: true p99 2.038  reported 2.000
average of pod p99s       1.243
p99 from summed buckets   0.490
true p99, all requests    0.298
requests over 1 s         30 of 10000

Four lessons in six lines

Each line of that output is a separate trap:

  • p99 hides the worst 1% by definition. 30 slow requests in 10,000 are 0.3%: invisible at p99, and exactly the users who complained. Track the count over the threshold (le="1" bucket against the total) or p99.9.
  • Interpolation is not measurement. The true p99 is 0.298 s, but with bucket edges at 0.25 and 0.5 Prometheus can only say “somewhere in this bucket” and interpolates to 0.486. Put a bucket edge at your SLO threshold; a 300 ms SLO with no le="0.3" bucket cannot be computed.
  • Averaging percentiles is meaningless. 1.243 s describes no request. Sum the buckets across pods, then take the quantile.
  • The server never sees some failures. If the load balancer gives up at 2 s, or a worker is killed mid-request, the client-side latency is not in the server’s histogram at all. Measure at the edge too: load balancer metrics, or a synthetic check.

The investigation that finds it: the error-rate or over-threshold metric says “checkout, since 09:10”; an exemplar on the 2.5 s bucket opens a trace where the bank-api span takes 2 s; that span’s logs say the connection pool was exhausted.

Who monitors the monitoring

A quiet dashboard can mean a healthy system or a broken pipeline. Each hop fails in its own way:

Hop Failure How you see it
SDK span queue full queue drops spans “Queue is full” log line
Collector memory_limiter refuses data otelcol_receiver_refused_spans
Collector export backend down or slow otelcol_exporter_send_failed_spans
Prometheus scrape target down or timing out up == 0, scrape_duration_seconds
Log shipper backpressure, dropped lines the shipper’s own metrics
  • The app keeps running when the Collector is down. The Python BatchSpanProcessor buffers up to 2,048 spans (OTEL_BSP_MAX_QUEUE_SIZE), exports in batches every 5 s, and drops spans once the queue is full; it never blocks a request thread. A 10-minute Collector outage is a 10-minute hole in traces, not an outage. Only shutdown waits, up to the 30 s export timeout.
  • The Collector is a service like any other. Scrape its own metrics (with a _total suffix on counters in Prometheus format), alert on refused and send-failed counts and on otelcol_exporter_queue_size approaching otelcol_exporter_queue_capacity.
  • Alert on absence. A rule over a metric that has stopped arriving evaluates to nothing and stays silent. up == 0 and absent() catch it; see the dead-exporter case in Grafana.

What it costs, with numbers

A worked example: 50 services, 2,000 requests per second in total.

  • Metrics: 50 services x about 2,000 series each = 100,000 active series. A few hundred MB of RAM on one Prometheus; on a per-series SaaS price this is the line that grows when someone adds a label.
  • Logs: 3 lines of 500 bytes = 1.5 KB per request, so 2,000 req/s is 3 MB/s, about 7.8 TB a month. At CloudWatch Logs’ $0.50/GB ingestion that is about $3,900 a month before storage or queries.
  • Traces: 8 spans of about 1 KB per request = 16 MB/s unsampled, about 41 TB a month. Head sampling at 10% brings it to 4 TB; tail sampling keeps every error and slow trace with a similar total.

Logs usually dominate, which is why the levers are dropping health-check and debug lines, sampling routine INFO, and short retention for searchable logs. More in Cost as a signal.

The method on top: RED, USE and SLOs

  • RED for request-driven services: rate, errors, duration per route.
  • USE for resources: utilisation, saturation (queue length, waiting threads), errors. A pool at 100% utilisation is fine; a pool with callers waiting is not.
  • SLOs turn these into alerts that page on user impact (error-budget burn rate) rather than on causes like CPU; see SLO, SLI, SLA, and Error Budgets.

Instrumentation: SDK or eBPF

  • SDK auto-instrumentation (opentelemetry-instrument python app.py) patches frameworks and clients in-process. It sees routes, SQL text, your own attributes and the trace context, and needs a dependency and a restart.
  • eBPF instrumentation (OpenTelemetry’s OBI, formerly Grafana Beyla) watches syscalls and network traffic from the kernel without touching the app. It gets RED metrics and basic spans for any language at once, but has no in-process context: no business attributes, and limited propagation through async code.

The usual answer is eBPF for coverage on day one, the SDK for the services you debug most.

One gap to know in Python: the OpenTelemetry logs SDK is still marked Development (opentelemetry.sdk._logs, an underscore module), even though the logs data model is stable. Many teams keep the standard logging module writing JSON to stdout, with trace ids injected, and let the Collector or the platform ship it.

Where it breaks in production

  • p99 looks fine while users time out: the slow tail is under 1%, the buckets are too coarse, or the failures never reach the server.
  • Traces stop at the queue: the producer did not put traceparent in the message headers, so the consumer starts a new trace.
  • Dashboards go empty after an upgrade: semantic-convention names changed under queries that still use http.status_code.
  • A Prometheus OOM after a deploy: a new label with request ids, or pod churn creating new series on every rollout.
  • A quiet night that was not quiet: the Collector refused data under memory pressure, and nothing alerted on the Collector.
  • The log bill doubles: a DEBUG level left on, or a library logging every retry.

The trade not taken

One store of wide structured events instead of three signals. The Honeycomb argument: emit one rich event per request (or per span) with hundreds of attributes, including high-cardinality ones like user_id, and query it ad hoc; metrics and dashboards are pre-aggregations that throw away the question you have not thought of yet.

It is genuinely better for “which customers on which build hit this”, and tracing backends that query span attributes (Honeycomb, Tempo’s TraceQL, Datadog) have moved most teams part of the way there.

Teams still keep metrics because they are the cheapest way to alert and the only signal that survives 100% sampling at any volume, and logs because some detail belongs nowhere else. The pragmatic stance: spans as wide events, metrics for alerting, logs for the details, all sharing one trace id.

Interview angle 4

  • “The dashboard says p99 is 490 ms while users report 2 s timeouts. How can both be true?” - the slow requests may be under 1% of traffic, the quantile is interpolated inside a coarse bucket, and requests killed at the load balancer never reach the server’s histogram.
    • Follow-up: how would you prove the buckets are the cause? Compare the reported p99 with the bucket edges around it, and count requests over the threshold directly from the le bucket; add an edge at the SLO.
    • Follow-up: why not average the per-pod p99s? A percentile of percentiles describes no request. Sum the buckets, then take the quantile.
  • “How do you get from an alert to the line of code?” - the metric says what and when; an exemplar or a trace search gives one slow request; the span shows which dependency; its logs, joined by trace id, give the error; a profile, if it is CPU, gives the function.
    • Follow-up: the trace stops at the queue. Why? The producer never wrote traceparent into the message metadata, so the consumer had no parent context.
  • “How do you know your telemetry pipeline is dropping data?” - each hop reports its own drops: SDK queue warnings, the Collector’s refused and send-failed counters, Prometheus up. Alert on those, and on absence.
    • Follow-up: what happens to the app when the Collector is down for ten minutes? Nothing visible: the batch processor fills its queue and drops spans without blocking requests. You lose ten minutes of traces.
  • “When do you reach for a profile instead of a trace?” - when a span is slow but has no child spans to explain it: the time is inside your own code, and only stack sampling shows where.
    • Follow-up: what does Python 3.15 add? A built-in sampling profiler, profiling.sampling (PEP 799), that can attach to a running process without restarting it.