End-to-end correlation — request IDs across signals · Docker & Containers

A request that crosses five containers produces five log streams, one trace and a great many metric samples. Without a shared identifier the only thing joining them is a timestamp, and joining by timestamp on a busy host means “these two things happened in the same 40 milliseconds as three thousand other things”.

Correlation is the shared identifier. It is a small amount of work, almost all of it done once, and it has to be in place before the incident — retrofitting it during one is not possible.

Two identifiers, and they are not interchangeable

	Trace ID	Request ID
Format	32 hex characters (16 bytes)	anything; commonly a UUID
Created by	the instrumentation SDK at the first instrumented hop	the outermost proxy
Propagated by	the `traceparent` header, automatically	an `X-Request-ID` header, by your code
Exists when tracing is off	no	yes
Exists for a request the proxy rejected	no	yes
Good for	causation, timing, the span tree	support tickets, sharing with a human

Most systems need both, and the cheapest way to have both is to make them the same value where possible: mint the request ID at the proxy, and let the trace ID be derived from it or logged alongside it. What you must not do is have two independent IDs that nobody ever writes in the same log line, because then correlating them is its own project.

The row that decides it is “a request the proxy rejected”. A request that was rate-limited, failed TLS, or hit a 413 never reached an instrumented application and therefore has no trace — but it is exactly the request a user is complaining about. Only an ID minted at the edge covers it.

Minting the ID at the true edge

The right place is the outermost thing that sees the request. Do it further in and every hop before that point is invisible.

Two of the four proxies in this course can generate an identifier themselves. Two cannot, and it is worth knowing which is which before you plan around it.

Configuration changenginx — $request_id— Built in since nginx 1.11.0: 16 random bytes in hexadecimal, per request.

# Accept a caller-supplied ID from a trusted upstream, otherwise mint one.
map $http_x_request_id $correlation_id {
  default   $http_x_request_id;
  ""        $request_id;
}

log_format correlated escape=json
  '{"time":"$time_iso8601","request_id":"$correlation_id",'
  '"client":"$remote_addr","method":"$request_method","uri":"$request_uri",'
  '"status":$status,"upstream_time":"$upstream_response_time",'
  '"request_time":$request_time}';

server {
  access_log /var/log/nginx/access.log correlated;

  location / {
      proxy_set_header X-Request-ID $correlation_id;
      proxy_pass http://app_backend;

      # Return it to the client so a user can quote it in a ticket.
      add_header X-Request-ID $correlation_id always;
  }
}

Configuration changeHAProxy — unique-id-format— `unique-id-header` adds the generated value to the request sent to the server.

frontend https_in
  bind *:443 ssl crt /etc/haproxy/certs/app.example.com.pem

  # The uuid() sample fetch produces a fresh UUID per request.
  unique-id-format %[uuid()]
  unique-id-header X-Request-ID

  # Echo it back so the client can quote it.
  http-response set-header X-Request-ID %[unique-id]

  # And put it in the log line.
  log-format "%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %hrl %hsl %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %ID"

  default_backend web_servers

unique-id-format also accepts HAProxy’s older composite form — %{+X}o\ %ci:%cp_%fi:%fp_%Ts_%rt:%pid, which encodes the connection four-tuple, a timestamp and the process ID — which is harder to read but carries information a UUID does not.

Traefik and Caddy do not ship a request-ID generator

This is worth stating plainly because it is not obvious and it changes the design.

Traefik’s built-in middleware list — AddPrefix, BasicAuth, Buffering, Chain, CircuitBreaker, Compress, ContentType, DigestAuth, Errors, ForwardAuth, Headers, IPAllowList, InFlightReq, PassTLSClientCert, RateLimit, RedirectScheme, RedirectRegex, ReplacePath, Retry, StripPrefix and friends — contains no request-ID middleware. There are community plugins; there is nothing in the core distribution.

Caddy’s documented placeholder set does not include a per-request UUID either. The shorthands are things like {remote_host}, {uri}, {method}, {host} and {client_ip} — all properties of the request, none of them freshly generated.

If your edge is one of those two, the honest options are: use the OpenTelemetry trace ID as your correlation ID and accept that proxy-rejected requests have none; put nginx or HAProxy in front; or generate at the application and accept that the edge hop is invisible. Pick knowingly rather than discovering it mid-incident.

Threading it through the application

Two things must happen in every service: read the incoming ID or mint one, and attach it to every log line the request produces.

import logging
import uuid
from contextvars import ContextVar

from flask import Flask, g, request

app = Flask(__name__)
_request_id: ContextVar[str] = ContextVar("request_id", default="-")


