diff options
| author | Adam Malczewski <[email protected]> | 2026-06-05 14:06:39 +0900 |
|---|---|---|
| committer | Adam Malczewski <[email protected]> | 2026-06-05 14:06:39 +0900 |
| commit | 9ae09aad5d8d6232c55932af0d496b888166065f (patch) | |
| tree | e62b59314ba065a531f9924151742c5adc7426ef /packages/kernel | |
| parent | 6733bbd47e6df8681fcf4b6815f82bd6b6922334 (diff) | |
| download | dispatch-9ae09aad5d8d6232c55932af0d496b888166065f.tar.gz dispatch-9ae09aad5d8d6232c55932af0d496b888166065f.zip | |
feat(observability): Phase A.2 — verbatim provider.request "after" capture + self-redaction (267 tests)
Threads the step span's correlated logger into provider.stream (new optional ProviderStreamOptions.logger) so provider-openai-compat opens a child provider.request span at the fetch edge, capturing the verbatim post-transform request + response status/cache-tokens/raw-error. Auth header self-redacted in the provider's OWN code (graduated mask tiers; no shared helper). Capture is fail-safe (never throws into the turn). Adds the first hermetic provider HTTP test (stream.test.ts: fetch mocked, 15 cases). Large payloads use attributes for now; the LogRecord.body channel is a deferred ABI design (notes §10).
Verified: tsc -b clean, 267 tests (250->+17), biome 0 warnings/0 infos. Live boot: provider.request shares turnId with prompt:before (before<->after diffable); auth-key leak count = 0 (self-redaction proven on a real request).
Diffstat (limited to 'packages/kernel')
| -rw-r--r-- | packages/kernel/src/contracts/provider.ts | 9 | ||||
| -rw-r--r-- | packages/kernel/src/runtime/run-turn.test.ts | 103 | ||||
| -rw-r--r-- | packages/kernel/src/runtime/run-turn.ts | 7 |
3 files changed, 99 insertions, 20 deletions
diff --git a/packages/kernel/src/contracts/provider.ts b/packages/kernel/src/contracts/provider.ts index 1d0fd75..62dc8e9 100644 --- a/packages/kernel/src/contracts/provider.ts +++ b/packages/kernel/src/contracts/provider.ts @@ -7,6 +7,7 @@ */ import type { ChatMessage } from "./conversation.js"; +import type { Logger } from "./logging.js"; import type { ToolContract } from "./tool.js"; /** @@ -92,6 +93,14 @@ export interface ProviderStreamOptions { readonly maxTokens?: number; /** System prompt to prepend. */ readonly systemPrompt?: string; + /** + * Correlated logger for this turn's step (Phase A logging ABI). When present, + * the provider should open a child `provider.request` span and capture the + * verbatim post-transform request + raw response/error there, self-redacting + * secrets in its own code. Optional so non-instrumented callers/tests still + * compile (the provider falls back to no capture). + */ + readonly logger?: Logger; } /** diff --git a/packages/kernel/src/runtime/run-turn.test.ts b/packages/kernel/src/runtime/run-turn.test.ts index 48f0b5a..667476f 100644 --- a/packages/kernel/src/runtime/run-turn.test.ts +++ b/packages/kernel/src/runtime/run-turn.test.ts @@ -817,26 +817,26 @@ describe("runTurn", () => { } }); - describe("span instrumentation", () => { - function createTestLogger(): { - logger: Logger; - sink: LogSink & { records: LogRecord[] }; - deps: LogDeps; - } { - let idCounter = 0; - const deps: LogDeps = { - now: () => 1000 + idCounter * 100, - newId: () => `span-${++idCounter}`, - }; - const records: LogRecord[] = []; - const sink: LogSink & { records: LogRecord[] } = { - records, - emit: (record) => records.push(record), - }; - const logger = createLogger({ extensionId: "test" }, sink, deps); - return { logger, sink, deps }; - } + function createTestLogger(): { + logger: Logger; + sink: LogSink & { records: LogRecord[] }; + deps: LogDeps; + } { + let idCounter = 0; + const deps: LogDeps = { + now: () => 1000 + idCounter * 100, + newId: () => `span-${++idCounter}`, + }; + const records: LogRecord[] = []; + const sink: LogSink & { records: LogRecord[] } = { + records, + emit: (record) => records.push(record), + }; + const logger = createLogger({ extensionId: "test" }, sink, deps); + return { logger, sink, deps }; + } + describe("span instrumentation", () => { it("emits turn + step span open/close in order", async () => { const provider = createFakeProvider([ [ @@ -1040,4 +1040,69 @@ describe("runTurn", () => { } }); }); + + describe("provider logger threading", () => { + it("passes step span logger to provider.stream opts when logger provided", async () => { + let capturedOpts: Record<string, unknown> | undefined; + + const provider: ProviderContract = { + id: "fake", + stream(_messages, _tools, opts) { + capturedOpts = opts !== undefined ? { ...opts } : undefined; + return (async function* () { + yield { type: "text-delta", delta: "hi" } as ProviderEvent; + yield { type: "usage", usage: { inputTokens: 1, outputTokens: 1 } } as ProviderEvent; + yield { type: "finish", reason: "stop" } as ProviderEvent; + })(); + }, + }; + + const { logger } = createTestLogger(); + + await runTurn({ + provider, + messages: [userMessage], + tools: [], + dispatch: { maxConcurrent: 1, eager: false }, + conversationId: "conv-1", + turnId: "turn-1", + emit: () => {}, + logger, + }); + + expect(capturedOpts).toBeDefined(); + expect(capturedOpts?.logger).toBeDefined(); + expect(typeof (capturedOpts?.logger as Record<string, unknown>).info).toBe("function"); + expect(typeof (capturedOpts?.logger as Record<string, unknown>).span).toBe("function"); + }); + + it("passes undefined for opts.logger when no logger provided", async () => { + let capturedOpts: Record<string, unknown> | undefined; + + const provider: ProviderContract = { + id: "fake", + stream(_messages, _tools, opts) { + capturedOpts = opts !== undefined ? { ...opts } : undefined; + return (async function* () { + yield { type: "text-delta", delta: "hi" } as ProviderEvent; + yield { type: "usage", usage: { inputTokens: 1, outputTokens: 1 } } as ProviderEvent; + yield { type: "finish", reason: "stop" } as ProviderEvent; + })(); + }, + }; + + await runTurn({ + provider, + messages: [userMessage], + tools: [], + dispatch: { maxConcurrent: 1, eager: false }, + conversationId: "conv-1", + turnId: "turn-1", + emit: () => {}, + }); + + expect(capturedOpts).toBeDefined(); + expect(capturedOpts?.logger).toBeUndefined(); + }); + }); }); diff --git a/packages/kernel/src/runtime/run-turn.ts b/packages/kernel/src/runtime/run-turn.ts index 0f42ef3..a78c31d 100644 --- a/packages/kernel/src/runtime/run-turn.ts +++ b/packages/kernel/src/runtime/run-turn.ts @@ -78,6 +78,7 @@ interface StepContext { readonly conversationId: string; readonly turnId: string; readonly logger: Logger; + readonly stepLogger: Logger | undefined; readonly toolSpans: Map<string, Span>; } @@ -197,7 +198,10 @@ async function executeStep(ctx: StepContext): Promise<StepResult> { ); try { - const stream = ctx.provider.stream(ctx.messages, ctx.tools); + const opts = { + ...(ctx.stepLogger !== undefined ? { logger: ctx.stepLogger } : {}), + }; + const stream = ctx.provider.stream(ctx.messages, ctx.tools, opts); for await (const event of stream) { if (ctx.signal.aborted) break; processEvent(event, chunks, toolCalls, dispatcher, ctx); @@ -351,6 +355,7 @@ export async function runTurn(input: RunTurnInput): Promise<RunTurnResult> { conversationId, turnId, logger: turnSpan?.log ?? logger ?? createNoopLogger(), + stepLogger: logger, toolSpans, }); |
