feat(observability): refine span linkage and telemetry

This commit is contained in:
starptech 2026-07-08 21:33:46 +02:00
parent a2e640aef9
commit 0b9f1a47c6
6 changed files with 289 additions and 30 deletions

View file

@ -714,13 +714,21 @@ const layer = Layer.effect(
readonly force: boolean
}) {
const run = Effect.gen(function* () {
yield* AgentTelemetry.stage("compaction", runPendingCompaction(input.sessionID))
const hasSteer = yield* AgentTelemetry.stage("input", SessionInput.hasPending(db, input.sessionID, "steer"))
const hasQueue = hasSteer
? false
: yield* AgentTelemetry.stage("input", SessionInput.hasPending(db, input.sessionID, "queue"))
if (yield* SessionInput.pendingCompaction(db, input.sessionID)) {
const compactionAgent = yield* agents.select((yield* getSession(input.sessionID)).agent)
yield* AgentTelemetry.invoke(
{
sessionID: input.sessionID,
agent: compactionAgent.id,
errorType: (cause) => toSessionError(cause).type,
},
AgentTelemetry.stage("compaction", runPendingCompaction(input.sessionID)),
)
}
const hasSteer = yield* SessionInput.hasPending(db, input.sessionID, "steer")
const hasQueue = hasSteer ? false : yield* SessionInput.hasPending(db, input.sessionID, "queue")
if (!input.force && !hasSteer && !hasQueue) return
yield* AgentTelemetry.stage("tool_recovery", failInterruptedTools(input.sessionID))
yield* failInterruptedTools(input.sessionID)
let promotion: SessionInput.Delivery | undefined = hasSteer ? "steer" : hasQueue ? "queue" : undefined
let trigger: AgentTelemetry.ModelCallTrigger = hasSteer || hasQueue ? "input" : "resume"
let shouldRun = input.force || hasSteer || hasQueue

View file

@ -3,13 +3,18 @@ import { NodeFileSystem } from "@effect/platform-node"
import {
ATTR_DEPLOYMENT_ENVIRONMENT_NAME,
ATTR_ERROR_TYPE,
ATTR_GEN_AI_CONVERSATION_ID,
ATTR_OPENCODE_ERROR_SOURCE,
ATTR_OPENCODE_ERROR_STAGE,
ATTR_OPENCODE_LINK_TYPE,
ATTR_OPENCODE_CLIENT,
ATTR_OPENCODE_RUN,
ATTR_OPENCODE_TOOL_OUTCOME,
ATTR_SERVICE_INSTANCE_ID,
ATTR_SERVICE_NAMESPACE,
ATTR_URL_FULL,
} from "@opencode-ai/core/observability/semconv"
import { Cause, Deferred, Effect, Fiber, Layer, Logger, Option, Tracer } from "effect"
import { Cause, Deferred, Effect, Exit, 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"
@ -198,6 +203,38 @@ it.effect("links each agent turn to the previous Session turn", () =>
}),
)
it.effect("keeps previous-turn links isolated by Session", () =>
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 = (sessionID: string) =>
telemetry
.drain(
sessionID,
AgentTelemetry.invoke({ sessionID, agent: "build", errorType: () => "unknown" }, Effect.void),
)
.pipe(Effect.provideService(Tracer.Tracer, tracer))
yield* run("a")
yield* run("b")
yield* run("a")
const a = spans.filter((span) => span.attributes.get(ATTR_GEN_AI_CONVERSATION_ID) === "a")
const b = spans.filter((span) => span.attributes.get(ATTR_GEN_AI_CONVERSATION_ID) === "b")
expect(a).toHaveLength(2)
expect(b).toHaveLength(1)
expect(a[1]?.links[0]?.span).toBe(a[0])
expect(b[0]?.links).toEqual([])
}),
)
it.effect("closes an active agent span when its execution scope is interrupted", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
@ -240,7 +277,7 @@ it.effect("classifies a tool cause containing interruption as canceled", () =>
Cause.makeInterruptReason(),
])
yield* ToolTelemetry.execute(
const exit = yield* ToolTelemetry.execute(
{ sessionID: "session", agent: "explore", call: { id: "call", name: "read" } },
Effect.failCause(cause),
() => "tool.execution",
@ -248,7 +285,14 @@ it.effect("classifies a tool cause containing interruption as canceled", () =>
const span = spans.find((span) => span.name === "execute_tool read")
expect(span?.attributes.get(ATTR_ERROR_TYPE)).toBe("canceled")
expect(span?.attributes.get(ATTR_OPENCODE_ERROR_SOURCE)).toBe("cancellation")
expect(span?.attributes.get(ATTR_OPENCODE_ERROR_STAGE)).toBe("execution")
expect(span?.attributes.get(ATTR_OPENCODE_TOOL_OUTCOME)).toBe("canceled")
expect(span?.status._tag === "Ended" && span.status.exit._tag).toBe("Failure")
expect(Exit.isFailure(exit) && Cause.hasInterrupts(exit.cause)).toBeTrue()
expect(Exit.isFailure(exit) ? Option.getOrUndefined(Cause.findErrorOption(exit.cause)) : undefined).toBeInstanceOf(
Error,
)
}),
)
@ -270,6 +314,36 @@ it.effect("applies HTTP response validation without a parent span", () =>
}),
)
it.effect("omits URL credentials, query, and fragment without changing the request", () =>
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 url = "https://user:password@example.test/path?region=us-east-1#fragment"
let executedUrl: string | undefined
const request = HttpClientRequest.get(url)
const http = HttpClient.make((request) => {
executedUrl = request.url
return Effect.succeed(HttpClientResponse.fromWeb(request, new Response("ok")))
})
yield* HttpTelemetry.use(http, request, Effect.succeed).pipe(
Effect.withSpan("execute_tool webfetch"),
Effect.provideService(Tracer.Tracer, tracer),
)
expect(executedUrl).toBe(url)
expect(spans.find((span) => span.name === "GET")?.attributes.get(ATTR_URL_FULL)).toBe(
"https://example.test/path",
)
}),
)
test("falls back to local logging when OTLP initialization fails", async () => {
const dir = await fs.mkdtemp(path.join(os.tmpdir(), "opencode-observability-test-"))
await using _ = {

View file

@ -39,7 +39,10 @@ import {
ATTR_OPENCODE_SESSION_INPUT_COUNT,
ATTR_OPENCODE_SESSION_INPUT_DELIVERY,
ATTR_OPENCODE_SESSION_PARENT_ID,
ATTR_OPENCODE_TOOL_OUTCOME,
EVENT_OPENCODE_COMPACTION_FAILED,
EVENT_OPENCODE_COMPACTION_COMPLETED,
EVENT_OPENCODE_COMPACTION_STARTED,
EVENT_OPENCODE_RETRY_SCHEDULED,
EVENT_OPENCODE_RETRY_STOPPED,
EVENT_OPENCODE_SESSION_INPUT_PROMOTED,
@ -809,6 +812,7 @@ describe("SessionRunnerLLM", () => {
[ATTR_GEN_AI_CONVERSATION_ID, sessionID],
]),
)
expect(tool?.attributes.get(ATTR_OPENCODE_TOOL_OUTCOME)).toBe("completed")
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")
@ -904,6 +908,7 @@ describe("SessionRunnerLLM", () => {
expect(tools[0]?.attributes.get(ATTR_OPENCODE_AGENT_STEP_TRIGGER)).toBe("input")
expect(tools[1]?.attributes.get(ATTR_OPENCODE_AGENT_STEP_INDEX)).toBe(2)
expect(tools[1]?.attributes.get(ATTR_OPENCODE_AGENT_STEP_TRIGGER)).toBe("tool_result")
expect(spans.filter((span) => span.name === "invoke_agent build")).toHaveLength(1)
}),
)
@ -926,6 +931,9 @@ describe("SessionRunnerLLM", () => {
const tool = spans.find((span) => span.name === "execute_tool echo")
expect(tool?.attributes.get(ATTR_ERROR_TYPE)).toBe("tool.execution")
expect(tool?.attributes.get(ATTR_OPENCODE_ERROR_SOURCE)).toBe("tool")
expect(tool?.attributes.get(ATTR_OPENCODE_ERROR_STAGE)).toBe("execution")
expect(tool?.attributes.get(ATTR_OPENCODE_TOOL_OUTCOME)).toBe("error")
expect(tool?.status._tag === "Ended" && tool.status.exit._tag).toBe("Failure")
requests.length = 0
spans.length = 0
@ -1587,6 +1595,10 @@ describe("SessionRunnerLLM", () => {
status: "completed",
summary: "durable summary",
})
const turn = spans.find((span) => span.name === "invoke_agent build")
expect(turn?.events.map(([name]) => name)).toEqual(
expect.arrayContaining([EVENT_OPENCODE_COMPACTION_STARTED, EVENT_OPENCODE_COMPACTION_COMPLETED]),
)
}),
)
@ -1627,6 +1639,10 @@ describe("SessionRunnerLLM", () => {
(type) => type === EventV2.versionedType(SessionEvent.Compaction.Failed.type, 1),
),
).toHaveLength(1)
const turn = spans.find((span) => span.name === "invoke_agent build")
expect(turn?.events.map(([name]) => name)).toEqual(
expect.arrayContaining([EVENT_OPENCODE_COMPACTION_STARTED, EVENT_OPENCODE_COMPACTION_FAILED]),
)
}),
)
@ -1650,6 +1666,10 @@ describe("SessionRunnerLLM", () => {
(type) => type === EventV2.versionedType(SessionEvent.Compaction.Failed.type, 1),
),
).toHaveLength(1)
const turn = spans.find((span) => span.name === "invoke_agent build")
expect(turn?.events.map(([name]) => name)).toEqual(
expect.arrayContaining([EVENT_OPENCODE_COMPACTION_STARTED, EVENT_OPENCODE_COMPACTION_FAILED]),
)
}),
)
@ -1673,6 +1693,10 @@ describe("SessionRunnerLLM", () => {
(type) => type === EventV2.versionedType(SessionEvent.Compaction.Failed.type, 1),
),
).toHaveLength(1)
const turn = spans.find((span) => span.name === "invoke_agent build")
expect(turn?.events.map(([name]) => name)).toEqual(
expect.arrayContaining([EVENT_OPENCODE_COMPACTION_STARTED, EVENT_OPENCODE_COMPACTION_FAILED]),
)
}),
)
@ -2368,6 +2392,7 @@ describe("SessionRunnerLLM", () => {
"user",
"assistant",
])
expect(spans.filter((span) => span.name === "invoke_agent build")).toHaveLength(1)
}),
)
@ -2396,6 +2421,9 @@ describe("SessionRunnerLLM", () => {
expect(userTexts(requests[0]!)).toEqual(["Start working"])
expect(userTexts(requests[1]!)).toEqual(["Start working"])
expect(userTexts(requests[2]!)).toEqual(["Start working", "Wait until continuation ends"])
const turns = spans.filter((span) => span.name === "invoke_agent build")
expect(turns).toHaveLength(2)
expect(turns[1]?.links.at(-1)?.span).toBe(turns[0])
}),
)
@ -3625,6 +3653,7 @@ describe("SessionRunnerLLM", () => {
])
yield* replaySessionProjection(sessionID)
expect((yield* session.context(sessionID)).filter((message) => message.type === "assistant")).toHaveLength(1)
expect(spans.filter((span) => span.name === "invoke_agent build")).toHaveLength(1)
}),
)
@ -3642,6 +3671,14 @@ describe("SessionRunnerLLM", () => {
yield* TestClock.adjust("1 millis")
yield* Fiber.join(run)
expect(requests).toHaveLength(2)
expect(
spans
.find((span) => span.name === "invoke_agent build")
?.events.find(([name]) => name === EVENT_OPENCODE_RETRY_SCHEDULED)?.[2],
).toMatchObject({
[ATTR_OPENCODE_RETRY_DELAY_MS]: 5_000,
[ATTR_OPENCODE_RETRY_DELAY_SOURCE]: "max(backoff,retry_after)",
})
}),
)
@ -3721,6 +3758,11 @@ describe("SessionRunnerLLM", () => {
expect(eventTypes.filter((type) => type === "session.step.started.1")).toHaveLength(2)
expect(eventTypes.filter((type) => type === "session.retry.scheduled.1")).toHaveLength(1)
expect((yield* session.context(sessionID)).filter((message) => message.type === "assistant")).toHaveLength(1)
expect(
spans
.find((span) => span.name === "invoke_agent build")
?.events.find(([name]) => name === EVENT_OPENCODE_RETRY_STOPPED)?.[2],
).toMatchObject({ [ATTR_OPENCODE_RETRY_DECISION]: "step_limit" })
}),
)
@ -3734,6 +3776,11 @@ describe("SessionRunnerLLM", () => {
expect(yield* session.resume(sessionID).pipe(Effect.flip)).toBe(failure)
expect(requests).toHaveLength(1)
expect(yield* recordedEventTypes(sessionID)).not.toContain("session.retry.scheduled.1")
expect(
spans
.find((span) => span.name === "invoke_agent build")
?.events.find(([name]) => name === EVENT_OPENCODE_RETRY_STOPPED)?.[2],
).toMatchObject({ [ATTR_OPENCODE_RETRY_DECISION]: "non_retryable" })
}),
)

