Trace-Based Debugging & Signal Correlation

A distributed trace that no one can query under pressure is just storage cost. The hard part of production observability is not capturing telemetry — auto-instrumentation does that — it is answering two questions fast, at 3 a.m., while an SLO burns: why was this request slow, and why did it fail. Teams routinely have traces, logs, and metrics all flowing, yet an incident still turns into twenty minutes of tab-switching because none of the three signals shares a join key, and no one knows which span on the timeline actually caused the latency.

That is the observability gap this reference addresses. Metrics tell you something is wrong — error rate crossed a threshold, p99 doubled — but they are aggregates with no request-level detail. Logs hold the detail but are scattered across services with no reliable way to reassemble one request’s story. Traces hold the causal structure but, on their own, do not tell you which of forty spans is on the critical path or link out to the log line that carries the stack trace. The consumption side of tracing — correlating the three signals, reading the critical path, and driving alerts from span data — is what converts raw telemetry into root-cause answers. The other capability areas on this site cover producing that data: the fundamentals and architecture of traces themselves, SDK and context propagation, and baggage and metadata routing. This reference is about using it.

Core Concepts & Terminology

Architectural Overview

Correlation only works when all three signals carry the same key. The trace_id generated at the edge is that key: every span inherits it, every log line written inside a span’s scope should stamp it, and every latency histogram observation can attach it as an exemplar. Downstream, an analysis plane — Grafana over Tempo/Prometheus/Loki, or a managed backend — pivots on trace_id to move from a metric spike to an exemplar trace to the exact log line holding the stack trace, without a human guessing timestamps.

The design rule the diagram encodes: trace_id is not one signal’s private identifier, it is the shared join key across all three. If any signal drops it — logs written without it, metrics with no exemplars — that signal falls out of the correlation graph and becomes an island you can only reach by manually matching timestamps. Everything in the sections below exists to keep that key present and consistent from emission through analysis.

Instrumentation Models: Recording Debuggable Spans

A span you cannot debug from is a span whose status, exception, and salient attributes were never recorded. Auto-instrumentation gets you span boundaries and HTTP/DB semantic attributes for free, but it does not know your domain: it will not mark a 200 OK response that carried an application-level error as failed, and it will not record the business context that makes a trace legible. That judgement is manual. The distinction between capturing a span and capturing a debuggable span is the difference between “the request touched these services” and “the request failed here, for this reason, with this stack trace.”

Three things make a span debuggable: an accurate status (unset for success, ERROR for failure — never guess from HTTP codes alone), exceptions recorded as span events so the stack trace travels with the trace, and bounded attributes that describe what the operation was doing. The example below, built on top of a standard OpenTelemetry SDK setup, shows all three within the span lifecycle.

# Python: recording a debuggable span
from opentelemetry import trace
from opentelemetry.trace import Status, StatusCode

tracer = trace.get_tracer("checkout")

def charge_card(order_id: str, amount_cents: int):
    with tracer.start_as_current_span("charge_card") as span:
        # Bounded, describing attributes — safe cardinality
        span.set_attribute("payment.provider", "stripe")
        span.set_attribute("order.id", order_id)          # bounded per trace
        span.set_attribute("payment.amount_cents", amount_cents)
        try:
            resp = gateway.charge(order_id, amount_cents)
            if resp.declined:
                # Application-level failure the HTTP layer would call 200 OK
                span.add_event("payment.declined", {"reason": resp.decline_code})
                span.set_status(Status(StatusCode.ERROR, "card declined"))
                return resp
            span.set_attribute("payment.auth_code", resp.auth_code)
            return resp
        except GatewayTimeout as exc:
            # record_exception adds an 'exception' span event with the stack trace
            span.record_exception(exc)
            span.set_status(Status(StatusCode.ERROR, "gateway timeout"))
            raise

record_exception writes a span event named exception carrying exception.type, exception.message, and exception.stacktrace, so the failure detail lives on the span itself and surfaces in Jaeger’s timeline without a separate log lookup. set_status(ERROR) is what downstream span-metric aggregation counts as an error — set it deliberately, because auto-instrumentation will not set it for a semantically failed 200.

Propagation Mechanics: Getting trace_id Into Logs

Correlation requires the same trace_id to appear in every signal, and logs are where it is most often missing. The trace context lives in an in-process store (thread-local, or coroutine-local via async boundaries); the log formatter must read it at format time and emit it as a structured field. If the log line is written outside the active span’s scope, or on a thread that never inherited the context, the field is empty and the line becomes an orphan.

