Adding Trace IDs to Python Log Records

Correlating a log line with the distributed trace that produced it means injecting the active trace_id and span_id into every LogRecord, then emitting those identifiers as discrete fields so a backend can join logs to spans. This page is for backend engineers and SREs who already emit JSON logs and already run OpenTelemetry, but still cannot answer "show me every log line from this one slow request". It is part of the Python Logging Fundamentals and Structured Data guide and extends the formatter configuration material with a single focused, production-ready correlation recipe.

Prerequisites

Install the OpenTelemetry API and SDK with pinned version ranges. The API exposes the current span context and is the only import the injection code needs; the SDK plus at least one instrumentation library produce the real spans without which every identifier reads as zeros.

pip install "opentelemetry-api>=1.30.0,<2.0.0" \
            "opentelemetry-sdk>=1.30.0,<2.0.0"

No environment variable is strictly required by the correlation logic itself, but a tracer provider must be configured somewhere in the process, and naming the service keeps the correlated records attributable once several services write into the same index.

export OTEL_SERVICE_NAME="checkout"
export OTEL_TRACES_EXPORTER="otlp"
export OTEL_EXPORTER_OTLP_ENDPOINT="http://collector:4317"

If you have not set a provider up yet, the distributed tracing and OpenTelemetry in Python guide covers provider lifecycle and the OpenTelemetry SDK setup page covers processor and exporter wiring. Context propagation and baggage explains how a trace_id travels between processes, which is what makes the same identifier appear in the logs of both the caller and the callee.

Implementation

The correlation pipeline has three responsibilities: read the active span context, attach its identifiers to each LogRecord, and serialize those identifiers as discrete JSON fields. Everything else — handlers, levels, transports — stays exactly as it is.

Step 1 — Read the active span context. Call opentelemetry.trace.get_current_span() and inspect its get_span_context(). The returned SpanContext carries integer trace_id and span_id values plus an is_valid flag that is False when no span is recording. The identifiers are plain Python integers, not strings, so a 128-bit trace ID can be a very large number; you must format the integers as zero-padded lowercase hex to match the W3C Trace Context representation, using width 32 for the trace ID and 16 for the span ID. Reading the context this way is cheap and lock-free, because the active span lives in a context variable rather than shared mutable state — the same mechanism described in context variables and thread safety — which is why injection on the hot path adds negligible overhead per record.

Step 2 — Stamp the identifiers onto every record with a LogRecordFactory. The factory wraps the default record constructor and is invoked for every record the logging system creates, so you avoid attaching a filter to each handler. This is the most robust injection point available in the standard library.

import logging
from opentelemetry import trace

# Capture the original factory so we can delegate to it.
_old_factory = logging.getLogRecordFactory()


def _record_factory(*args, **kwargs):
    record = _old_factory(*args, **kwargs)
    span = trace.get_current_span()
    ctx = span.get_span_context()
    if ctx.is_valid:
        # Zero-padded lowercase hex matching W3C Trace Context.
        record.trace_id = format(ctx.trace_id, "032x")
        record.span_id = format(ctx.span_id, "016x")
        # trace_flags is an int bitmask; 01 means sampled.
        record.trace_flags = format(ctx.trace_flags, "02x")
    else:
        # Keep the keys present so downstream schemas stay stable.
        record.trace_id = "0" * 32
        record.span_id = "0" * 16
        record.trace_flags = "00"
    return record


logging.setLogRecordFactory(_record_factory)

The factory approach has one important property: it runs for records created anywhere in the process, including records emitted by third-party libraries you do not control. That is usually what you want, because a database driver or web framework that logs a slow query should carry the same trace_id as your own handlers. The cost is global mutation of process state, so install the factory exactly once during startup, before any framework has begun serving, and keep a reference to the previous factory as shown above so the chain stays intact if another component installed its own factory first.

Step 3 — Emit the fields from a JSON formatter. Because the attributes now exist on every record, the formatter reads them with plain attribute access. Use getattr defaults so the formatter still works if the factory was never installed — during a unit test, for example, or in a management command that imports the formatter without running startup. Keeping the field present even when empty matters for downstream schemas: a pipeline that indexes on trace_id will reject or mis-map records where the key is sometimes absent, so an explicit zero placeholder is safer than omitting it. The same serialization discipline is covered end to end in structured logging with the Python standard library.

import json
import logging


class TraceJSONFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload = {
            "timestamp": self.formatTime(record, "%Y-%m-%dT%H:%M:%S%z"),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            # getattr defaults keep the formatter usable without the factory.
            "trace_id": getattr(record, "trace_id", "0" * 32),
            "span_id": getattr(record, "span_id", "0" * 16),
            "trace_flags": getattr(record, "trace_flags", "00"),
        }
        if record.exc_info:
            # One escaped string, so line-delimited parsers stay intact.
            payload["exception"] = self.formatException(record.exc_info)
        return json.dumps(payload, separators=(",", ":"))

Step 4 — Wire it together and emit inside a span. Attach the formatter to a stream handler and log from within an active span so the identifiers are populated. In a real service this wiring belongs in a dictConfig dictionary rather than imperative calls; see configuring logging with dictConfig for the declarative form, which references TraceJSONFormatter by its dotted path under formatters.

import logging
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider

trace.set_tracer_provider(TracerProvider())
tracer = trace.get_tracer("checkout")

handler = logging.StreamHandler()
handler.setFormatter(TraceJSONFormatter())
log = logging.getLogger("checkout")
log.setLevel(logging.INFO)
log.addHandler(handler)
log.propagate = False  # avoid a duplicate line from the root handler

with tracer.start_as_current_span("process_payment"):
    log.info("payment authorized", extra={"order_id": "A-9182"})