View file

@ -1,7 +1,7 @@
import { describe, expect } from "bun:test"
import { Cause, Clock, Effect, References, Stream, Tracer } from "effect"
import { Cause, Clock, Deferred, Effect, Fiber, References, Stream, Tracer } from "effect"
import * as TestClock from "effect/testing/TestClock"
import { FetchHttpClient } from "effect/unstable/http"
import { FetchHttpClient, HttpClientRequest } from "effect/unstable/http"
import { LLM, LLMEvent, Message, Usage } from "../src"
import * as OpenAIChat from "../src/protocols/openai-chat"
import * as OpenAIResponses from "../src/protocols/openai-responses"
@ -43,6 +43,8 @@ import {
GEN_AI_OPERATION_NAME_VALUE_CHAT,
} from "../src/semconv"
import { RequestIssued, ResponseChunkReceived, stream as instrument } from "../src/telemetry"
import { LLMHttpTelemetry } from "../src/telemetry/http"
import { LLMWebSocketTelemetry } from "../src/telemetry/websocket"
const ATTR_AGENT_STEP_INDEX = "test.agent.step.index"
const ATTR_AGENT_STEP_TRIGGER = "test.agent.step.trigger"
@ -172,6 +174,7 @@ describe("GenAI telemetry", () => {
expect(http?.attributes.get(ATTR_HTTP_RESPONSE_STATUS_CODE)).toBe(200)
expect(http?.attributes.get(ATTR_SERVER_PORT)).toBe(443)
expect(http?.attributes.get(ATTR_URL_FULL)).toStartWith("https://api.openai.test/")
expect(http?.attributes.get(ATTR_URL_FULL)).not.toContain("?")
expect(http?.attributes.get(ATTR_URL_FULL)).not.toContain("secret-key")
expect(http?.attributes.get(ATTR_URL_FULL)).not.toContain("short-key")
expect(http?.attributes.get(ATTR_URL_FULL)).not.toContain("signed-value")
@ -286,6 +289,98 @@ describe("GenAI telemetry", () => {
}),
)
it.effect("requires an explicit model span for transport instrumentation", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []
const tracer = Tracer.make({
span(options) {
const span = new Tracer.NativeSpan(options)
spans.push(span)
return span
},
})
yield* Effect.useSpan("ambient", () =>
Effect.all(
[
LLMHttpTelemetry.stream(HttpClientRequest.post("https://example.test/path"), Stream.empty).pipe(
Stream.runDrain,
),
LLMWebSocketTelemetry.stream("wss://example.test/path", Stream.empty).pipe(Stream.runDrain),
],
{ discard: true },
),
).pipe(Effect.provideService(Tracer.Tracer, tracer))
expect(spans.map((span) => span.name)).toEqual(["ambient"])
}),
)
it.effect("does not attribute downstream consumer failures to transports", () =>
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 model = OpenAIChat.route
.with({ endpoint: { baseURL: "https://api.openai.test/v1" } })
.model({ id: "consumer-failure-model" })
const failure = new Error("consumer failed")
const error = yield* LLMClient.stream(LLM.request({ model, prompt: "secret" })).pipe(
Stream.runForEach(() => Effect.fail(failure)),
Effect.provide(fixedResponse(sseEvents(deltaChunk({ role: "assistant", content: "Hello" })))),
Effect.flip,
Effect.provideService(Tracer.Tracer, tracer),
)
expect(error).toBe(failure)
const modelSpan = spans.find((span) => span.name === "chat consumer-failure-model")
const httpSpan = spans.find((span) => span.attributes.get(ATTR_HTTP_REQUEST_METHOD) === "POST")
expect(modelSpan?.attributes.get(ATTR_ERROR_TYPE)).toBe("incomplete_response")
expect(httpSpan?.attributes.has(ATTR_ERROR_TYPE)).toBeFalse()
expect(httpSpan?.status._tag === "Ended" && httpSpan.status.exit._tag).toBe("Success")
}),
)
it.effect("closes a model span when its stream fiber 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>()
const model = OpenAIChat.route
.with({ endpoint: { baseURL: "https://api.openai.test/v1" } })
.model({ id: "interrupted-model" })
const source = Stream.concat(
Stream.fromEffect(Deferred.succeed(started, undefined).pipe(Effect.as(LLMEvent.stepStart({ index: 0 })))),
Stream.never,
)
yield* Effect.gen(function* () {
const fiber = yield* instrument(LLM.request({ model, prompt: "secret" }), source).pipe(
Stream.runDrain,
Effect.forkChild,
)
yield* Deferred.await(started)
yield* Fiber.interrupt(fiber)
}).pipe(Effect.provideService(Tracer.Tracer, tracer))
const span = spans.find((span) => span.name === "chat interrupted-model")
expect(span?.attributes.get(ATTR_ERROR_TYPE)).toBe("canceled")
expect(span?.status._tag === "Ended" && span.status.exit._tag).toBe("Failure")
}),
)
it.effect("measures first-chunk latency from request issuance", () =>
Effect.gen(function* () {
const spans: Tracer.NativeSpan[] = []

View file

@ -0,0 +1,32 @@
import { expect, test } from "bun:test"
import { NodeServices } from "@effect/platform-node"
import { Context, Effect, Layer, References } from "effect"
import { HttpMiddleware, HttpServer, HttpServerRequest } from "effect/unstable/http"
test("route construction retains the server tracing policy", async () => {
const database = process.env.OPENCODE_DB
const endpoint = process.env.OTEL_EXPORTER_OTLP_ENDPOINT
delete process.env.OTEL_EXPORTER_OTLP_ENDPOINT
process.env.OPENCODE_DB = ":memory:"
try {
const { createEmbeddedRoutes } = await import("../src/routes")
await Effect.gen(function* () {
const context = yield* Layer.build(
createEmbeddedRoutes().pipe(
Layer.provide(HttpServer.layerServices),
Layer.provide(NodeServices.layer),
),
)
const request = HttpServerRequest.fromWeb(new Request("http://opencode.local/api/session"))
expect(Context.get(context, References.TracerEnabled)).toBeFalse()
expect(Context.get(context, HttpMiddleware.TracerDisabledWhen)(request)).toBeTrue()
}).pipe(Effect.scoped, Effect.runPromise)
} finally {
if (database === undefined) delete process.env.OPENCODE_DB
else process.env.OPENCODE_DB = database
if (endpoint === undefined) delete process.env.OTEL_EXPORTER_OTLP_ENDPOINT
else process.env.OTEL_EXPORTER_OTLP_ENDPOINT = endpoint
}
})

View file

@ -72,30 +72,33 @@ The `experimental.openTelemetry` configuration option only controls AI SDK telem
### Navigate conversations
Each agent turn is a separate trace. Use the Session ID in `gen_ai.conversation.id` to find the full conversation. In Dash0, also filter `gen_ai.operation.name = invoke_agent` to show turn roots, then sort by start time. **Links to** opens the previous turn; **Linked from** opens the next turn. The oldest turn has no `previous_turn` link.
Each agent turn is exported as a separate trace.
List conversation turns with the Dash0 CLI:
1. In Dash0, filter by `gen_ai.conversation.id = <session-id>` and `gen_ai.operation.name = invoke_agent`, then sort by start time.
2. List turn traces with the Dash0 CLI:
```bash
dash0 spans query \
--dataset production \
--from now-4h \
--filter "gen_ai.conversation.id is <session-id>" \
--filter "gen_ai.operation.name is invoke_agent" \
--column timestamp \
--column "span name" \
--column "trace id" \
--column "span links"
```
```bash
dash0 spans query \
--dataset production \
--from now-4h \
--filter "gen_ai.conversation.id is <session-id>" \
--filter "gen_ai.operation.name is invoke_agent" \
--column timestamp \
--column "span name" \
--column "trace id" \
--column "span links"
```
Follow links from the newest turn:
3. Follow links from the newest turn:
```bash
dash0 traces get <trace-id> \
--dataset production \
--from now-4h \
--follow-span-links
```
```bash
dash0 traces get <trace-id> \
--dataset production \
--from now-4h \
--follow-span-links
```
4. Use **Links to** for the previous turn and **Linked from** for the next. The oldest observed turn has no `previous_turn` link.
Foreground subagents are child spans in the spawning turn. Background subagents use linked traces with `opencode.link.type=subagent`; turn links use `opencode.link.type=previous_turn`. Links are process-local, so use `gen_ai.conversation.id` across restarts.