In Python, OpenTelemetry’s logging instrumentation injects otelTraceID and otelSpanID into the LogRecord; a structured formatter promotes them to first-class JSON fields:

import logging
from opentelemetry.instrumentation.logging import LoggingInstrumentor

# Injects otelTraceID / otelSpanID into every LogRecord created inside a span
LoggingInstrumentor().instrument(set_logging_format=False)

import json
class TraceJsonFormatter(logging.Formatter):
    def format(self, record):
        payload = {
            "level": record.levelname,
            "msg": record.getMessage(),
            "trace_id": getattr(record, "otelTraceID", ""),
            "span_id": getattr(record, "otelSpanID", ""),
            "service": "checkout",
        }
        return json.dumps(payload)

In Node.js the same idea, reading the active span context explicitly so the join key is never lost across an await:

// Node.js: stamp trace_id/span_id onto every structured log line
const { trace } = require('@opentelemetry/api');

function log(level, msg, extra = {}) {
  const span = trace.getActiveSpan();
  const ctx = span ? span.spanContext() : {};
  process.stdout.write(JSON.stringify({
    level, msg,
    trace_id: ctx.traceId || '',   // 32-hex; empty means orphaned log
    span_id: ctx.spanId || '',
    ...extra,
  }) + '\n');
}

With trace_id on every line, the pivot from trace to logs becomes a single query. In Loki, once traces live in Tempo and logs in Loki, you jump straight from a span to its logs:

{service="checkout"} | json | trace_id = "4bf92f3577b34da6a3ce929d0e0e4736"

That one query — filter logs by the trace_id you clicked in the trace view — is the entire payoff of trace-log correlation: no timestamp guessing, no per-service log spelunking. The deep mechanics of wiring all three stores together, including derived-field configuration, are covered in correlating logs, metrics, and traces.

Sampling Strategies Overview

Sampling is where debugging silently breaks: the trace you most need — the rare error, the p99.9 outlier — is statistically the one head-based sampling throws away, because the decision is made at ingress before anyone knows the request will fail. The full trade-off is in choosing between head-based and tail-based sampling; for debugging specifically, the summary is:

The production pattern that keeps debugging intact: run tail-based sampling in the Collector to retain every errored or slow trace, keep a low uniform head sample for baseline traffic, and — crucially — derive RED metrics from the unsampled span stream so your rates and error ratios stay accurate even though most individual traces are discarded. Metrics measure everything; traces are the retained exemplars.

Critical-Path Analysis

A trace with forty spans does not tell you where the time went — most of those spans ran in parallel or off the hot path, and optimising them changes nothing. The critical path is the specific chain of spans that gated the response: starting from the root, at each level you follow the child that finished last, because that child is what the parent waited on. Time spent on any span not on this chain is slack; time on the chain is the request’s actual latency budget.

Consider a request whose root span took 480 ms. Under it, three calls fan out in parallel: a cache lookup (12 ms), an auth check (30 ms), and a product-catalog query (410 ms) that itself waited on a slow downstream inventory span. Only the catalog → inventory chain is on the critical path. Speeding up auth by 50% saves nothing; shaving 100 ms off inventory saves the whole request 100 ms. The algorithm to extract that chain is a walk down the last-finisher at each level:

# Reconstruct the critical path from a span tree.
# spans: list of dicts with id, parent_id, start_ns, end_ns, name
def critical_path(spans):
    by_parent = {}
    for s in spans:
        by_parent.setdefault(s["parent_id"], []).append(s)

    root = next(s for s in spans if s["parent_id"] is None)
    path, node = [], root
    while node:
        path.append(node)
        children = by_parent.get(node["id"], [])
        if not children:
            break
        # The child that ends last is what its parent blocked on.
        # (Serial gaps between children are parent self-time; see note.)
        node = max(children, key=lambda c: c["end_ns"])
    return path

for span in critical_path(fetch_trace("4bf92f...")):
    dur_ms = (span["end_ns"] - span["start_ns"]) / 1e6
    print(f"{dur_ms:8.2f} ms  {span['name']}")

This last-finisher walk is the simplest useful model; a rigorous implementation also accounts for parent self-time between sequential children and for spans that overlap only partially. The practical takeaway is that critical-path thinking redirects optimisation effort from whatever looks slow in isolation to whatever is actually on the blocking chain — often a surprising downstream span. The full treatment, including handling of async fan-out and self-time attribution, is in finding latency bottlenecks with critical-path analysis.

RED / Span Metrics & Trace-Based Alerting

