Skip to main content
RunBook Academy

ObservabilityLIII · Log / Trace CorrelationLogTraceCorrelation

Log / Trace Link

Foundation⏱ ~18 minbash

What you'll learn

  • Stamp a 32-char trace_id on every log line emitted inside a request span
  • Wire an OpenTelemetry-aware log handler that reads the current SpanContext and writes the field
  • Distinguish a structured trace_id field from a free-text regex match in unstructured lines
  • Verify that Loki receives the field and that Tempo resolves it to the same span tree
  • Recognise the four common ways the field disappears and re-stamp it without redeploying the world

Prerequisites

Verified against Prometheus 2.55.x · Alertmanager 0.28.x · node_exporter 1.8.x · blackbox_exporter 0.26.x · Grafana 11.x · Loki 3.x · Tempo current · OpenTelemetry Collector 0.110.x · Grafana Alloy current · Docker Engine 28.x · Ubuntu 24.04 LTS · Debian 12 (Bookworm) · RHEL / Rocky / AlmaLinux 9.x · 2026-08-13

Not yet marked complete on this device.

A payment fails at 03:14. The on-call engineer opens Loki and runs {service="checkout"} |= "level=error". Forty lines come back. Each one names the symptom, none of them names the span. The engineer copies the user’s request ID by hand, opens Tempo, types it into the search box, and stares at a blank result. The request ID is not the trace ID. Tempo never saw it. The correlation is missing because no one ever stamped the trace ID on the log line.

The link from log to trace is not the database join or the search index. It is a single structured field on every log line that the Grafana pivot turns into a one-click jump. The field is trace_id. The value is the 32-character hex string from W3C Trace Context. The cost of including it is one field per line. The cost of not including it is the forty-minute hunt above, every incident, forever.

What it is

A log/trace link is a structured trace_id field on every log record emitted inside a request scope. The field is set by the application’s logging library, not scraped from the message text. The value is the same trace_id (32 lowercase hex characters) the OpenTelemetry SDK attached to the current span. With the field present, Grafana 11.x renders a clickable link on every Loki line that targets a Tempo trace by its identifier.

The shape matters. The link works because trace_id is a top-level structured attribute — a key/value pair the log encoder can extract without regex. A free-text substring like trace_id=abc123... inside an unstructured message also “contains” a trace ID, but Loki has to regex-match the substring on every rendered line, the match is fragile across log-format changes, and the match is impossible to index. Structured fields are cheap to read and cheap to filter; free-text matches are expensive and unreliable.

Why a sysadmin cares

Three production failures depend on this field being correct:

  • Trace-to-logs pivot. Grafana’s built-in pivot on the Tempo data source queries Loki for {...} | trace_id="<current>". If trace_id is not a structured field on the Loki line, the query returns zero rows and the button is silently dead.
  • Cross-tool searching. Ad-hoc LogQL queries like | json | trace_id="4bf92f3577b34da6a3ce929d0e0e4736" rely on the field being a parsed attribute. A regex line-filter |="trace_id=4bf92f..." works but scans every byte of every line; parsed structured metadata is order-of-magnitude cheaper.
  • Incident timeline assembly. A trace ID found in a Slack thread, a customer support ticket, or a post-mortem only becomes useful when the team can paste it back into Grafana and have it resolve. The field on the log line is what makes the round trip closed.

The trade-off is small. A trace_id field adds roughly 40 bytes per log line (key + value + JSON overhead). On a fleet that ships 100 GB of logs per day, that is 4 GB. The investigation savings dwarf the storage cost.

How it works

The OpenTelemetry SDK holds the active span in a process-local context. Every log handler that participates in the SDK’s context API reads the same context, pulls the trace_id from the SpanContext, and writes it as a structured attribute on the log record. The path:

incoming request
   |
   |  W3C traceparent header
   v
+--------------------------+
| OpenTelemetry SDK        |
|  span = ServerSpan(...)  |
|  context.TraceID set     |
+--------------------------+
   |
   |  current context (Go: context.Context, Python: token, ...)
   v
+--------------------------+
| Log handler              |
|  reads context           |
|  adds trace_id attribute |
+--------------------------+
   |
   |  {"ts":"...","level":"info","msg":"...","trace_id":"4bf92f...","span_id":"..."}
   v
stdout / file / journald
   |
   |  Alloy / Promtail
   v
+--------------------------+
| Loki                     |
|  log line + structured   |
|  metadata trace_id=...   |
+--------------------------+
   |
   |  Grafana data-link pivot
   v
