feat(observability): add turn links to session traces

This commit is contained in:
starptech 2026-07-08 21:12:27 +02:00
commit a2e640aef9
20 changed files with 544 additions and 191 deletions

View file

@ -2,12 +2,14 @@ import { afterEach, describe, expect, test } from "bun:test"
import { NodeFileSystem } from "@effect/platform-node"
import {
ATTR_DEPLOYMENT_ENVIRONMENT_NAME,
ATTR_ERROR_TYPE,
ATTR_OPENCODE_LINK_TYPE,
ATTR_OPENCODE_CLIENT,
ATTR_OPENCODE_RUN,
ATTR_SERVICE_INSTANCE_ID,
ATTR_SERVICE_NAMESPACE,
} from "@opencode-ai/core/observability/semconv"
import { Deferred, Effect, Fiber, Layer, Logger, Option, Tracer } from "effect"
import { Cause, Deferred, Effect, Fiber, Layer, Logger, Option, Tracer } from "effect"
import { ParentSpan, type Span } from "effect/Tracer"
import { HttpClient, HttpClientRequest, HttpClientResponse } from "effect/unstable/http"
import fs from "fs/promises"
@ -17,6 +19,8 @@ import { fileLogger } from "../../src/observability/logging"
import { resource } from "../../src/observability/otlp"
import { SessionTelemetry } from "../../src/observability/session"
import { HttpTelemetry } from "../../src/observability/http"
import { AgentTelemetry } from "../../src/observability/agent"
import { ToolTelemetry } from "../../src/observability/tool"
import { it } from "../lib/effect"
const otelResourceAttributes = process.env.OTEL_RESOURCE_ATTRIBUTES
@ -106,6 +110,148 @@ it.effect("retains an external ambient trace parent", () =>
}),
)
it.effect("detaches a top-level execution from its acquisition parent", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
},
})
const telemetry = SessionTelemetry.makeExecution<string>()
yield* Effect.useSpan("startup", () =>
telemetry.drain(
"session",
AgentTelemetry.invoke({ sessionID: "session", agent: "build", errorType: () => "unknown" }, Effect.void),
),
).pipe(Effect.provideService(Tracer.Tracer, tracer))
expect(spans.find((span) => span.name === "invoke_agent build")?.parent._tag).toBe("None")
}),
)
it.effect("links a detached execution to its spawning span", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
},
})
const telemetry = SessionTelemetry.makeExecution<string>()
yield* Effect.useSpan("execute_tool subagent", (parent) =>
telemetry
.resume("session", Effect.void)
.pipe(
Effect.provideService(SessionTelemetry.TraceParent, null),
Effect.provideService(SessionTelemetry.TraceLinks, [{ span: parent, attributes: {} }]),
),
).pipe(Effect.provideService(Tracer.Tracer, tracer))
yield* telemetry
.drain(
"session",
AgentTelemetry.invoke({ sessionID: "session", agent: "explore", errorType: () => "unknown" }, Effect.void),
)
.pipe(Effect.provideService(Tracer.Tracer, tracer))
const parent = spans.find((span) => span.name === "execute_tool subagent")
const child = spans.find((span) => span.name === "invoke_agent explore")
expect(child?.parent._tag).toBe("None")
expect(child?.links).toHaveLength(1)
expect(child?.links[0]?.span).toBe(parent)
}),
)
it.effect("links each agent turn to the previous Session turn", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
},
})
const telemetry = SessionTelemetry.makeExecution<string>()
const run = telemetry
.drain(
"session",
AgentTelemetry.invoke({ sessionID: "session", agent: "build", errorType: () => "unknown" }, Effect.void),
)
.pipe(Effect.provideService(Tracer.Tracer, tracer))
yield* run
yield* telemetry.settled("session")
yield* run
const turns = spans.filter((span) => span.name === "invoke_agent build")
expect(turns).toHaveLength(2)
expect(turns[1]?.links).toHaveLength(1)
expect(turns[1]?.links[0]?.span).toBe(turns[0])
expect(turns[1]?.links[0]?.attributes[ATTR_OPENCODE_LINK_TYPE]).toBe("previous_turn")
}),
)
it.effect("closes an active agent span when its execution scope is interrupted", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
},
})
const started = yield* Deferred.make<void>()
yield* Effect.gen(function* () {
const fiber = yield* AgentTelemetry.invoke(
{ sessionID: "session", agent: "build", errorType: () => "unknown" },
Deferred.succeed(started, undefined).pipe(Effect.andThen(Effect.never)),
).pipe(Effect.provideService(SessionTelemetry.TraceParent, null), Effect.forkChild)
yield* Deferred.await(started)
yield* Fiber.interrupt(fiber)
}).pipe(Effect.provideService(Tracer.Tracer, tracer))
const span = spans.find((span) => span.name === "invoke_agent build")
expect(span?.attributes.get(ATTR_ERROR_TYPE)).toBe("canceled")
expect(span?.status._tag === "Ended" && span.status.exit._tag).toBe("Failure")
}),
)
it.effect("classifies a tool cause containing interruption as canceled", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
},
})
const cause = Cause.fromReasons([
Cause.makeFailReason(new Error("concurrent failure")),
Cause.makeInterruptReason(),
])
yield* ToolTelemetry.execute(
{ sessionID: "session", agent: "explore", call: { id: "call", name: "read" } },
Effect.failCause(cause),
() => "tool.execution",
).pipe(Effect.exit, Effect.provideService(Tracer.Tracer, tracer))
const span = spans.find((span) => span.name === "execute_tool read")
expect(span?.attributes.get(ATTR_ERROR_TYPE)).toBe("canceled")
expect(span?.status._tag === "Ended" && span.status.exit._tag).toBe("Failure")
}),
)
it.effect("applies HTTP response validation without a parent span", () =>
Effect.gen(function* () {
const request = HttpClientRequest.get("https://example.test/missing")

View file

@ -42,9 +42,10 @@ import { Instructions } from "@opencode-ai/core/instructions"
import { SkillGuidance } from "@opencode-ai/core/skill/guidance"
import { ReferenceGuidance } from "@opencode-ai/core/reference/guidance"
import { McpGuidance } from "@opencode-ai/core/mcp/guidance"
import { SessionTelemetry } from "@opencode-ai/core/observability/session"
import { describe, expect } from "bun:test"
import { eq } from "drizzle-orm"
import { Effect, Layer, Tracer } from "effect"
import { Effect, Layer, References, Tracer } from "effect"
import path from "node:path"
import { testEffect } from "./lib/effect"
@ -108,12 +109,14 @@ const execution = Layer.effect(
SessionExecution.Service,
Effect.gen(function* () {
const sessionRunner = yield* SessionRunner.Service
const telemetry = SessionTelemetry.makeExecution<SessionV2.ID>()
const coordinator = yield* SessionRunCoordinator.make<SessionV2.ID, SessionRunner.RunError>({
drain: (sessionID, force) => sessionRunner.drain({ sessionID, force }),
drain: (sessionID, force) => telemetry.drain(sessionID, sessionRunner.drain({ sessionID, force })),
settled: (sessionID) => telemetry.settled(sessionID),
})
return SessionExecution.Service.of({
active: coordinator.active,
resume: coordinator.run,
resume: (sessionID) => telemetry.resume(sessionID, coordinator.run(sessionID)),
wake: coordinator.wake,
interrupt: coordinator.interrupt,
awaitIdle: coordinator.awaitIdle,
@ -121,7 +124,12 @@ const execution = Layer.effect(
}),
).pipe(
Layer.provide(runnerLayer),
Layer.updateService(Tracer.Tracer, () => tracer),
Layer.provideMerge(
Layer.mergeAll(
Layer.succeed(Tracer.Tracer, tracer),
Layer.succeed(References.TracerEnabled, false),
),
),
)
const it = testEffect(
AppNodeBuilder.build(
@ -191,7 +199,7 @@ describe("SessionRunnerLLM recorded", () => {
resume: false,
})
yield* session.resume(sessionID)
yield* session.resume(sessionID).pipe(Effect.provideService(SessionTelemetry.TraceParent, null))
const messages = yield* session.context(sessionID)
expect(messages).toHaveLength(2)
@ -200,14 +208,16 @@ describe("SessionRunnerLLM recorded", () => {
expect(messages[1]?.type === "assistant" ? messages[1].content : []).toMatchObject([
{ type: "text", text: "Hello!" },
])
const agent = spans.find((span) => span.name === "invoke_agent")
const agent = spans.find((span) => span.name === "invoke_agent build")
const model = spans.find((span) => span.name === "chat gpt-4o-mini")
const http = spans.find((span) => span.attributes.get(ATTR_HTTP_REQUEST_METHOD) === "POST")
expect(agent?.parent._tag).toBe("None")
expect(agent?.attributes.get(ATTR_GEN_AI_CONVERSATION_ID)).toBe(sessionID)
expect(model?.parent._tag === "Some" ? model.parent.value.spanId : undefined).toBe(agent?.spanId)
expect(http?.parent._tag === "Some" ? http.parent.value.spanId : undefined).toBe(model?.spanId)
expect(model?.attributes.get(ATTR_GEN_AI_USAGE_INPUT_TOKENS)).toBeNumber()
expect(model?.attributes.get(ATTR_GEN_AI_USAGE_OUTPUT_TOKENS)).toBeNumber()
expect(spans.filter((span) => span.name.startsWith("SessionRunner."))).toEqual([])
expect(
(yield* db
.select({ type: EventTable.type })

View file

@ -92,10 +92,11 @@ import { InstructionDiscovery } from "@opencode-ai/core/instruction-discovery"
import { SkillGuidance } from "@opencode-ai/core/skill/guidance"
import { ReferenceGuidance } from "@opencode-ai/core/reference/guidance"
import { McpGuidance } from "@opencode-ai/core/mcp/guidance"
import { SessionTelemetry } from "@opencode-ai/core/observability/session"
import { ModelV2 } from "@opencode-ai/core/model"
import { Location } from "@opencode-ai/core/location"
import { ProviderV2 } from "@opencode-ai/core/provider"
import { Cause, DateTime, Deferred, Effect, Exit, Fiber, Layer, Schema, Stream, Tracer } from "effect"
import { Cause, DateTime, Deferred, Effect, Exit, Fiber, Layer, References, Schema, Stream, Tracer } from "effect"
import { TestClock } from "effect/testing"
import { asc, eq } from "drizzle-orm"
import { testEffect } from "./lib/effect"
@ -366,12 +367,14 @@ const execution = Layer.effect(
SessionExecution.Service,
Effect.gen(function* () {
const sessionRunner = yield* SessionRunner.Service
const telemetry = SessionTelemetry.makeExecution<SessionV2.ID>()
const coordinator = yield* SessionRunCoordinator.make<SessionV2.ID, SessionRunner.RunError>({
drain: (sessionID, force) => sessionRunner.drain({ sessionID, force }),
drain: (sessionID, force) => telemetry.drain(sessionID, sessionRunner.drain({ sessionID, force })),
settled: (sessionID) => telemetry.settled(sessionID),
})
return SessionExecution.Service.of({
active: coordinator.active,
resume: coordinator.run,
resume: (sessionID) => telemetry.resume(sessionID, coordinator.run(sessionID)),
wake: coordinator.wake,
interrupt: coordinator.interrupt,
awaitIdle: coordinator.awaitIdle,
@ -379,7 +382,12 @@ const execution = Layer.effect(
}),
).pipe(
Layer.provide(runnerLayer),
Layer.updateService(Tracer.Tracer, () => tracer),
Layer.provideMerge(
Layer.mergeAll(
Layer.succeed(Tracer.Tracer, tracer),
Layer.succeed(References.TracerEnabled, false),
),
),
)
const it = testEffect(
AppNodeBuilder.build(
@ -773,7 +781,7 @@ describe("SessionRunnerLLM", () => {
yield* session.resume(sessionID)
const agent = spans.find((span) => span.name === "invoke_agent")
const agent = spans.find((span) => span.name === "invoke_agent build")
const tool = spans.find((span) => span.name === "execute_tool echo")
expect(agent?.attributes).toMatchObject(
new Map([
@ -786,7 +794,8 @@ describe("SessionRunnerLLM", () => {
[ATTR_OPENCODE_SESSION_INPUT_DELIVERY]: "steer",
[ATTR_OPENCODE_SESSION_INPUT_COUNT]: 1,
})
expect(ancestorNames(agent)).toContain("SessionRunner.drain")
expect(agent?.parent._tag).toBe("None")
expect(spans.filter((span) => span.name.startsWith("SessionRunner."))).toEqual([])
expect(agent?.attributes.get(ATTR_GEN_AI_USAGE_INPUT_TOKENS)).toBe(8)
expect(agent?.attributes.get(ATTR_GEN_AI_USAGE_OUTPUT_TOKENS)).toBe(3)
expect(agent?.attributes.get(ATTR_GEN_AI_USAGE_CACHE_READ_INPUT_TOKENS)).toBe(2)
@ -800,7 +809,7 @@ describe("SessionRunnerLLM", () => {
[ATTR_GEN_AI_CONVERSATION_ID, sessionID],
]),
)
expect(ancestorNames(tool)).toContain("invoke_agent")
expect(ancestorNames(tool).some((name) => name.startsWith("invoke_agent"))).toBeTrue()
expect(ancestorNames(tool)).not.toContain("SessionRunner.attemptStep")
expect(ancestorNames(tool)).not.toContain("chat fake-model")
expect(tool?.status._tag === "Ended" && tool.status.exit._tag).toBe("Success")
@ -841,7 +850,7 @@ describe("SessionRunnerLLM", () => {
]
yield* session.resume(child.id)
const agent = spans.find((span) => span.name === "invoke_agent")
const agent = spans.find((span) => span.name === "invoke_agent explore")
const tool = spans.find((span) => span.name === "execute_tool echo")
expect(agent?.attributes).toMatchObject(
new Map([
@ -858,7 +867,7 @@ describe("SessionRunnerLLM", () => {
[ATTR_OPENCODE_SESSION_PARENT_ID, sessionID],
]),
)
expect(ancestorNames(tool)).toContain("invoke_agent")
expect(ancestorNames(tool).some((name) => name.startsWith("invoke_agent"))).toBeTrue()
}),
)
@ -1686,7 +1695,7 @@ describe("SessionRunnerLLM", () => {
expect(requests).toHaveLength(2)
expect(
spans
.filter((span) => span.name === "invoke_agent")
.filter((span) => span.name.startsWith("invoke_agent"))
.at(-1)
?.events.find(([name]) => name === EVENT_OPENCODE_COMPACTION_COMPLETED)?.[2],
).toMatchObject({ [ATTR_OPENCODE_COMPACTION_REASON]: "automatic" })
@ -2480,6 +2489,11 @@ describe("SessionRunnerLLM", () => {
expect(userTexts(requests[0]!)).toEqual(["Start working"])
expect(userTexts(requests[1]!)).toEqual(["Start working", "Queue first"])
expect(userTexts(requests[2]!)).toEqual(["Start working", "Queue first", "Queue second"])
const turns = spans.filter((span) => span.name === "invoke_agent build")
expect(turns).toHaveLength(3)
expect(new Set(turns.map((span) => span.traceId)).size).toBe(3)
expect(turns[1]?.links.at(-1)?.span).toBe(turns[0])
expect(turns[2]?.links.at(-1)?.span).toBe(turns[1])
}),
)
@ -3310,7 +3324,7 @@ describe("SessionRunnerLLM", () => {
{ type: "assistant", finish: "error", error: { type: "aborted", message: "Step interrupted" } },
])
expect(yield* recordedEventTypes(sessionID)).toContain("session.step.failed.1")
const agent = spans.find((span) => span.name === "invoke_agent")
const agent = spans.find((span) => span.name.startsWith("invoke_agent"))
expect(agent?.attributes.get(ATTR_ERROR_TYPE)).toBe("canceled")
expect(agent?.status._tag === "Ended" && agent.status.exit._tag).toBe("Failure")
yield* session.interrupt(sessionID)
@ -3591,7 +3605,7 @@ describe("SessionRunnerLLM", () => {
expect(eventTypes).toContain("session.retry.scheduled.1")
expect(
spans
.find((span) => span.name === "invoke_agent")
.find((span) => span.name.startsWith("invoke_agent"))
?.events.find(([name]) => name === EVENT_OPENCODE_RETRY_SCHEDULED)?.[2],
).toMatchObject({
[ATTR_OPENCODE_RETRY_ATTEMPT]: 2,
@ -3602,7 +3616,9 @@ describe("SessionRunnerLLM", () => {
[ATTR_ERROR_TYPE]: "provider.transport",
})
expect(eventTypes.filter((type) => type === "session.step.started.1")).toHaveLength(2)
expect(spans.find((span) => span.name === "invoke_agent")?.attributes.has(ATTR_OPENCODE_ERROR_STAGE)).toBeFalse()
expect(
spans.find((span) => span.name.startsWith("invoke_agent"))?.attributes.has(ATTR_OPENCODE_ERROR_STAGE),
).toBeFalse()
expect(yield* session.context(sessionID)).toMatchObject([
{ type: "user" },
{ type: "assistant", finish: "stop", content: [{ type: "text", text: "Recovered" }] },
@ -3660,7 +3676,7 @@ describe("SessionRunnerLLM", () => {
])
expect(
spans
.find((span) => span.name === "invoke_agent")
.find((span) => span.name.startsWith("invoke_agent"))
?.events.find(([name]) => name === EVENT_OPENCODE_RETRY_STOPPED)?.[2],
).toMatchObject({
[ATTR_OPENCODE_RETRY_DECISION]: "exhausted",
@ -3669,7 +3685,7 @@ describe("SessionRunnerLLM", () => {
})
expect((yield* recordedEventTypes(sessionID)).filter((type) => type === "session.step.started.1")).toHaveLength(5)
expect((yield* session.context(sessionID)).filter((message) => message.type === "assistant")).toHaveLength(1)
const agent = spans.find((span) => span.name === "invoke_agent")
const agent = spans.find((span) => span.name.startsWith("invoke_agent"))
expect(agent?.attributes.get(ATTR_ERROR_TYPE)).toBe("provider.transport")
expect(agent?.attributes.get(ATTR_OPENCODE_ERROR_SOURCE)).toBe("provider")
expect(agent?.attributes.get(ATTR_OPENCODE_ERROR_STAGE)).toBe("model")

View file

@ -1,6 +1,7 @@
import { describe, expect } from "bun:test"
import { DateTime, Effect, Layer, Schema, Tracer } from "effect"
import {
ATTR_OPENCODE_LINK_TYPE,
ATTR_OPENCODE_SUBAGENT_AGENT_NAME,
ATTR_OPENCODE_SUBAGENT_SESSION_ID,
} from "@opencode-ai/core/observability/semconv"
@ -36,7 +37,11 @@ const childText = "child final response"
const childModel = ModelV2.Ref.make({ id: ModelV2.ID.make("child"), providerID: ProviderV2.ID.make("test") })
const parentModel = ModelV2.Ref.make({ id: ModelV2.ID.make("parent"), providerID: ProviderV2.ID.make("test") })
const tokens = { input: 0, output: 0, reasoning: 0, cache: { read: 0, write: 0 } }
let resumedWith: Tracer.AnySpan | undefined
const resumedContexts: Array<{
readonly sessionID: SessionV2.ID
readonly parent: Tracer.AnySpan | null | undefined
readonly links: ReadonlyArray<Tracer.SpanLink>
}> = []
const outputSessionID = (value: unknown) => Schema.decodeUnknownSync(SubagentTool.Output)(value).sessionID
@ -85,7 +90,11 @@ const executionNode = makeGlobalNode({
active: Effect.succeed(new Set()),
resume: (sessionID) =>
Effect.gen(function* () {
resumedWith = (yield* SessionTelemetry.TraceParent) ?? undefined
resumedContexts.push({
sessionID,
parent: yield* SessionTelemetry.TraceParent,
links: yield* SessionTelemetry.TraceLinks,
})
return yield* complete(sessionID)
}),
wake: () => Effect.void,
@ -153,6 +162,7 @@ describe("SubagentTool", () => {
const locations = yield* LocationServiceMap.Service
const registry = yield* ToolRegistry.Service.pipe(Effect.provide(locations.get(parent.location)))
yield* waitForTool(registry, SubagentTool.name)
resumedContexts.length = 0
expect((yield* registry.materialize({ model: testModel })).definitions.map((tool) => tool.name)).toContain(
SubagentTool.name,
)
@ -218,7 +228,9 @@ describe("SubagentTool", () => {
const span = spans.find((span) => span.name === "execute_tool subagent")
expect(span?.attributes.get(ATTR_OPENCODE_SUBAGENT_AGENT_NAME)).toBe("reviewer")
expect(span?.attributes.get(ATTR_OPENCODE_SUBAGENT_SESSION_ID)).toBe(child.id)
expect(resumedWith?.spanId).toBe(span?.spanId)
const resumed = resumedContexts.find((context) => context.sessionID === child.id)
expect(resumed?.parent?.spanId).toBe(span?.spanId)
expect(resumed?.links).toEqual([])
const fallback = yield* settleTool(registry, {
sessionID: parent.id,
@ -283,7 +295,7 @@ describe("SubagentTool", () => {
const locations = yield* LocationServiceMap.Service
const registry = yield* ToolRegistry.Service.pipe(Effect.provide(locations.get(parent.location)))
yield* waitForTool(registry, SubagentTool.name)
resumedWith = undefined
resumedContexts.length = 0
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
@ -311,7 +323,14 @@ describe("SubagentTool", () => {
expect(synthetic).toHaveLength(1)
expect(synthetic[0]?.text).toContain(`<subagent id="${childID}" state="completed"`)
expect(synthetic[0]?.text).toContain(childText)
expect(resumedWith).toBeUndefined()
const resumed = resumedContexts.find((context) => context.sessionID === childID)
expect(resumed?.parent).toBeNull()
const span = spans.find((span) => span.name === "execute_tool subagent")
expect(span).toBeDefined()
if (!span) return
expect(resumed?.links).toHaveLength(1)
expect(resumed?.links[0]?.span.spanId).toBe(span.spanId)
expect(resumed?.links[0]?.attributes[ATTR_OPENCODE_LINK_TYPE]).toBe("subagent")
}),
),
),