@app.before_request
def assign_request_id():
    # Trust the header only from the edge proxy; see the client-IP lesson.
    incoming = request.headers.get("X-Request-ID")
    g.request_id = incoming or str(uuid.uuid4())
    _request_id.set(g.request_id)


@app.after_request
def echo_request_id(response):
    response.headers["X-Request-ID"] = g.request_id
    return response


class CorrelationFilter(logging.Filter):
    """Puts the id on every record, including ones from libraries."""

    def filter(self, record):
        record.request_id = _request_id.get()
        return True

The ContextVar rather than g is deliberate. Flask’s g is not visible to logging calls made from a background thread or an async task, so library log lines would silently carry -. A context variable propagates where the runtime propagates context, which is the same boundary the tracing SDK uses.

And when an outbound call is made, forward it:

import requests


def call_inventory(item_id):
    return requests.get(
        f"http://inventory:9090/items/{item_id}",
        headers={"X-Request-ID": _request_id.get()},
        timeout=(2.0, 5.0),
    )

That one line is the container boundary. Omit it in one service and the chain breaks there, silently, and the logs of every service downstream of it become unfindable.

How trace IDs get into log lines without you passing them

OpenTelemetry’s logging instrumentation does the same job automatically, and understanding the mechanism explains when it fails.

The SDK keeps the active span in the runtime’s context — a thread-local, a ContextVar, an async-local, depending on the language. The logging bridge installs a hook in the logging framework that, on every record, reads the currently active span and copies its trace_id and span_id onto the record. No argument is passed anywhere; the log call and the span simply share a context.

Two consequences follow directly:

A log line emitted where no span is active gets zeroes. Startup logs, background timers and anything running outside a request produce trace_id=00000000000000000000000000000000, which is the invalid all-zero value W3C defines. That is correct, not broken.
A log line emitted from a thread the context did not propagate to gets zeroes too — and this one is a bug, in the same place as the broken traces from the previous lesson. Handing work to a raw thread pool loses the context for both signals at once.

Because the trace ID is on the record rather than in the message, a JSON formatter puts it in its own field, which is what makes the log backend able to index it. A formatter that renders it into the message string works for grep and not for anything else.

Configuration changestructured output— JSON to stdout, one object per line — the container logging contract.

import logging
import sys

from pythonjsonlogger import json as jsonlogger

handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(
  jsonlogger.JsonFormatter(
      "%(asctime)s %(levelname)s %(name)s %(message)s "
      "%(request_id)s %(otelTraceID)s %(otelSpanID)s",
      rename_fields={"asctime": "time", "levelname": "level"},
  )
)
handler.addFilter(CorrelationFilter())

root = logging.getLogger()
root.handlers = [handler]
root.setLevel(logging.INFO)

Read-only / Safewhat a correlated log line looks like— One object per line on stdout, with both identifiers as fields.

$ docker compose logs --no-log-prefix --since 2m api | head -2

{"time":"2026-08-12T02:41:07.412Z","level":"INFO","name":"myapp.orders","message":"order.processed","request_id":"9f2c1e44-73a1-4b8e-9d0a-6c1f2e5b7a30","otelTraceID":"4bf92f3577b34da6a3ce929d0e0e4736","otelSpanID":"00f067aa0ba902b7","order_id":12345}
{"time":"2026-08-12T02:41:07.518Z","level":"ERROR","name":"myapp.inventory","message":"inventory.unavailable","request_id":"9f2c1e44-73a1-4b8e-9d0a-6c1f2e5b7a30","otelTraceID":"4bf92f3577b34da6a3ce929d0e0e4736","otelSpanID":"9d7f21ba03c4e618","sku":"AB-1174"}

Illustrative output

The structured form is not a style preference. docker logs gives you one interleaved stream per container; the only thing that makes those streams joinable across five containers is a field a log backend can index. The stdout/stderr contract and the collection pipeline are covered in the logging part of this course — correlation is what makes that pipeline worth having.

Never put a request ID in a metric label

One label, millions of time series

Prometheus creates a new time series for every unique combination of label values. A request ID is unique per request by definition, so http_requests_total{request_id="..."} creates one series per request — for the lifetime of the retention window.

At 100 requests per second that is 8.6 million new series a day. The Prometheus documentation’s guidance is to keep a metric’s cardinality below 10, to investigate alternatives above 100, and it explicitly describes a “double digit number of millions” of series as “too much for the current implementation of Prometheus”.

What actually happens: Prometheus’s memory climbs steadily, ingestion slows, queries that touch that metric time out, and eventually the process is OOM-killed by its container limit. Restarting it replays the WAL and it is killed again. Recovery means deleting the offending series or the whole TSDB.

