diff options
| author | Adam Malczewski <[email protected]> | 2026-06-05 14:29:06 +0900 |
|---|---|---|
| committer | Adam Malczewski <[email protected]> | 2026-06-05 14:29:06 +0900 |
| commit | 4d94c530406567791dbe4ab06c838a83c2e26023 (patch) | |
| tree | 4e15e5ffee8bf4de68ddac55462aa7dc04e67ee7 /packages/kernel/src/runtime | |
| parent | 9ae09aad5d8d6232c55932af0d496b888166065f (diff) | |
| download | dispatch-4d94c530406567791dbe4ab06c838a83c2e26023.tar.gz dispatch-4d94c530406567791dbe4ab06c838a83c2e26023.zip | |
refactor(observability): pure-types contracts/logging + Span body channel; verbatim before/after -> LogRecord.body (273 tests)
contracts/logging.ts reduced to pure types; createLogger (+ helpers) moved to kernel/src/logging/ — @dispatch/kernel still exports it (host-bin/tool-read-file unaffected).
Span body channel (Option A): Logger.span / Span.child / Span.end accept an optional body string -> SpanOpenRecord.body / SpanCloseRecord.body. Large verbatim payloads now use body, not stringified attributes (store-fat-serve-thin; attributes stay thin/queryable for D9).
before: run-turn emits a 'prompt' span with the verbatim messages+tools in body (small scalars in attrs). after: provider.request span carries the verbatim request in body; attrs thin, auth self-redacted.
Verified: tsc -b clean, 273 tests, biome 0 warnings/0 infos. Live boot: prompt + provider.request bodies present and correlated (shared turnId); request.body no longer in attributes; auth-key leak count = 0.
Diffstat (limited to 'packages/kernel/src/runtime')
| -rw-r--r-- | packages/kernel/src/runtime/run-turn.test.ts | 52 | ||||
| -rw-r--r-- | packages/kernel/src/runtime/run-turn.ts | 25 |
2 files changed, 63 insertions, 14 deletions
diff --git a/packages/kernel/src/runtime/run-turn.test.ts b/packages/kernel/src/runtime/run-turn.test.ts index 667476f..9c19027 100644 --- a/packages/kernel/src/runtime/run-turn.test.ts +++ b/packages/kernel/src/runtime/run-turn.test.ts @@ -2,9 +2,9 @@ import { describe, expect, it } from "vitest"; import type { ChatMessage } from "../contracts/conversation.js"; import type { AgentEvent } from "../contracts/events.js"; import type { LogDeps, Logger, LogRecord, LogSink } from "../contracts/logging.js"; -import { createLogger } from "../contracts/logging.js"; import type { ProviderContract, ProviderEvent } from "../contracts/provider.js"; import type { ToolContract, ToolExecuteContext, ToolResult } from "../contracts/tool.js"; +import { createLogger } from "../logging/logger.js"; import { runTurn } from "./run-turn.js"; function delay(ms: number): Promise<void> { @@ -1039,6 +1039,56 @@ describe("runTurn", () => { expect(stepCloses[0].attributes?.["error.message"]).toContain("provider exploded"); } }); + + it("emits a prompt span with verbatim body and small scalar attributes", async () => { + const tool = createFakeTool("echo", async () => ({ content: "echoed" })); + + const provider = createFakeProvider([ + [ + { type: "text-delta", delta: "done" }, + { type: "finish", reason: "stop" }, + ], + ]); + + const { logger, sink } = createTestLogger(); + + await runTurn({ + provider, + messages: [userMessage], + tools: [tool], + dispatch: { maxConcurrent: 1, eager: false }, + conversationId: "conv-1", + turnId: "turn-1", + emit: () => {}, + logger, + }); + + const promptOpens = sink.records.filter((r) => r.kind === "span-open" && r.name === "prompt"); + expect(promptOpens).toHaveLength(1); + + const promptOpen = promptOpens[0]; + if (promptOpen?.kind === "span-open") { + expect(promptOpen.body).toBeDefined(); + const parsed = JSON.parse(promptOpen.body as string); + expect(parsed.messages).toEqual([userMessage]); + expect(parsed.tools).toHaveLength(1); + expect(parsed.tools[0].name).toBe("echo"); + + expect(promptOpen.attributes?.messageCount).toBe(1); + expect(promptOpen.attributes?.toolCount).toBe(1); + } + + const promptCloses = sink.records.filter( + (r) => r.kind === "span-close" && r.name === "prompt", + ); + expect(promptCloses).toHaveLength(1); + + const logRecords = sink.records.filter( + (r) => + r.kind === "log" && r.kind === "log" && (r as { msg: string }).msg === "prompt:before", + ); + expect(logRecords).toHaveLength(0); + }); }); describe("provider logger threading", () => { diff --git a/packages/kernel/src/runtime/run-turn.ts b/packages/kernel/src/runtime/run-turn.ts index a78c31d..5e60641 100644 --- a/packages/kernel/src/runtime/run-turn.ts +++ b/packages/kernel/src/runtime/run-turn.ts @@ -167,22 +167,21 @@ async function executeStep(ctx: StepContext): Promise<StepResult> { let stepUsage = zeroUsage(); let finishReason = "stop"; - // Open a step span with the verbatim pre-mutation prompt in its body (BEFORE capture). + // Open a step span; capture the verbatim pre-mutation prompt via a + // "prompt" child span whose body holds the serialized messages+tools. let stepSpan: Span | undefined; try { stepSpan = ctx.logger.span("step"); - // Emit the verbatim pre-mutation prompt as a log record on the step span's logger. - // This is the "BEFORE" capture — the messages + tools as handed to provider.stream. - stepSpan.log.info("prompt:before", { - "prompt.messages": JSON.stringify(ctx.messages), - "prompt.tools": JSON.stringify( - ctx.tools.map((t) => ({ - name: t.name, - description: t.description, - parameters: t.parameters, - })), - ), - }); + const promptBody = JSON.stringify({ messages: ctx.messages, tools: ctx.tools }); + const promptSpan = stepSpan.child( + "prompt", + { + messageCount: ctx.messages.length, + toolCount: ctx.tools.length, + }, + promptBody, + ); + promptSpan.end(); } catch { // Swallow — D7. } |
