Logs Metrics Traces Correlation and Production Debugging

Published by Programming Line in System Design and Distributed Systems. Last updated .

Purpose: debug one user journey, not three separate datasets

Logs, metrics, and traces answer different questions during production debugging. Metrics say that something changed: error rate rose, latency shifted, queue depth grew, or saturation crossed a threshold. Logs explain discrete events: a validation failed, a dependency returned 503, a feature flag branch was taken, or a retry policy gave up. Traces show causality across service boundaries: checkout called inventory, inventory called pricing, pricing waited on a cache, and payment failed after 900 milliseconds. Correlation is the design work that lets those signals describe the same request, tenant, job, device, or deployment.

The outcome for this lesson is practical: given a production symptom, you should know which signal to inspect first, how correlation identifiers move through a system, what to put in each signal, and how to avoid making observability either too expensive or too noisy to use. This belongs in system design because debugging ability is an architectural property. A service mesh, async queue, batch worker, mobile client, and CDN edge function all change what can be observed and where context can be lost.

How the signals work internally

A log record is an append-only event emitted by code or infrastructure. In modern systems it should be structured, usually key-value data serialized as JSON or a compact binary format. The logging pipeline typically has an agent on the node or sidecar, a transport buffer, an indexing or object-storage tier, and a query layer. Good fields are stable and low-surprise: timestamp, severity, service, environment, version, operation, trace_id, span_id, user-safe subject identifiers, and an event name. The free-text message is useful for humans, but fields are what make logs joinable.

A metric is a numeric time series: a measurement plus labels. Counters only increase, gauges move up and down, histograms bucket observations, and summaries estimate quantiles. Metrics systems trade detail for speed. They are excellent for alerting because a query such as payment_error_rate over five minutes is cheap compared with scanning millions of logs. The hard limit is label cardinality. Labels such as service, route, status_code, and region are usually useful; labels such as raw user_id, order_id, or trace_id can create an unbounded series explosion.

A trace is a directed tree or graph of spans. A span has a trace id, span id, optional parent span id, service name, operation name, start time, duration, attributes, events, and status. Context propagation is the internal mechanism that makes a trace cross process boundaries. An inbound request arrives with a trace context header; the service creates a child span; outbound HTTP, RPC, or messaging clients inject the current trace context into the next call. Without propagation, every service may produce spans, but the trace viewer cannot assemble the path.

Correlation binds these signals using shared dimensions. The strongest link is trace_id: logs written while a span is active include the active trace id and span id, and exemplars or trace links connect a high-latency metric bucket to a representative trace. Deployment version, region, pod, route, tenant tier, and feature flag are secondary correlation fields. They help when the issue affects many requests and an individual trace is too narrow.

API and configuration anatomy

Instrumentation has four important surfaces. First, inbound middleware extracts trace context and starts a server span. Second, outbound clients inject context and record dependency spans. Third, the logger reads the current context and adds correlation fields automatically. Fourth, metric instruments record counters and histograms with bounded labels. The service owner should configure sampling, retention, redaction, and alert queries explicitly. Defaults often collect enough data for demos but not enough discipline for real incidents.

Trace sampling has two common forms. Head sampling decides at request start whether to keep a trace. It is cheap but may drop rare errors. Tail sampling decides after seeing the whole trace, allowing policies such as keep all errors, keep slow requests, and sample normal traffic. Tail sampling needs buffering and more collector capacity. Log sampling is different: repetitive logs can be sampled by event type, but error logs that carry diagnostic state usually need retention long enough to support incident review.

Example 1: structured log with trace context

The first step is making a single service emit a log that can be joined to a request trace. The trace id is not just text decoration; it is the key a log search can use after an engineer opens a slow trace.

import json
import uuid

trace_id = uuid.UUID('12345678-1234-5678-1234-567812345678').hex
log = {
    'level': 'INFO',
    'service': 'checkout',
    'operation': 'POST /orders',
    'trace_id': trace_id,
    'span_id': 'checkout-1',
    'message': 'accepted order request',
}
print(json.dumps(log, sort_keys=True))

The deterministic part of the output is the field shape and the trace id. A real UUID generator would create a new value per request, but every log line in that request should carry the same trace_id. The expected output is one JSON object sorted by field name, including service checkout, operation POST /orders, span_id checkout-1, and the 32-character trace id 12345678123456781234567812345678.

Example 2: deriving metrics from spans

Metrics summarize many events into a small set of time series. A collector can derive request count, error count, and latency distribution from spans, or application code can record them directly. This example compresses three spans into service-level numbers.

spans = [
    {'service': 'checkout', 'name': 'POST /orders', 'duration_ms': 142, 'status': 'ok'},
    {'service': 'inventory', 'name': 'reserve', 'duration_ms': 38, 'status': 'ok'},
    {'service': 'payment', 'name': 'authorize', 'duration_ms': 611, 'status': 'error'},
]

count = len(spans)
errors = sum(1 for span in spans if span['status'] == 'error')
total_latency = sum(span['duration_ms'] for span in spans)
print(f'requests_total {count}')
print(f'request_errors_total {errors}')
print(f'request_duration_ms_avg {total_latency / count:.1f}')

The output is requests_total 3, request_errors_total 1, and request_duration_ms_avg 263.7. In production you would normally use a histogram instead of an average because averages hide whether latency is one uniformly slow dependency or a small number of extreme outliers. The example still shows the key relationship: spans have rich per-request detail, while metrics provide cheap aggregate detection.

Example 3: reconstructing the failing request

During an incident you often start with a metric alarm, jump to a trace, then read logs that share the trace id. This example groups mixed events by trace_id to show why correlation fields matter.