+--------------------------+
| Tempo                    |
|  /api/traces/<trace_id>  |
+--------------------------+

Two operational observations:

  1. The trace_id is written once, by the logging library, inside the request scope. It is never derived from the message text by the log shipper. The shaping of the field is the application’s responsibility — not Alloy’s, not Promtail’s, not Loki’s.
  2. The structured attribute travels through Loki’s structured metadata path in current best practice. In Loki 3.x the line itself is stored as a single opaque blob; every key/value the application wants to be queryable belongs in structured metadata, not as a stream label. Stream labels cost cardinality; structured metadata costs bytes per query result.

How to configure it

The application side — Go, with slog and the OpenTelemetry SDK:

import (
    "context"
    "log/slog"
    "os"

    "go.opentelemetry.io/otel"
    "go.opentelemetry.io/otel/trace"
)

type traceHandler struct{ slog.Handler }

func (h *traceHandler) Handle(ctx context.Context, r slog.Record) error {
    sc := trace.SpanContextFromContext(ctx)
    if sc.IsValid() {
        r.AddAttrs(
            slog.String("trace_id", sc.TraceID().String()),
            slog.String("span_id",  sc.SpanID().String()),
        )
    }
    return h.Handler.Handle(ctx, r)
}

func newLogger() *slog.Logger {
    h := slog.NewJSONHandler(os.Stdout, nil)
    return slog.New(&traceHandler{Handler: h})
}

The Python equivalent, with the standard logging package and the OpenTelemetry SDK’s bridge:

import logging
from opentelemetry import trace

class TraceIdFilter(logging.Filter):
    def filter(self, record):
        span = trace.get_current_span()
        ctx = span.get_span_context() if span else None
        if ctx and ctx.is_valid:
            record.trace_id = format(ctx.trace_id, "032x")
            record.span_id  = format(ctx.span_id,  "016x")
        else:
            record.trace_id = None
            record.span_id  = None
        return True

handler = logging.StreamHandler()
handler.addFilter(TraceIdFilter())
fmt = logging.Formatter(
    '{"ts":"%(asctime)s","level":"%(levelname)s",'
    '"trace_id":"%(trace_id)s","span_id":"%(span_id)s",'
    '"msg":%(message)r}'
)
handler.setFormatter(fmt)
logging.getLogger().addHandler(handler)

Java, with the OpenTelemetry logback appender:

<!-- logback.xml -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
  <encoder>
    <pattern>%d{ISO8601} %-5level [%thread] trace_id=%X{trace_id:-} span_id=%X{span_id:-} %logger{36} - %msg%n</pattern>
  </encoder>
</appender>

The MDC fields trace_id and span_id are populated by the OpenTelemetry logback instrumentation, which ships in the opentelemetry-logback-appender-1.0 module.

The Alloy / Promtail side — no regex, no derivation. The trace ID is a structured attribute on the line and travels through the pipeline as-is:

// /etc/alloy/config.alloy
loki.source.journal "checkout" {
  forward_to = [loki.process.checkout.receiver]
}

loki.process "checkout" {
  // Promote the application's structured fields to Loki
  // structured metadata. The trace_id joins on the Tempo side
  // without needing a re-extraction regex here.
  stage.structured_metadata {
    values = {
      "trace_id" = "trace_id",
      "span_id"  = "span_id",
    }
  }

  forward_to = [loki.write.prod.receiver]
}

loki.write "prod" {
  endpoint {
    url = "http://loki-prod-eu.internal:3100/loki/api/v1/push"
  }
}

The Loki side — a stream label set to the high-level identifier only, never to the trace ID itself:

# Stream labels (applied by Alloy or the application's tags)
# job=checkout
# service_name=checkout-api
# deployment_environment=prod-eu
#
# Structured metadata on the line:
# trace_id=4bf92f3577b34da6a3ce929d0e0e4736
# span_id=00f067aa0ba902b7

The two labels above are the high-cardinality-shaped choices the team agreed to bound; trace_id is in structured metadata because it changes per request and would explode the index if made a label. This is the discipline other lessons in this module assume.

How to validate it