Traces are for one request; you cannot alert on forty thousand of them individually. The bridge is span metrics: aggregate the span stream into rate, error, and duration series, and alert on those. The OpenTelemetry Collector’s spanmetrics connector does this in the pipeline — every span becomes a calls_total counter increment and a duration histogram observation, dimensioned by a bounded set of attributes. Critically, this runs on the unsampled stream, so the metrics reflect all traffic even when trace retention is sampled.

# OTel Collector: derive RED metrics from spans, with exemplars
connectors:
  spanmetrics:
    histogram:
      explicit:
        buckets: [5ms, 10ms, 25ms, 50ms, 100ms, 250ms, 500ms, 1s, 2s]
    # ONLY bounded attributes as dimensions — never user_id or raw URL
    dimensions:
      - name: service.name
      - name: span.kind
      - name: http.route
      - name: status_code
    exemplars:
      enabled: true          # attach trace_id to bucket observations

service:
  pipelines:
    traces:
      receivers: [otlp]
      exporters: [spanmetrics]      # feed the connector
    metrics:
      receivers: [spanmetrics]
      exporters: [prometheus]

With exemplars enabled, each histogram bucket carries representative trace_ids — so a p99 spike on a Grafana panel becomes a one-click jump into an actual slow trace. From the resulting series you compute SLIs and drive burn-rate alerts. A request-error-ratio SLO in PromQL:

# Error ratio (SLI) over 5m, from span-derived RED metrics
sum(rate(calls_total{status_code="STATUS_CODE_ERROR"}[5m])) by (service_name)
/
sum(rate(calls_total[5m])) by (service_name)

# Fast-burn alert: consuming a 99.9% error budget 14.4x too fast over 1h.
# 0.001 = allowed error fraction; firing means budget gone in ~2 days.
(
  sum(rate(calls_total{status_code="STATUS_CODE_ERROR", service_name="checkout"}[1h]))
  /
  sum(rate(calls_total{service_name="checkout"}[1h]))
) > (14.4 * 0.001)

Latency SLOs come from the histogram — the fraction of requests served under the objective threshold:

# Proportion of checkout requests faster than 250ms (latency SLI)
sum(rate(duration_bucket{service_name="checkout", le="250"}[5m]))
/
sum(rate(duration_count{service_name="checkout"}[5m]))

Burn-rate alerting on span-derived RED metrics is the load-bearing pattern for production SLOs, and the multi-window multi-burn-rate details — pairing a fast 1h window with a slow 6h window to cut false pages — are covered in trace-based alerting and SLO monitoring.

Failure Modes & Edge Cases

Missing trace_id in Logs

The single most common correlation failure: logs exist, traces exist, but they will not join because the log lines never captured the trace_id. Causes are almost always context scope — a log written before the span was activated, on a thread pool worker that never inherited the context, or through a logging path the instrumentation never patched. Detect it by measuring the fraction of log lines with a non-empty trace_id field and alerting when it drops. A correlation rate below ~95% for in-request logs means an instrumentation gap, usually at an async boundary.

Cardinality Explosion in Span Metrics

Promoting an unbounded attribute — user_id, a full URL with path parameters, a raw SQL string — to a span-metric dimension detonates Prometheus: every distinct value is a new time series, and a busy service manufactures millions. The spanmetrics connector emits one series per unique dimension combination, so restrict dimensions to bounded fields (service.name, span.kind, http.route, status_code) and template variable path segments (/orders/{id}, not /orders/8842) before they reach the connector. Watch prometheus_tsdb_head_series for step-change growth after a deploy.

Sampling That Hides the Traces You Need

Head-based sampling at 1% keeps 1% of errors too — so the incident trace is 99% likely to be gone. If your debugging workflow assumes the trace exists and it does not, you have built a blind spot precisely where you need sight. The fix is architectural, not a query: retain errors and outliers with tail-based sampling, and never let the trace sample rate silently govern what your metrics report.

Exemplars Present but Unlinkable

Exemplars are emitted but clicking them goes nowhere when the metrics backend stores them but the dashboard has no configured link to the trace store, or the exemplar’s trace_id was sampled out of the trace store while surviving in the metric. Keep exemplar retention aligned with tail-sampling retention, and configure the datasource link so an exemplar resolves to a trace that still exists.

Clock Skew Distorting the Critical Path

Critical-path analysis reads span start/end timestamps; if two hosts disagree on wall-clock time by more than a few milliseconds, a child span can appear to end after its parent or overlap incorrectly, corrupting the last-finisher walk. Keep NTP tight across the fleet and treat sub-millisecond ordering with suspicion rather than as ground truth.

