[BUG] OTel log events (claude_code.user_prompt, api_request_body, tool_decision, hook_execution_complete) emitted with empty trace_id/span_id while sibling spans correlate correctly

Status Fixed / completed

Reported on v2.1.153

Maintainer reply None cached

Activity 3 comments · opened May 28, 2026 · closed Jul 15, 2026

Summary

When OTEL_LOGS_EXPORTER=otlp is enabled, the CLI emits claude_code.* OTel log events (via the com.anthropic.claude_code.events instrumentation scope) with empty trace_id and span_id fields — even though TRACEPARENT propagation works correctly for spans in the same subprocess invocation. This breaks log↔trace correlation in any backend (SigNoz, Honeycomb, Datadog, Grafana) and forces a DB-side join via session.id to recover execution context.

Environment

Claude Code CLI: 2.1.153
claude-agent-sdk-python: 0.1.81
Parent process spawns the CLI via claude_agent_sdk.query() with an active parent OTel span
Subprocess env includes:
CLAUDE_CODE_ENABLE_TELEMETRY=1
OTEL_LOGS_EXPORTER=otlp
OTEL_LOG_USER_PROMPTS=1
OTEL_LOG_TOOL_DETAILS=1
OTEL_LOG_RAW_API_BODIES=1
OTLP/HTTP to a sidecar collector → SigNoz

Expected

Each claude_code.* log event carries trace_id and span_id derived from the active span context at emit time, so users can pivot from a log event to the parent trace in one click.

Actual

On the same subprocess invocation:

claude_code.interaction span: parentSpanID = af90b0d5d83dfe10 ✅ (TRACEPARENT propagated)
claude_code.tool / claude_code.llm_request spans: parented correctly ✅
claude_code.user_prompt / api_request_body / tool_decision / hook_execution_complete log events: trace_id = "", span_id = "" ❌

Sample raw event attributes (from com.anthropic.claude_code.events scope):

event.name: api_request_body
trace_id: ""
span_id: ""
user.id: <SDK hashed user id, not domain user>
session.id: <SDK auto-generated UUID>
prompt.id: <ok>

The events do carry session.id, but it's the SDK's auto-generated session UUID, not the parent's execution.id — and there's no on-event way to join back without a DB lookup.

Likely cause

OTel JS LogRecords populate spanContext from context.active() at emit time. If logger.emit(...) is invoked from a callback that has lost AsyncLocalStorage context (event-emitter dispatch, microtask boundary, etc.), the LogRecord ships with empty spanContext. Wrapping each event emission in context.with(trace.setSpan(context.active(), interactionSpan), () => logger.emit(...)) would fix it.

Impact

All log↔trace navigation in observability backends is broken for claude_code.* events.
Per-tenant / per-execution event filtering requires a DB join via session.id → application session store → thread_id/execution_id, instead of a backend-side filter on execution.id or trace_id.
Worth fixing because spans already work — the gap is just in log-event emission paths.

Workaround

Pivot from log events to traces through session.id only, or rely on traces (claude_code.interaction, claude_code.tool, claude_code.llm_request) instead of log events for execution-level correlation.

View original on GitHub ↗

3 Comments

makeavish · 3 months ago

Additional finding: `session.id` is also inconsistently set on the `claude_code.interaction` span itself

Continuing to dig into correlation across the same dataset, I noticed the same context-loss pattern affects span attributes too, not just log events.

When filtering traces by session.id = '<SDK session UUID>', some sessions return their claude_code.interaction span and some don't — even though the span clearly exists in the trace (it's the parent of claude_code.llm_request / claude_code.tool children that do carry session.id).

Concrete example from one trace (session.id = 769e228b-a86d-4bc1-9f62-eb118cbae607):

| Span | Has session.id attribute? |
|---|---|
| claude_code.llm_request | ✅ yes |
| claude_code.tool | ✅ yes |
| claude_code.tool.execution | ✅ yes |
| claude_code.tool.blocked_on_user | ✅ yes |
| claude_code.interaction | ❌ no |

For a different session in another pod, claude_code.interaction did carry session.id. So the attribute is set on the interaction span sometimes but not always — likely the same root cause as this bug: the SDK emits the parent interaction span (and the log events) from a code path where the session-bound context hasn't been activated yet, while the child request/tool spans pick it up correctly because they're opened deeper inside the active context.

Practical impact

The current workaround in this issue's description ("pivot from log events via session.id") implicitly assumes claude_code.interaction is reliably tagged. It isn't. The robust pivot has to filter on any claude_code.* child span (llm_request / tool), grab the trace_id, then open the trace to find the interaction parent.

Suggested fix scope

Whatever wrapping fixes context propagation for the log events should also be applied at the site where the claude_code.interaction span is started, so the session attribute is set on the parent span at start-of-span time rather than only being available once a child is emitted.

bnorman21 · 2 months ago

+1. Why emit logs if you cant search for them by a trace id.

Necmttn · 2 months ago

A useful regression fixture here would cover the async boundary directly, rather than only the final exported shape.

For each event emitter path (user_prompt, api_request_body, tool_decision, hook_execution_complete), create an active parent span, cross the same callback or event-emitter boundary the CLI uses, emit the log record, and assert:

trace_id and span_id match the active span context
session.id is still present as a fallback join key
prompt/tool ids stay on the event

Implementation-wise, wrapping the emit in context.with(parentContext, () => logger.emit(...)) is safer than relying on whatever context.active() happens to be after the callback hop.

---

_Generated with ax._