# READ-ONLY: confirm the application emitted the field on stdout.
docker logs checkout-api-7f8c --since 5m | head -5
# {"ts":"2026-08-13T14:22:11Z","level":"info",
#  "trace_id":"4bf92f3577b34da6a3ce929d0e0e4736",
#  "span_id":"00f067aa0ba902b7","msg":"req started"}
# {"ts":"2026-08-13T14:22:11Z","level":"info",
#  "trace_id":"4bf92f3577b34da6a3ce929d0e0e4736",
#  "span_id":"1a2b3c4d5e6f7081","msg":"payment dispatched"}
#
# (Both lines share trace_id; span_id differs because they are
# emitted from different spans inside the same trace.)

# READ-ONLY: confirm Loki received the field as structured metadata.
logcli query --since 5m '{service_name="checkout-api"}' | head -20
# 2026-08-13T14:22:11.000Z {service_name="checkout-api"}
#   trace_id="4bf92f3577b34da6a3ce929d0e0e4736"
#   span_id="00f067aa0ba902b7"
#   request started path=/checkout

# READ-ONLY: filter Loki by trace_id (the shape that powers the pivot).
TRACE=4bf92f3577b34da6a3ce929d0e0e4736
logcli query --since 1h "{service_name=\"checkout-api\"} | trace_id=\"$TRACE\""
# (Returns every log line from every service for one trace.)

# READ-ONLY: confirm Tempo holds the trace block.
curl -fsS -u "$TEMPO_USER:$TEMPO_PASS" \
  "http://tempo.internal:3200/api/traces/$TRACE" | jq '.batches | length'
# 4
# (Four services emitted spans; the numbers should match the
# distinct service_name values found in Loki above.)

# READ-ONLY: confirm the Grafana data source provisioned the
# derived field on the Loki panel.
curl -fsS -u "$GRAFANA_ADMIN" \
  "http://grafana.internal:3000/api/datasources/uid/loki-prod-eu" | jq .jsonData.derivedFields
# [
#   {
#     "name": "traceID",
#     "matcherRegex": "\"trace_id\":\"([0-9a-f]{32})\"",
#     "url": "$${__value.raw}",
#     "urlDisplayLabel": "Open in Tempo",
#     "datasourceUid": "tempo-prod-eu",
#     "internalLink": {
#       "expr": "${__value.raw}",
#       "datasourceUid": "tempo-prod-eu"
#     }
#   }
# ]

If step 2 returns empty for a request that definitely ran, the logging library is not in scope of the SDK. If step 3 returns zero lines, the Loki stream has the wrong labels or the structured metadata promotion in Alloy is missing. If step 4 returns 404, Tempo’s retention has dropped the trace or the ingestion pipeline is not delivering. If step 5 returns an empty array, the Grafana provisioning file has not been loaded or the datasourceUid value is wrong.

How it can fail

  1. The logging library is not in scope of the SDK. The service creates spans correctly, but the log handler is constructed once at startup and never given the active context. Symptom: every log line has trace_id="00000000000000000000000000000000" or the field is null/missing entirely.
  2. The SDK is configured but the auto-instrumentation is not. A Java service compiles with the OpenTelemetry libraries but never attaches the agent. Symptom: the span context exists in tests but never flows through production HTTP handlers; logs at request time carry no trace_id.
  3. The field name uses an unexpected shape. The handler writes traceID (camel-case, capital ID) instead of trace_id. Symptom: Tempo and Grafana cannot find it; the Grafana derived-field regex, which expects "trace_id":"([0-9a-f]{32})", returns zero matches; the pivot is greyed out.
  4. The value is parsed out of the message text in Alloy. A team that does not have the SDK in the application falls back to a regex stage that scrapes the trace_id=... substring out of an unstructured log line. Symptom: the field exists on Loki lines but is wrong on services that have a different log format; some lines have a real value, some have garbage.
  5. The async boundary loses the context. A Go service submits work to a goroutine without passing the context.Context. Symptom: logs emitted inside the goroutine have no trace_id even though the launching request has one; the chains break at the goroutine boundary.
  6. Loki receives the line but the structured metadata promotion is missing. Alloy ships the line to Loki without the stage.structured_metadata block. Symptom: logcli query returns the line text, but | trace_id="..." returns zero rows because Loki does not know the field exists.

How to troubleshoot it

