fix(logs): correlate V2 log records with their span context

README.md

@@ -100,6 +100,12 @@ the parent run span; a background child may outlive its already-ended dispatch t
 
 ## Installation
 
+Log events associated with an observed LLM step, tool call, or failed execution carry that span's native OTel
+trace and span IDs. Events without a matching span can remain uncorrelated. Disabling a span type uses its
+available parent context; disabling logs still suppresses all log export. Trace IDs are not metric attributes.
+Prompt admission logs use the current execution's context only when steering an active execution. Queued prompts
+remain uncorrelated because their consuming execution has not started yet.
+
 Add the plugin to your opencode config at `~/.config/opencode/opencode.json`:
 
 ```json

src/handlers/permission.ts

@@ -1,6 +1,6 @@
 import { SeverityNumber } from "@opentelemetry/api-logs"
 import type { EventOf, HandlerContext } from "../types.ts"
-import { agentAttrs, getSessionAgentMeta, setBoundedMap } from "../util.ts"
+import { agentAttrs, getSessionAgentMeta, resolveRunContext, setBoundedMap } from "../util.ts"
 
 /** Stores an answered permission prompt for correlation when the reply arrives. */
 export function handlePermissionAsked(e: EventOf<"permission.asked">, ctx: HandlerContext) {
@@ -31,6 +31,7 @@ export function handlePermissionReplied(e: EventOf<"permission.replied">, ctx: H
     timestamp: e.created,
     observedTimestamp: Date.now(),
     body: "tool_decision",
+    context: resolveRunContext(d.sessionID, ctx),
     attributes: {
       "event.name": "tool_decision",
       "session.id": d.sessionID,

src/handlers/session.ts

@@ -18,6 +18,7 @@ import {
   isTraceEnabled,
   markSeen,
   modelRef,
+  resolveRunContext,
   resolveSubagentTraceContext,
   setBoundedMap,
   totalTokens,
@@ -33,7 +34,8 @@ export function handlePromptEnqueued(e: EventOf<"session.inbox.enqueued">, ctx:
   for (const agent of item.payload.agents ?? []) parts.push(agent.name)
   for (const skill of item.payload.skills ?? []) parts.push(skill.name)
   const text = parts.filter(Boolean).join("\n")
-  if (item.delivery === "steer" && ctx.tracing.activeExecutions.has(sessionID)) {
+  const steeringActiveExecution = item.delivery === "steer" && ctx.tracing.activeExecutions.has(sessionID)
+  if (steeringActiveExecution) {
     const active = ctx.tracing.activePrompts.get(sessionID)
     setBoundedMap(ctx.tracing.activePrompts, sessionID, {
       text: active?.text ? `${active.text}\n${text}` : text,
@@ -51,6 +53,7 @@ export function handlePromptEnqueued(e: EventOf<"session.inbox.enqueued">, ctx:
     timestamp: e.created,
     observedTimestamp: Date.now(),
     body: "user_prompt",
+    ...(steeringActiveExecution ? { context: resolveRunContext(sessionID, ctx) } : {}),
     attributes: {
       "event.name": "user_prompt",
       "session.id": sessionID,
@@ -236,6 +239,7 @@ export function handleExecutionEnded(
 ) {
   const sessionID = e.data.sessionID
   const totals = ctx.tracing.sessionTotals.get(sessionID)
+  const logContext = resolveRunContext(sessionID, ctx)
   ctx.tracing.activeExecutions.delete(sessionID)
   const pendingDispatch = ctx.tracing.subagentParents.get(sessionID)
   if (pendingDispatch) {
@@ -279,6 +283,7 @@ export function handleExecutionEnded(
       timestamp: e.created,
       observedTimestamp: Date.now(),
       body: "session.error",
+      context: logContext,
       attributes: {
         "event.name": "session.error",
         "session.id": sessionID,

src/handlers/step.ts

@@ -34,6 +34,7 @@ import {
   isTraceEnabled,
   markSeen,
   resolveRunContext,
+  resolveStepContext,
   setBoundedMap,
 } from "../util.ts"
 
@@ -170,6 +171,7 @@ export function handleStepEnded(e: EventOf<"session.step.ended">, ctx: HandlerCo
   const providerID = meta?.providerID ?? "unknown"
   const durationMs = Math.max(0, e.created - (meta?.startMs ?? e.created))
 
+  const logContext = resolveStepContext(d.sessionID, d.assistantMessageID, ctx)
   recordUsageMetrics(d.sessionID, modelID, agent, d.tokens, d.cost, ctx)
   const firstStep = countMessage(d.assistantMessageID, d.sessionID, modelID, providerID, agent, ctx)
   accumulateTotals(d.sessionID, allTokens(d.tokens), d.cost, firstStep, ctx)
@@ -207,6 +209,7 @@ export function handleStepEnded(e: EventOf<"session.step.ended">, ctx: HandlerCo
     timestamp: e.created,
     observedTimestamp: Date.now(),
     body: "api_request",
+    context: logContext,
     attributes: {
       "event.name": "api_request",
       "session.id": d.sessionID,
@@ -238,6 +241,7 @@ export function handleStepFailed(e: EventOf<"session.step.failed">, ctx: Handler
   const error = errorSummary(d.error)
   const durationMs = Math.max(0, e.created - (meta?.startMs ?? e.created))
 
+  const logContext = resolveStepContext(d.sessionID, d.assistantMessageID, ctx)
   recordUsageMetrics(d.sessionID, modelID, agent, d.tokens, d.cost, ctx)
   const firstStep = countMessage(d.assistantMessageID, d.sessionID, modelID, providerID, agent, ctx)
   accumulateTotals(d.sessionID, allTokens(d.tokens), d.cost ?? 0, firstStep, ctx)
@@ -272,6 +276,7 @@ export function handleStepFailed(e: EventOf<"session.step.failed">, ctx: Handler
     timestamp: e.created,
     observedTimestamp: Date.now(),
     body: "api_error",
+    context: logContext,
     attributes: {
       "event.name": "api_error",
       "session.id": d.sessionID,

src/handlers/tool.ts

@@ -22,6 +22,7 @@ import {
   isMetricEnabled,
   isTraceEnabled,
   resolveStepContext,
+  resolveToolContext,
   setBoundedMap,
 } from "../util.ts"
 
@@ -173,6 +174,7 @@ function finishTool(
   const durationMs = Math.max(0, endMs - start)
   const { agentName, agentType } = getSessionAgentMeta(sessionID, ctx)
   const sizeBytes = output ? Buffer.byteLength(output, "utf8") : 0
+  const logContext = resolveToolContext(callID, sessionID, meta?.assistantMessageID ?? "", ctx)
 
   if (success && observedExecution && meta.command && SHELL_TOOL_RE.test(tool) && GIT_COMMIT_RE.test(meta.command)) {
     if (isMetricEnabled("commit.count", ctx)) {
@@ -184,6 +186,7 @@ function finishTool(
       timestamp: endMs,
       observedTimestamp: Date.now(),
       body: "commit",
+      context: logContext,
       attributes: {
         "event.name": "commit",
         "session.id": sessionID,
@@ -226,6 +229,7 @@ function finishTool(
     timestamp: start,
     observedTimestamp: Date.now(),
     body: "tool_result",
+    context: logContext,
     attributes: {
       "event.name": "tool_result",
       "session.id": sessionID,

src/plugin.ts

@@ -88,7 +88,7 @@ export async function setup(ctx: OpenCodeContext): Promise<() => Promise<void>>
 
   const emitLog: HandlerContext["emitLog"] = (record) => {
     if (!config.logsEnabled) return
-    shared.logger.emit(record)
+    shared.logger.emit({ ...record, context: record.context ?? ROOT_CONTEXT })
   }
 
   const remoteContext = remoteParentContext(config.traceparent, config.tracestate)

src/util.ts

@@ -141,6 +141,14 @@ export function resolveStepContext(sessionID: string, assistantMessageID: string
   return spanContext ? trace.setSpanContext(parent, spanContext) : parent
 }
 
+export function resolveToolContext(callID: string, sessionID: string, assistantMessageID: string, ctx: HandlerContext): Context {
+  const parent = resolveStepContext(sessionID, assistantMessageID, ctx)
+  const span = ctx.tracing.toolSpans.get(callID)
+  if (span) return trace.setSpan(parent, span)
+  const spanContext = ctx.tracing.toolSpanContexts.get(callID)
+  return spanContext ? trace.setSpanContext(parent, spanContext) : parent
+}
+
 /** Resolves a child run under its correlated dispatch tool, falling back to the parent run. */
 export function resolveSubagentTraceContext(sessionID: string, parentID: string, agent: string, ctx: HandlerContext): Context {
   const exact = ctx.tracing.subagentParents.get(sessionID)

tests/handlers/log-context.test.ts

@@ -0,0 +1,167 @@
+import { describe, expect, test } from "bun:test"
+import { trace } from "@opentelemetry/api"
+import { InMemoryLogRecordExporter, LoggerProvider, SimpleLogRecordProcessor } from "@opentelemetry/sdk-logs"
+import { finalizeSession, handleExecutionEnded, handleExecutionStarted, handlePromptEnqueued, handleSessionCreated } from "../../src/handlers/session.ts"
+import { handleStepEnded, handleStepFailed, handleStepStarted } from "../../src/handlers/step.ts"
+import { handleToolCalled, handleToolFailed, handleToolInputStarted, handleToolSuccess } from "../../src/handlers/tool.ts"
+import { evt, makeCtx, tokens } from "../helpers.ts"
+
+function seed(ctx: ReturnType<typeof makeCtx>["ctx"], sessionID = "session", messageID = "message") {
+  handleSessionCreated(evt("session.created", { sessionID, agent: "build" }), ctx)
+  handleExecutionStarted(evt("session.execution.started", { sessionID }), ctx)
+  handleStepStarted(evt("session.step.started", {
+    sessionID,
+    assistantMessageID: messageID,
+    agent: "build",
+    model: { id: "model", providerID: "provider" },
+  }), ctx)
+}
+
+describe("native log trace context", () => {
+  test("keeps a queued prompt uncorrelated with the preceding execution", () => {
+    const { ctx, logger, tracer } = makeCtx()
+    seed(ctx)
+    const previousRun = ctx.tracing.runSpans.get("session")!
+    handlePromptEnqueued(evt("session.inbox.enqueued", {
+      sessionID: "session", inboxID: "queued",
+      item: { type: "user", payload: { text: "next execution" }, delivery: "queue" },
+    }), ctx, false)
+    const record = logger.records.at(-1)!
+    expect(record.body).toBe("user_prompt")
+    expect(record.context).toBeUndefined()
+    handleExecutionEnded(evt("session.execution.succeeded", { sessionID: "session" }), ctx, { type: "succeeded" })
+    finalizeSession("session", ctx)
+    handleExecutionStarted(evt("session.execution.started", { sessionID: "session" }), ctx)
+    const nextRun = tracer.spans.at(-1)!
+    expect(nextRun.attributes["input.value"]).toBe("next execution")
+    expect(nextRun.spanContext().spanId).not.toBe(previousRun.spanContext().spanId)
+    expect(record.context).toBeUndefined()
+  })
+
+  test("correlates a steering prompt with its active execution", () => {
+    const { ctx, logger } = makeCtx()
+    seed(ctx)
+    handlePromptEnqueued(evt("session.inbox.enqueued", {
+      sessionID: "session", inboxID: "steering",
+      item: { type: "user", payload: { text: "adjust current execution" }, delivery: "steer" },
+    }), ctx, false)
+    expect(trace.getSpanContext(logger.records.at(-1)!.context!)).toEqual(
+      ctx.tracing.runSpans.get("session")!.spanContext(),
+    )
+    expect(ctx.tracing.activePrompts.get("session")?.text).toBe("adjust current execution")
+    expect(ctx.tracing.pendingPrompts.has("session")).toBe(false)
+  })
+
+  test("leaves a steering prompt without an active execution uncorrelated", () => {
+    const { ctx, logger } = makeCtx()
+    handleSessionCreated(evt("session.created", { sessionID: "session", agent: "build" }), ctx)
+    handlePromptEnqueued(evt("session.inbox.enqueued", {
+      sessionID: "session", inboxID: "initial",
+      item: { type: "user", payload: { text: "start execution" }, delivery: "steer" },
+    }), ctx, false)
+    expect(logger.records.at(-1)!.context).toBeUndefined()
+    expect(ctx.tracing.pendingPrompts.get("session")?.[0]?.text).toBe("start execution")
+  })
+
+  for (const failed of [false, true]) {
+    test(`captures the completed LLM context before cleanup (${failed ? "failure" : "success"})`, () => {
+      const { ctx, logger, tracer } = makeCtx()
+      seed(ctx)
+      const data = { sessionID: "session", assistantMessageID: "message", finish: "stop", cost: 1, tokens: tokens() }
+      if (failed) handleStepFailed(evt("session.step.failed", { ...data, error: { type: "error", message: "failed" } }), ctx)
+      else handleStepEnded(evt("session.step.ended", data), ctx)
+      const span = tracer.spans.find(item => item.name === "opencode.llm")!
+      const record = logger.records.at(-1)!
+      expect(trace.getSpanContext(record.context!)).toEqual(span.spanContext())
+      expect(span.ended).toBe(true)
+      expect(ctx.tracing.stepSpans.size).toBe(0)
+      expect(ctx.tracing.stepSpanContexts.size).toBe(0)
+    })
+
+    test(`uses the exact tool context with overlapping calls (${failed ? "failure" : "success"})`, () => {
+      const { ctx, logger, tracer } = makeCtx()
+      seed(ctx)
+      for (const id of ["first", "second"]) {
+        handleToolInputStarted(evt("session.tool.input.started", { sessionID: "session", assistantMessageID: "message", id, name: "shell" }), ctx)
+        handleToolCalled(evt("session.tool.called", { sessionID: "session", assistantMessageID: "message", id, input: { command: "git commit -m test" } }), ctx)
+      }
+      const data = { sessionID: "session", assistantMessageID: "message", id: "first", content: [{ type: "text", text: "result" }] }
+      if (failed) handleToolFailed(evt("session.tool.failed", { ...data, error: { type: "error", message: "failed" } }), ctx)
+      else handleToolSuccess(evt("session.tool.success", data), ctx)
+      const span = tracer.spans.find(item => item.attributes["tool.id"] === "first")!
+      const record = logger.records.at(-1)!
+      expect(trace.getSpanContext(record.context!)).toEqual(span.spanContext())
+      expect(span.ended).toBe(true)
+      expect(ctx.tracing.toolSpans.has("first")).toBe(false)
+      expect(ctx.tracing.toolSpans.has("second")).toBe(true)
+      if (!failed) {
+        const commit = logger.records.find(item => item.body === "commit")!
+        expect(trace.getSpanContext(commit.context!)).toEqual(span.spanContext())
+      }
+    })
+  }
+
+  test("uses the failed execution context after its run span ends", () => {
+    const { ctx, logger, tracer } = makeCtx()
+    seed(ctx)
+    handleExecutionEnded(evt("session.execution.failed", { sessionID: "session" }), ctx, {
+      type: "failed", error: { type: "error", message: "failed" },
+    })
+    const span = tracer.spans.find(item => item.name === "opencode.session")!
+    expect(trace.getSpanContext(logger.records.at(-1)!.context!)).toEqual(span.spanContext())
+    expect(ctx.tracing.runSpans.size).toBe(0)
+  })
+
+  test("falls back to the run when LLM spans are disabled", () => {
+    const { ctx, logger, tracer } = makeCtx("project", [], ["llm"])
+    seed(ctx)
+    handleStepEnded(evt("session.step.ended", { sessionID: "session", assistantMessageID: "message", finish: "stop", cost: 1, tokens: tokens() }), ctx)
+    const span = tracer.spans.find(item => item.name === "opencode.session")!
+    expect(trace.getSpanContext(logger.records.at(-1)!.context!)).toEqual(span.spanContext())
+  })
+
+  test("does not invent context with tracing disabled or a missed start event", () => {
+    for (const disabled of [[], ["session", "llm", "tool"]]) {
+      const { ctx, logger, tracer } = makeCtx("project", [], disabled)
+      if (disabled.length) seed(ctx)
+      handleStepEnded(evt("session.step.ended", { sessionID: "session", assistantMessageID: "message", finish: "stop", cost: 1, tokens: tokens() }), ctx)
+      expect(trace.getSpanContext(logger.records.at(-1)!.context!)).toBeUndefined()
+      expect(tracer.spans).toHaveLength(0)
+    }
+  })
+
+  test("keeps contexts isolated between sessions", () => {
+    const { ctx, logger, tracer } = makeCtx()
+    seed(ctx, "first", "message-first")
+    seed(ctx, "second", "message-second")
+    handleStepEnded(evt("session.step.ended", { sessionID: "first", assistantMessageID: "message-first", finish: "stop", cost: 1, tokens: tokens() }), ctx)
+    const span = tracer.spans.find(item => item.name === "opencode.llm" && item.attributes["session.id"] === "first")!
+    expect(trace.getSpanContext(logger.records.at(-1)!.context!)).toEqual(span.spanContext())
+  })
+
+  test("does not enable logs when the content policy disables them", () => {
+    const { ctx, logger } = makeCtx("project", [], [], false)
+    seed(ctx)
+    handleStepEnded(evt("session.step.ended", { sessionID: "session", assistantMessageID: "message", finish: "stop", cost: 1, tokens: tokens() }), ctx)
+    expect(logger.records).toHaveLength(0)
+  })
+
+  test("exports native traceId and spanId with the real logs SDK", async () => {
+    const { ctx, logger, tracer } = makeCtx()
+    const exporter = new InMemoryLogRecordExporter()
+    const provider = new LoggerProvider({ processors: [new SimpleLogRecordProcessor(exporter)] })
+    try {
+      seed(ctx)
+      handleStepEnded(evt("session.step.ended", { sessionID: "session", assistantMessageID: "message", finish: "stop", cost: 1, tokens: tokens() }), ctx)
+      provider.getLogger("test").emit(logger.records.at(-1)!)
+      await provider.forceFlush()
+      const span = tracer.spans.find(item => item.name === "opencode.llm")!
+      const record = exporter.getFinishedLogRecords()[0]!
+      expect(record.spanContext?.traceId).toBe(span.spanContext().traceId)
+      expect(record.spanContext?.spanId).toBe(span.spanContext().spanId)
+      expect(record.attributes["trace_id"]).toBeUndefined()
+    } finally {
+      await provider.shutdown()
+    }
+  })
+})

tests/integration/opencode.test.ts

@@ -24,7 +24,10 @@ test("exports real OpenCode session telemetry over OTLP/JSON", async () => {
   expect(Number(sessions["asDouble"] ?? sessions["asInt"])).toBe(1)
   expect(attributes(sessions)["session.id"]).toBe(result["sessionID"])
   const logs = signalRecords(received["logs"]!, "Logs")
-  expect(logs.some(log => attributes(log)["event.name"] === "api_request")).toBe(true)
+  const apiLog = logs.find(log => attributes(log)["event.name"] === "api_request")!
+  expect(apiLog).toBeDefined()
+  expect(apiLog["traceId"]).toBe(llm["traceId"])
+  expect(apiLog["spanId"]).toBe(llm["spanId"])
   expect(logs.some(log => attributes(log)["event.name"] === "session.idle")).toBe(true)
 }, 40_000)
 
@@ -64,6 +67,10 @@ for (const disabled of [false, true]) {
         expect(parent["name"]).toBe("opencode.llm")
         expect(tool!["traceId"]).toBe(parent["traceId"])
         expect(attributes(tool!)["output.value"]).toContain("integration-fixture-contents")
+        const log = signalRecords(scenario.received["logs"]!, "Logs")
+          .find(record => attributes(record)["event.name"] === "tool_result")!
+        expect(log["traceId"]).toBe(tool!["traceId"])
+        expect(log["spanId"]).toBe(tool!["spanId"])
       })
     }