events = [
    {'trace_id': 'a1', 'service': 'checkout', 'kind': 'log', 'message': 'cart submitted'},
    {'trace_id': 'b2', 'service': 'checkout', 'kind': 'log', 'message': 'cart submitted'},
    {'trace_id': 'a1', 'service': 'payment', 'kind': 'span', 'duration_ms': 180, 'status': 'ok'},
    {'trace_id': 'b2', 'service': 'payment', 'kind': 'span', 'duration_ms': 920, 'status': 'error'},
    {'trace_id': 'b2', 'service': 'payment', 'kind': 'log', 'message': 'gateway timeout'},
]

for trace_id in sorted({event['trace_id'] for event in events}):
    related = [event for event in events if event['trace_id'] == trace_id]
    statuses = [event.get('status') for event in related if event.get('status')]
    messages = [event.get('message') for event in related if event.get('message')]
    print(trace_id, statuses or ['no span status'], messages)

The b2 group contains a payment span with status error and a gateway timeout log. The a1 group contains a normal payment span. A production trace viewer performs this grouping at scale, but the principle is the same: without the trace id on both log and span events, the engineer would be reduced to timestamp guessing.

Design choices and trade-offs

Choose correlation identifiers deliberately. A trace id should be generated at the edge or accepted from a trusted upstream format, then propagated everywhere. A request id may be useful for HTTP access logs, but if each service creates its own unrelated request id, it cannot replace a trace id. Business identifiers such as order_id are useful secondary fields, but they require privacy review and access control because they may expose customer activity.

Keep metric labels bounded. Labeling request latency by route and status class is useful; labeling by exact URL with embedded IDs is dangerous. The trade-off is diagnostic precision versus query cost and storage cardinality. Put high-cardinality details in logs or trace attributes, then use trace links to reach them from aggregate metrics.

Decide where instrumentation lives. Library instrumentation gives broad coverage quickly for HTTP clients, database drivers, queues, and frameworks. Manual spans add domain meaning around checkout authorization, inventory reservation, or reconciliation. Too much manual instrumentation makes traces noisy; too little leaves a black box around the code that actually matters.

Failure modes and troubleshooting

A common symptom is broken traces: the checkout span exists, payment spans exist, but they appear as separate traces. The likely cause is missing context propagation in an outbound client, queue producer, worker, or gateway. Diagnose by inspecting headers or message metadata at each hop, then verify that the consumer extracts the same trace id before starting work. Correct it by enabling instrumentation for that client or explicitly injecting and extracting trace context.

Another symptom is an observability bill or metrics backend load that grows faster than traffic. The cause is usually high-cardinality labels, such as user_id, session_id, raw path, or trace_id in metrics. Diagnose by listing top series counts by metric name and label. Correct it by removing the unbounded label, normalizing routes such as /orders/:id, and moving per-entity detail to logs or traces.

A third symptom is logs that cannot explain an error even though error rate and traces show the failure. The cause is often inconsistent logging scope: the log was emitted outside the active span, the logger was not context-aware, or exception details were swallowed. Diagnose by comparing timestamps and looking for missing trace_id or span_id fields. Correct it with logging middleware, structured exception handlers, and tests that assert correlation fields exist on representative log events.

Reliability, security, and performance implications

Observability pipelines are production dependencies, but they should not be in the synchronous critical path. Agents and SDKs need bounded queues, backpressure behavior, and drop policies so a telemetry outage does not take down the application. Prefer batching exports and using local collectors where possible. For high-throughput services, sample traces and debug logs intentionally, while keeping metrics complete enough for alerting.

Security controls are part of the design. Logs and traces often contain URLs, headers, SQL snippets, exception messages, and user-provided values. Redact secrets before export, restrict access to sensitive indices, and avoid storing payload bodies by default. Correlation should help operators find the right event without turning observability storage into a second customer database.

Hands-on lab: local correlation drill

Prerequisites: a shell with Python 3 and permission to run a temporary script. No external service is required. Create a local script from the three examples, run it, and observe how the same trace id links log events, span status, and aggregate numbers. Step 1: run the structured log example and confirm the JSON contains trace_id and span_id. Step 2: run the metrics example and confirm the aggregate error count is one. Step 3: run the grouping example and identify which trace failed. Step 4: change the b2 payment status to ok and rerun; verification should show no error status in b2, while the gateway timeout message remains a clue that the log and span now disagree. That disagreement is intentional: it demonstrates why production debugging compares signals instead of trusting one line. Cleanup is simply removing the temporary script or closing the shell session.

Assessment exercises

  1. A latency alert fires for POST /orders only in one region. Which metric labels should you check first, and which trace attributes would you inspect next?
  2. A queue worker starts new traces for every job even though the HTTP producer has a trace. Describe the missing propagation step and how you would verify the fix.
  3. Your team wants to add customer_id to every metric. Explain the cardinality risk and propose a safer way to debug one customer complaint.
  4. An error log has order_id but no trace_id. What can you still correlate, and what debugging ability has been lost?
  5. Design a tail-sampling policy for a checkout service where normal traffic is high, payment errors are rare, and slow inventory calls are important.

Summary

Logs, metrics, and traces are not interchangeable. Metrics detect shifts cheaply, traces explain request causality, and logs preserve discrete facts that spans and aggregates cannot carry. Production debugging becomes fast when correlation ids, bounded labels, context-aware logging, and thoughtful sampling are designed into the system before the incident. The trade-off is discipline: every added field, span, label, and retention rule must earn its cost by making a real operational question easier to answer.