Expected Output:

{"timestamp":"2026-06-19T10:14:02+0000","level":"INFO","logger":"checkout","message":"payment authorized","trace_id":"7651916a3df52b3f86d0c2a1bb9f4e10","span_id":"3a1f9c5d2e7b0846","trace_flags":"01"}

Alternative injection points

The record factory is the default recommendation, but two other seams exist and each is right in a specific situation.

A logging.Filter mutates the record in place and returns True so the record is still emitted. Use it when another library already owns the global factory, or when only some handlers should carry the identifiers — an audit handler that must not leak internal identifiers, for instance. The trade-off is coverage: a filter attached to a handler runs only for records that actually reach that handler, so records dropped by a level check or emitted through a logger you forgot to wire arrive without the fields.

import logging
from opentelemetry import trace


class TraceContextFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        ctx = trace.get_current_span().get_span_context()
        # Filters must return True or the record is dropped entirely.
        record.trace_id = format(ctx.trace_id, "032x") if ctx.is_valid else "0" * 32
        record.span_id = format(ctx.span_id, "016x") if ctx.is_valid else "0" * 16
        return True


handler.addFilter(TraceContextFilter())

A structlog processor is the right seam when your service builds events through structlog rather than the standard library. The identifiers are added to the event dictionary by a processor placed before the renderer, which is the structlog analogue of the factory; binding context variables in structlog covers where in the chain such a processor belongs. If both stacks run in one process — structlog for application events, stdlib for library output — install the factory and the processor so both paths carry the same identifiers.

Configuration options

Two options deserve emphasis. Emitting trace_flags is optional but cheap, and it lets you explain a missing trace: a line with trace_flags of 00 was produced inside a span the sampler discarded, so the log exists while the trace does not — see sampling strategies for distributed tracing for how that decision is made. And the field names matter more than they look: backends that offer a one-click jump from a log line to its trace usually key on exactly trace_id and span_id, so renaming them costs you the feature that motivated the work.

Verification

Run the wired example and confirm three things in the emitted line: trace_id is 32 hex characters, span_id is 16 hex characters, and trace_flags is 01 when the span is sampled. Then prove the factory degrades correctly by logging once outside any span and asserting the zero placeholders appear.

log.info("startup complete")  # no active span

Expected Output:

{"timestamp":"2026-07-25T10:14:00+0000","level":"INFO","logger":"checkout","message":"startup complete","trace_id":"00000000000000000000000000000000","span_id":"0000000000000000","trace_flags":"00"}

A unit test pins the behaviour so a future refactor cannot quietly remove the factory. Constructing a record through the installed factory exercises the real injection path without needing a live span.

import logging

record = logging.getLogRecordFactory()("t", logging.INFO, __file__, 1, "x", None, None)
assert len(record.trace_id) == 32
assert len(record.span_id) == 16
assert record.trace_flags == "00"  # no span active inside the test

Once the fields reach your backend, correlation becomes a query rather than a guess. In a trace-aware log store you filter by the trace_id shown on a slow or failed span and immediately see every line that request produced across every service, provided each service injects the identifiers and shares context. The reverse jump also works: copy the trace_id out of a log line into the trace view and open the full span tree. If only one side of a call shows the identifier, the problem is propagation rather than logging, and the fix belongs in context propagation and baggage — for message-driven services, specifically propagating trace context across Celery tasks.

Common mistakes

• Error signature: every field is present but trace_id is 00000000000000000000000000000000 for records emitted from a worker thread, while request-thread records are correct. Root cause: the OpenTelemetry context lives in a context variable, and a thread started with threading.Thread or a callback handed to a raw ThreadPoolExecutor does not inherit it, so get_current_span() returns the non-recording default span. Remediation: capture the context with context.get_current() before dispatching and re-attach it inside the worker, or hand the executor a contextvars.copy_context()-wrapped callable — the boundary rules are set out in context variables and thread safety and applied to request identifiers in using contextvars for request tracing.

• Error signature: the backend shows logs and traces side by side but the "view trace" link never resolves, and the log field reads 156802340019... or an uppercase hex string. Root cause: the integer SpanContext.trace_id was serialized directly, or formatted with hex() or "032X", none of which match the lowercase zero-padded 32-character form the backend stored. Remediation: always render with format(ctx.trace_id, "032x") and format(ctx.span_id, "016x"), and add a length assertion to the test above so a regression fails in CI rather than in an incident.

• Error signature: identifiers are correct for most lines but occasionally show a stale trace from a previous request, most visibly under load. Root cause: both a record factory and a handler filter set the same attributes, and the filter runs later against a context that has already been detached — the last writer wins and overwrites a valid identifier. Remediation: choose one injection point and delete the other, then grep the codebase for setLogRecordFactory and addFilter at startup to confirm only one path assigns trace_id.

• Error signature: correlated fields are perfect in development but the service's P99 latency rises after enabling JSON logging in production. Root cause: the injection is not the cost — the synchronous handler write is, and it now runs on the request thread for every line the factory has made worth keeping. Remediation: move emission off the hot path with the queue-based pattern in non-blocking logging with QueueHandler; the factory has already stamped the identifiers before the record is enqueued, so correlation survives the hand-off to the listener thread.

Related

• Formatter configuration — the parent guide covering serialization, timestamps, and exception rendering.
• Structured logging with the Python standard library — the zero-dependency JSON formatter these fields are added to.
• Configuring logging with dictConfig — the declarative way to attach the formatter and filter in a real service.
• Context propagation and baggage — how the same trace ID reaches the logs of the next service.
• Non-blocking logging with QueueHandler — keeping correlated JSON output off the request thread.

Frequently Asked Questions