Security Considerations

The correlation workflow multiplies where sensitive data can land: an attribute or span event that carries PII is now potentially copied into logs (via the trace_id-stamped line), aggregated into metrics, and retained in trace storage. The security boundaries in distributed tracing guide covers the full threat model; the debugging-specific hazards:

• PII in span events. record_exception captures a stack trace, and exception messages routinely embed emails, tokens, or account numbers (“payment failed for user [email protected]”). Scrub exception messages and sanitise event attributes in a Collector processor before export.
• PII promoted to metric dimensions. Beyond the cardinality damage, a user.email dimension writes personal data into a metrics store that usually has weaker access controls and longer retention than the trace store. Enforce a dimension allowlist.
• trace_id in client-visible logs. If trace_id is echoed to browser consoles or third-party log shippers, it becomes a correlation handle an attacker can use to pull a request’s full telemetry. Treat it as internal metadata; do not expose it across a trust boundary.
• Full-payload span attributes. Recording entire request/response bodies as attributes for “easier debugging” is the fastest way to leak secrets into storage. Record shape and identifiers, not payloads.

Production Readiness Checklist

• Span status set to ERROR on semantic failures, not only on thrown exceptions or non-2xx codes
• Exceptions recorded via record_exception so stack traces travel on the span
• trace_id and span_id injected into every structured log line, verified across async boundaries
• Log-to-trace correlation rate measured and alerted (target > 95% for in-request logs)
• Span-derived RED metrics generated from the unsampled stream via the spanmetrics connector
• Span-metric dimensions restricted to bounded attributes; variable URL segments templated
• Histogram exemplars enabled and dashboard datasource links resolve to live traces
• Tail-based sampling retains 100% of errored and high-latency traces
• SLIs (error ratio, latency proportion) defined in queries and version-controlled
• Multi-window burn-rate SLO alerts wired to on-call, not raw threshold alerts
• Exception messages and span-event attributes scrubbed of PII before export
• Critical-path view available in the trace UI or via a saved analysis query

Troubleshooting FAQ

Why can I see a slow trace in Jaeger but find no matching log lines?

Almost always the logging pipeline never captured the trace_id, so there is no join key. The application context and the log formatter ran on different threads or coroutines, or the log line was written outside the span’s active scope. Add a logging instrumentation layer that reads the current span context at format time and emits trace_id and span_id as structured fields, then re-run the Loki/backend query filtered on that ID.

My span metrics blew up Prometheus cardinality. What went wrong?

A high-cardinality attribute such as user_id, a full URL path, or a raw SQL statement was promoted to a metric dimension, and every distinct value became a new time series. Restrict the spanmetrics dimensions to bounded fields like service.name, span.kind, http.route, and status_code, template variable path segments, and drop unbounded attributes before the connector aggregates them.

Sampling dropped the exact trace I needed to debug an incident. How do I stop that?

Head-based sampling decides at ingress before it knows a trace will fail, so rare errors are frequently discarded. Move error and high-latency retention to tail-based sampling in the Collector, which sees the whole trace before deciding, and keep span-derived RED metrics unsampled so aggregate rates stay accurate even when individual traces are dropped.

How do exemplars connect a metrics dashboard to a single trace?

An exemplar is a trace_id attached to a specific histogram bucket observation. When a latency panel renders the p99 bucket, the exemplar gives the dashboard a concrete trace_id to link to, so one click on the spike opens a representative slow trace in Jaeger or Tempo instead of leaving you to search blindly by timestamp.

How do I confirm my SLO alert reflects reality and not a sampling artifact?

Compute the SLI from span-derived metrics generated on the unsampled stream, and cross-check the alert’s error ratio against the raw request count from your ingress or load balancer over the same window. If they diverge, a sampled metric is feeding the alert — repoint it at the unsampled calls_total series.

Related

• Correlating Logs, Metrics & Traces — wiring the three stores together on a shared trace_id, with derived-field and datasource-link configuration.
• Finding Latency Bottlenecks with Critical-Path Analysis — the full algorithm for async fan-out, self-time attribution, and reading the blocking chain.
• Trace-Based Alerting & SLO Monitoring — multi-window multi-burn-rate alerts driven by span-derived RED metrics.
• SDK Implementation & Context Propagation — how the trace_id and context that make correlation possible are produced and propagated.
• Distributed Tracing Fundamentals & Architecture — traces, spans, storage backends, and the sampling models this reference consumes.

↑ Back to Distributed Tracing Fundamentals & Architecture