The diagnostic order for “the trace_id field is missing or wrong”:

  1. Is the SDK in the process? docker exec checkout-api-7f8c printenv | grep OTEL — at least OTEL_SERVICE_NAME should be set. An empty result is a strong hint that the SDK has not been initialised.
  2. Is the log handler reading the context? Run a one-shot Python script in the same container that imports the handler’s filter and asserts the field is populated. If the filter reports null, the handler is reading from the wrong context scope.
  3. Is the line format correct? Grep stdout for the expected JSON shape. A line like traceID=4bf92f... instead of "trace_id":"4bf92f..." is the wrong key.
  4. Is the structured metadata promotion in Alloy loaded? curl -fsS http://alloy.internal:12345/config and look for the stage.structured_metadata block. Alloy does not re-load on its own; an OOM, a syntax error, or a stale file leaves the old config in effect.
  5. Is the trace in Tempo? curl ... /api/traces/<id> — 200 means the SDK is producing valid spans; 404 means the spans are not being exported; 400 means an identifier is malformed.

Security implications

The trace_id is a 128-bit random number. It is not a secret. It is safe to log, return in HTTP headers, paste into a Slack channel, and ship to a customer support ticket. The risk is not disclosure; the risk is correlation. An attacker who obtains a trace_id from a leaked log file can use it to find related log lines that might contain more sensitive material (the trace’s other services, other spans, request payloads).

Treat the field with the same discipline as any structured log attribute. Do not put personally identifiable information inside the same JSON object as trace_id and ship the combined object to a less-trusted destination. Redaction runs upstream of the structured metadata promotion in Alloy, not downstream of it.

The W3C format mandates the 32-lowercase-hex form. Hashing or one-way-encoding the trace_id before logging it breaks the pivot (Tempo expects the canonical form) and provides no security benefit (the value is already a random 128-bit token).

Performance implications

The cost is small but measurable. A trace_id and span_id field add approximately 50 bytes per log line after JSON encoding. On a fleet shipping 100 GB per day, that is roughly 5 GB per day — about 5% extra bytes on top of the base log volume. The cost is in storage and in network between the application and Loki.

The cheaper option is to put the field in structured metadata on the Loki side (the JSON-shaped pair travels as a separate header in the push payload, not as part of the line text). The more expensive option — making it a stream label — is wrong. Loki stores every distinct value of every stream label in its index; an unbounded trace_id label adds a row to the index per request and breaks the index budget within hours.

The query cost is the flip side. A query like {service_name="checkout-api"} | trace_id="<value>" reads structured metadata, which Loki evaluates against the per-line metadata index. A free-text line-filter |="trace_id=4bf92f..." scans every byte of every line and is orders of magnitude slower; avoid the line filter unless the application really does not emit the field as structured metadata.

Production guidance

  • Standardise the field name on the OpenTelemetry semantic conventions: trace_id and span_id, lowercase, underscored, 32 / 16 lowercase hex characters.
  • Promote the field through Loki’s structured metadata path. Never promote to a stream label unless the cardinality is provably bounded (per-tenant, per-environment — never per-request).
  • Reject hand-rolled correlation in favour of the OpenTelemetry log SDK or its equivalent bridge (logback instrumentation, python logging filter, slog handler). The hand-rolled version is the same code, written by every team that does not want to take the dependency.
  • Add a test that generates a request, asserts the log line contains a 32-char hex trace_id, and confirms Tempo resolves the same identifier. The test is the topic of lesson 06.

Verification

You should now be able to answer:

  • Why is a structured trace_id field preferred over a regex-derived match in a free-text log line?
  • Which component is responsible for writing the trace_id field — the application, the log shipper, or Loki?
  • What is the cost of putting the trace_id in a stream label versus in structured metadata?
  • How do you confirm that the field on a Loki line is the same value Tempo holds as the trace block key?
  • What is the most common cause of a trace_id that exists on some lines and not others?

Quiz

Knowledge check · 8 questions

  1. Q1. Which component is responsible for writing the trace_id field on every log line?

  2. Q2. A Loki stream label is set to trace_id. Why is that the wrong choice?

  3. Q3. A regex pipeline stage that scrapes trace_id=... out of an unstructured log line is a viable substitute for stamping the field in the logging library.

  4. Q4. Which of the following can cause the trace_id field to be missing on some log lines but present on others? Select all that apply.

  5. Q5. Name the OpenTelemetry semantic attribute that the log handler writes for the trace identifier, in its canonical form.

  6. Q6. A Grafana derived field on the Loki data source expects "trace_id":"(value)" in the JSON line. The line that fails to match is {"traceID":"4bf9...","msg":"..."}. What is most likely wrong?

  7. Q7. The log line shows a valid trace_id but the Grafana pivot button is greyed out. What is the next check?

  8. Q8. The trace_id is a 128-bit random value and is not considered sensitive.

Passing score: 75%. Answers are checked in this browser.