The same rule applies to any per-request or per-user value: user ID, email address, session ID, full URL with a query string, or a trace ID. All of them are unbounded.

The division of labour that works:

Question	Signal
How many requests failed?	metrics — aggregate, cheap, alertable
Which request failed, and why?	logs — one entry per event, high cardinality is free
Where did that request spend its time?	traces — one tree per sampled request

The bridge between the first and the others is an exemplar: a metric sample may carry a small annotation pointing at one trace ID that contributed to it. It does not become a label, so it does not multiply series, and it gives a histogram bucket a clickable example.

Prometheus stores exemplars behind --enable-feature=exemplar-storage, with the buffer size configured by the storage/exemplars block. They are introduced by the OpenMetrics exposition format, so the client library and the scrape must both support it.

The diagnostic flow

sequenceDiagram
  participant Alert
  participant Metrics
  participant Trace
  participant Logs
  Alert->>Metrics: p99 latency > 2s on /orders
  Metrics-->>Alert: exemplar attached to the slow bucket
  Alert->>Trace: open that trace ID
  Trace-->>Alert: 1.8s in the inventory CLIENT span
  Alert->>Logs: filter otelTraceID = that value
  Logs-->>Alert: inventory logged pool timeout, 4 retries

Each arrow is a pivot that only works because both ends carry the same identifier. Break any one of them and the step becomes “search by timestamp and hope”, which on a busy host is not a step at all.

Working it in the other direction is just as common and is the one users initiate: a customer quotes the X-Request-ID from an error page, you search logs for that value, find the trace ID on the same line, and open the trace. That flow is the reason the proxy echoes the header back to the client.

Verification that can fail

Read-only / Safefollow one request through every container— Send a request with a known ID and confirm each hop logged it.

set -euo pipefail
HOST=app.example.com
RID="verify-$(date +%s)-$$"

# Send one request carrying an ID we chose, so it is easy to find.
curl -sS -o /dev/null -D - -H "X-Request-ID: $RID" "https://$HOST/orders/42" | grep -i '^x-request-id' || echo 'PROXY DID NOT ECHO THE HEADER'

sleep 3

# Every service that handled it should have logged it at least once.
for svc in proxy api inventory; do
n=$(docker compose logs --since 2m --no-log-prefix "$svc" 2>/dev/null | grep -c "$RID" || true)
printf '%-12s %s line(s)\n' "$svc" "$n"
done

Read the output as a map of where the chain breaks:

A service with 0 lines did not receive the header, or received it and did not log it. Either way the chain ends there and every service downstream is unfindable.
The proxy did not echo the header means a user cannot quote an ID from an error page, so the support-ticket direction of the flow does not work.
Every service has at least one line is the passing case, and it is the only evidence that correlation works. A configuration that looks correct is not evidence.

Run this after every change to the edge configuration. It takes five seconds and it is the only check that covers the whole path.

What if a downstream service overwrites the incoming request ID instead of reusing it?

You get two half-chains and no error anywhere, which makes this one of the more expensive misconfigurations in the observability stack.

The service reads no incoming header — or reads it and ignores it — mints a fresh UUID, and logs and forwards that. Everything upstream is under one ID, everything downstream under another, and nothing in either set of logs connects them. Searching for the ID a user quoted finds the proxy and the first service and stops exactly where the problem is.

Three specific ways it happens on a Docker host:

The or is the wrong way round. str(uuid.uuid4()) or request.headers.get("X-Request-ID") always takes the first branch, because a UUID string is truthy. It looks almost identical to the correct version.
An inner proxy mints unconditionally. nginx’s $request_id is fresh per request; used directly rather than through a map that prefers an incoming value, an inner nginx replaces the edge’s ID. The map block earlier in this lesson is what prevents that.
A retry mints a new one. If the ID is generated per attempt rather than per request, a proxy-level retry produces two IDs for one user action and the two halves of the story are again separate.

The rule that avoids all three: generate at the outermost edge only, and every hop after that reads and forwards. Then invert the trust question — an inner service should accept the header because it is on an internal network and the edge overwrote whatever the client sent. That overwrite at the edge is what makes trusting it inside safe, and it is the same trust-boundary argument as X-Forwarded-For.

The undo is straightforward: fix the reading logic, redeploy, and run the verification above. Nothing persists — correlation is entirely a property of requests in flight.

Knowledge check

Where next

With a trace, a correlated log line and a metric, the next question is which of the three to reach for. The next lesson is the honest version of that comparison, including what each one costs to store.