diff options
| author | Adam Malczewski <[email protected]> | 2026-06-26 22:03:19 +0900 |
|---|---|---|
| committer | Adam Malczewski <[email protected]> | 2026-06-26 22:23:39 +0900 |
| commit | 727c98c9dae516a2070eb950410314380a20c974 (patch) | |
| tree | 52aa1022c54f11770be7e4e2a324f0a8b8b8deec /packages/kernel/src/logging | |
| parent | e59dc11f63b1df51142259bb2c406af8c9c8c2bb (diff) | |
| download | dispatch-727c98c9dae516a2070eb950410314380a20c974.tar.gz dispatch-727c98c9dae516a2070eb950410314380a20c974.zip | |
style: switch from tabs to 2-space indentation
Diffstat (limited to 'packages/kernel/src/logging')
| -rw-r--r-- | packages/kernel/src/logging/logger.test.ts | 64 | ||||
| -rw-r--r-- | packages/kernel/src/logging/logger.ts | 516 |
2 files changed, 290 insertions, 290 deletions
diff --git a/packages/kernel/src/logging/logger.test.ts b/packages/kernel/src/logging/logger.test.ts index 5d7bf45..783d5af 100644 --- a/packages/kernel/src/logging/logger.test.ts +++ b/packages/kernel/src/logging/logger.test.ts @@ -3,43 +3,43 @@ import type { LogDeps, LogRecord, LogSink } from "../contracts/logging.js"; import { createLogger } from "./logger.js"; function harness() { - let idCounter = 0; - const deps: LogDeps = { - now: () => 1000 + idCounter * 10, - newId: () => `span-${++idCounter}`, - }; - const records: LogRecord[] = []; - const sink: LogSink = { emit: (r) => records.push(r) }; - return { logger: createLogger({ extensionId: "test" }, sink, deps), records }; + let idCounter = 0; + const deps: LogDeps = { + now: () => 1000 + idCounter * 10, + newId: () => `span-${++idCounter}`, + }; + const records: LogRecord[] = []; + const sink: LogSink = { emit: (r) => records.push(r) }; + return { logger: createLogger({ extensionId: "test" }, sink, deps), records }; } describe("createLogger child-bound attributes", () => { - it("merges child-bound attrs into BOTH span-open and span-close records", () => { - const { logger, records } = harness(); - // Bind `warm: true` via child() — mirrors the cache-warming capture path. - const warmLogger = logger.child({ conversationId: "c1", attrs: { warm: true } }); + it("merges child-bound attrs into BOTH span-open and span-close records", () => { + const { logger, records } = harness(); + // Bind `warm: true` via child() — mirrors the cache-warming capture path. + const warmLogger = logger.child({ conversationId: "c1", attrs: { warm: true } }); - const span = warmLogger.span("provider.request", { model: "x" }); - span.end({ attrs: { "usage.cacheReadTokens": 0 } }); + const span = warmLogger.span("provider.request", { model: "x" }); + span.end({ attrs: { "usage.cacheReadTokens": 0 } }); - const open = records.find((r) => r.kind === "span-open"); - const close = records.find((r) => r.kind === "span-close"); + const open = records.find((r) => r.kind === "span-open"); + const close = records.find((r) => r.kind === "span-close"); - // Open carries the bound attr (pre-existing behavior). - expect(open?.attributes?.warm).toBe(true); - // Close MUST carry it too, so a `warm = true` query finds the closed span - // (with its usage/status) — not just the open record. - expect(close?.attributes?.warm).toBe(true); - // Span-specific attrs from span()/end() are still present on close. - expect(close?.attributes?.model).toBe("x"); - expect(close?.attributes?.["usage.cacheReadTokens"]).toBe(0); - }); + // Open carries the bound attr (pre-existing behavior). + expect(open?.attributes?.warm).toBe(true); + // Close MUST carry it too, so a `warm = true` query finds the closed span + // (with its usage/status) — not just the open record. + expect(close?.attributes?.warm).toBe(true); + // Span-specific attrs from span()/end() are still present on close. + expect(close?.attributes?.model).toBe("x"); + expect(close?.attributes?.["usage.cacheReadTokens"]).toBe(0); + }); - it("omits attributes entirely when neither bound nor span attrs exist", () => { - const { logger, records } = harness(); - const span = logger.span("bare"); - span.end(); - const close = records.find((r) => r.kind === "span-close"); - expect(close?.attributes).toBeUndefined(); - }); + it("omits attributes entirely when neither bound nor span attrs exist", () => { + const { logger, records } = harness(); + const span = logger.span("bare"); + span.end(); + const close = records.find((r) => r.kind === "span-close"); + expect(close?.attributes).toBeUndefined(); + }); }); diff --git a/packages/kernel/src/logging/logger.ts b/packages/kernel/src/logging/logger.ts index 4d2a609..341348d 100644 --- a/packages/kernel/src/logging/logger.ts +++ b/packages/kernel/src/logging/logger.ts @@ -6,112 +6,112 @@ */ import type { - Attributes, - ErrorAttributes, - Level, - LogContext, - LogDeps, - Logger, - LogLineRecord, - LogSink, - Span, - SpanCloseRecord, - SpanLink, - SpanOpenRecord, - SpanStatus, + Attributes, + ErrorAttributes, + Level, + LogContext, + LogDeps, + Logger, + LogLineRecord, + LogSink, + Span, + SpanCloseRecord, + SpanLink, + SpanOpenRecord, + SpanStatus, } from "../contracts/logging.js"; interface LoggerState { - readonly ctx: LogContext; - readonly attrs: Attributes | undefined; - readonly deps: LogDeps; - readonly sink: LogSink; + readonly ctx: LogContext; + readonly attrs: Attributes | undefined; + readonly deps: LogDeps; + readonly sink: LogSink; } function mergeAttributes( - base: Attributes | undefined, - extra: Attributes | undefined, + base: Attributes | undefined, + extra: Attributes | undefined, ): Attributes | undefined { - if (base === undefined && extra === undefined) return undefined; - if (base === undefined) return extra; - if (extra === undefined) return base; - return { ...base, ...extra }; + if (base === undefined && extra === undefined) return undefined; + if (base === undefined) return extra; + if (extra === undefined) return base; + return { ...base, ...extra }; } function isScalarAttr(value: unknown): value is string | number | boolean | null { - const t = typeof value; - return t === "string" || t === "number" || t === "boolean" || value === null; + const t = typeof value; + return t === "string" || t === "number" || t === "boolean" || value === null; } function emitLog(state: LoggerState, level: Level, msg: string, attrs?: Attributes): void { - const merged = mergeAttributes(state.attrs, attrs); - const base = { - kind: "log" as const, - level, - msg, - timestamp: state.deps.now(), - extensionId: state.ctx.extensionId, - }; - const record: LogLineRecord = - state.ctx.conversationId !== undefined || - state.ctx.turnId !== undefined || - state.ctx.spanId !== undefined || - state.ctx.parentSpanId !== undefined || - merged !== undefined - ? { - ...base, - ...(state.ctx.conversationId !== undefined - ? { conversationId: state.ctx.conversationId } - : {}), - ...(state.ctx.turnId !== undefined ? { turnId: state.ctx.turnId } : {}), - ...(state.ctx.spanId !== undefined ? { spanId: state.ctx.spanId } : {}), - ...(state.ctx.parentSpanId !== undefined ? { parentSpanId: state.ctx.parentSpanId } : {}), - ...(merged !== undefined ? { attributes: merged } : {}), - } - : base; - try { - state.sink.emit(record); - } catch { - // Swallow — D7: the turn is sovereign (never break the caller). - } + const merged = mergeAttributes(state.attrs, attrs); + const base = { + kind: "log" as const, + level, + msg, + timestamp: state.deps.now(), + extensionId: state.ctx.extensionId, + }; + const record: LogLineRecord = + state.ctx.conversationId !== undefined || + state.ctx.turnId !== undefined || + state.ctx.spanId !== undefined || + state.ctx.parentSpanId !== undefined || + merged !== undefined + ? { + ...base, + ...(state.ctx.conversationId !== undefined + ? { conversationId: state.ctx.conversationId } + : {}), + ...(state.ctx.turnId !== undefined ? { turnId: state.ctx.turnId } : {}), + ...(state.ctx.spanId !== undefined ? { spanId: state.ctx.spanId } : {}), + ...(state.ctx.parentSpanId !== undefined ? { parentSpanId: state.ctx.parentSpanId } : {}), + ...(merged !== undefined ? { attributes: merged } : {}), + } + : base; + try { + state.sink.emit(record); + } catch { + // Swallow — D7: the turn is sovereign (never break the caller). + } } function buildSpanOpen( - state: LoggerState, - name: string, - spanId: string, - attrs?: Attributes, - body?: string, - parentSpanId?: string, + state: LoggerState, + name: string, + spanId: string, + attrs?: Attributes, + body?: string, + parentSpanId?: string, ): SpanOpenRecord { - const base = { - kind: "span-open" as const, - spanId, - name, - timestamp: state.deps.now(), - extensionId: state.ctx.extensionId, - }; - const merged = mergeAttributes(state.attrs, attrs); - const effectiveParent = parentSpanId ?? state.ctx.parentSpanId; - return { - ...base, - ...(state.ctx.conversationId !== undefined ? { conversationId: state.ctx.conversationId } : {}), - ...(state.ctx.turnId !== undefined ? { turnId: state.ctx.turnId } : {}), - ...(effectiveParent !== undefined ? { parentSpanId: effectiveParent } : {}), - ...(merged !== undefined ? { attributes: merged } : {}), - ...(body !== undefined ? { body } : {}), - }; + const base = { + kind: "span-open" as const, + spanId, + name, + timestamp: state.deps.now(), + extensionId: state.ctx.extensionId, + }; + const merged = mergeAttributes(state.attrs, attrs); + const effectiveParent = parentSpanId ?? state.ctx.parentSpanId; + return { + ...base, + ...(state.ctx.conversationId !== undefined ? { conversationId: state.ctx.conversationId } : {}), + ...(state.ctx.turnId !== undefined ? { turnId: state.ctx.turnId } : {}), + ...(effectiveParent !== undefined ? { parentSpanId: effectiveParent } : {}), + ...(merged !== undefined ? { attributes: merged } : {}), + ...(body !== undefined ? { body } : {}), + }; } function buildSpanLink( - target: { readonly spanId: string; readonly turnId?: string }, - reason?: string, + target: { readonly spanId: string; readonly turnId?: string }, + reason?: string, ): SpanLink { - return { - spanId: target.spanId, - ...(target.turnId !== undefined ? { turnId: target.turnId } : {}), - ...(reason !== undefined ? { reason } : {}), - }; + return { + spanId: target.spanId, + ...(target.turnId !== undefined ? { turnId: target.turnId } : {}), + ...(reason !== undefined ? { reason } : {}), + }; } /** @@ -124,187 +124,187 @@ function buildSpanLink( * @param attrs Optional default attributes (from child()). */ export function createLogger( - ctx: LogContext, - sink: LogSink, - deps: LogDeps, - attrs?: Attributes, + ctx: LogContext, + sink: LogSink, + deps: LogDeps, + attrs?: Attributes, ): Logger { - const state: LoggerState = { ctx, attrs, deps, sink }; + const state: LoggerState = { ctx, attrs, deps, sink }; - function makeSpan( - name: string, - spanAttrs?: Attributes, - parentSpanId?: string, - body?: string, - ): Span { - const spanId = deps.newId(); - const mergedParent = parentSpanId ?? state.ctx.spanId; - const spanCtx: LogContext = { - extensionId: ctx.extensionId, - ...(ctx.conversationId !== undefined ? { conversationId: ctx.conversationId } : {}), - ...(ctx.turnId !== undefined ? { turnId: ctx.turnId } : {}), - spanId, - ...(mergedParent !== undefined ? { parentSpanId: mergedParent } : {}), - }; + function makeSpan( + name: string, + spanAttrs?: Attributes, + parentSpanId?: string, + body?: string, + ): Span { + const spanId = deps.newId(); + const mergedParent = parentSpanId ?? state.ctx.spanId; + const spanCtx: LogContext = { + extensionId: ctx.extensionId, + ...(ctx.conversationId !== undefined ? { conversationId: ctx.conversationId } : {}), + ...(ctx.turnId !== undefined ? { turnId: ctx.turnId } : {}), + spanId, + ...(mergedParent !== undefined ? { parentSpanId: mergedParent } : {}), + }; - const openRecord = buildSpanOpen(state, name, spanId, spanAttrs, body, mergedParent); - const spanAttrsMutable: Record<string, string | number | boolean | null> = - spanAttrs !== undefined ? { ...spanAttrs } : {}; - const links: SpanLink[] = []; - const openedAt = deps.now(); + const openRecord = buildSpanOpen(state, name, spanId, spanAttrs, body, mergedParent); + const spanAttrsMutable: Record<string, string | number | boolean | null> = + spanAttrs !== undefined ? { ...spanAttrs } : {}; + const links: SpanLink[] = []; + const openedAt = deps.now(); - try { - sink.emit(openRecord); - } catch { - // Swallow — D7. - } + try { + sink.emit(openRecord); + } catch { + // Swallow — D7. + } - const spanLogger = createLogger(spanCtx, sink, deps, state.attrs); + const spanLogger = createLogger(spanCtx, sink, deps, state.attrs); - const span: Span = { - id: spanId, - log: spanLogger, - setAttributes(newAttrs: Attributes): void { - for (const [key, value] of Object.entries(newAttrs)) { - spanAttrsMutable[key] = value; - } - }, - addLink(target, reason): void { - links.push(buildSpanLink(target, reason)); - }, - child(childName: string, childAttrs?: Attributes, childBody?: string): Span { - return makeSpan(childName, childAttrs, spanId, childBody); - }, - end(outcome?): void { - const closedAt = deps.now(); - const err = outcome?.err; - let status: SpanStatus = "ok"; - if (err !== undefined && err !== null) { - status = "error"; - const errMsg = err instanceof Error ? err.message : String(err); - spanAttrsMutable["error.message"] = errMsg; - if (err instanceof Error && err.stack !== undefined) { - spanAttrsMutable["error.stack"] = err.stack; - } - } - if (outcome?.attrs !== undefined) { - for (const [key, value] of Object.entries(outcome.attrs)) { - spanAttrsMutable[key] = value; - } - } + const span: Span = { + id: spanId, + log: spanLogger, + setAttributes(newAttrs: Attributes): void { + for (const [key, value] of Object.entries(newAttrs)) { + spanAttrsMutable[key] = value; + } + }, + addLink(target, reason): void { + links.push(buildSpanLink(target, reason)); + }, + child(childName: string, childAttrs?: Attributes, childBody?: string): Span { + return makeSpan(childName, childAttrs, spanId, childBody); + }, + end(outcome?): void { + const closedAt = deps.now(); + const err = outcome?.err; + let status: SpanStatus = "ok"; + if (err !== undefined && err !== null) { + status = "error"; + const errMsg = err instanceof Error ? err.message : String(err); + spanAttrsMutable["error.message"] = errMsg; + if (err instanceof Error && err.stack !== undefined) { + spanAttrsMutable["error.stack"] = err.stack; + } + } + if (outcome?.attrs !== undefined) { + for (const [key, value] of Object.entries(outcome.attrs)) { + spanAttrsMutable[key] = value; + } + } - const hasAttrs = Object.keys(spanAttrsMutable).length > 0; - // Merge child-bound default attrs (state.attrs) the SAME way span-open - // does (buildSpanOpen). Without this, an attribute bound via - // `logger.child({ attrs })` appears on the span-open record but NOT the - // span-close record — so a query like `warm = true` can't find the - // closed span (with its usage/status). Open and close must agree. - const mergedCloseAttrs = mergeAttributes( - state.attrs, - hasAttrs ? spanAttrsMutable : undefined, - ); - const hasLinks = links.length > 0; - const base = { - kind: "span-close" as const, - spanId, - name, - timestamp: closedAt, - durationMs: closedAt - openedAt, - status, - extensionId: ctx.extensionId, - }; - const closeRecord: SpanCloseRecord = { - ...base, - ...(ctx.conversationId !== undefined ? { conversationId: ctx.conversationId } : {}), - ...(ctx.turnId !== undefined ? { turnId: ctx.turnId } : {}), - ...(mergedParent !== undefined ? { parentSpanId: mergedParent } : {}), - ...(mergedCloseAttrs !== undefined ? { attributes: mergedCloseAttrs } : {}), - ...(hasLinks ? { links: [...links] } : {}), - ...(outcome?.body !== undefined ? { body: outcome.body } : {}), - }; - try { - sink.emit(closeRecord); - } catch { - // Swallow — D7. - } - }, - }; + const hasAttrs = Object.keys(spanAttrsMutable).length > 0; + // Merge child-bound default attrs (state.attrs) the SAME way span-open + // does (buildSpanOpen). Without this, an attribute bound via + // `logger.child({ attrs })` appears on the span-open record but NOT the + // span-close record — so a query like `warm = true` can't find the + // closed span (with its usage/status). Open and close must agree. + const mergedCloseAttrs = mergeAttributes( + state.attrs, + hasAttrs ? spanAttrsMutable : undefined, + ); + const hasLinks = links.length > 0; + const base = { + kind: "span-close" as const, + spanId, + name, + timestamp: closedAt, + durationMs: closedAt - openedAt, + status, + extensionId: ctx.extensionId, + }; + const closeRecord: SpanCloseRecord = { + ...base, + ...(ctx.conversationId !== undefined ? { conversationId: ctx.conversationId } : {}), + ...(ctx.turnId !== undefined ? { turnId: ctx.turnId } : {}), + ...(mergedParent !== undefined ? { parentSpanId: mergedParent } : {}), + ...(mergedCloseAttrs !== undefined ? { attributes: mergedCloseAttrs } : {}), + ...(hasLinks ? { links: [...links] } : {}), + ...(outcome?.body !== undefined ? { body: outcome.body } : {}), + }; + try { + sink.emit(closeRecord); + } catch { + // Swallow — D7. + } + }, + }; - return span; - } + return span; + } - const logger: Logger = { - debug(msg: string, attrs?: Attributes): void { - emitLog(state, "debug", msg, attrs); - }, - info(msg: string, attrs?: Attributes): void { - emitLog(state, "info", msg, attrs); - }, - warn(msg: string, attrs?: Attributes): void { - emitLog(state, "warn", msg, attrs); - }, - error(msg: string, attrs?: ErrorAttributes): void { - const err = attrs?.err; - if (err !== undefined && err !== null) { - // Extract scalar attributes (everything except err). - const scalarAttrs: Record<string, string | number | boolean | null> = {}; - if (attrs !== undefined) { - for (const [key, value] of Object.entries(attrs)) { - if (key !== "err" && isScalarAttr(value)) { - scalarAttrs[key] = value; - } - } - } - const merged = mergeAttributes( - state.attrs, - Object.keys(scalarAttrs).length > 0 ? scalarAttrs : undefined, - ); - const errMsg = err instanceof Error ? err.message : String(err); - const errorAttrs: Record<string, string | number | boolean | null> = { - ...(merged ?? {}), - "error.message": errMsg, - }; - if (err instanceof Error && err.stack !== undefined) { - errorAttrs["error.stack"] = err.stack; - } - emitLog(state, "error", msg, errorAttrs as Attributes); - } else { - // No err field — filter to scalar attributes only. - const scalarAttrs: Record<string, string | number | boolean | null> = {}; - if (attrs !== undefined) { - for (const [key, value] of Object.entries(attrs)) { - if (isScalarAttr(value)) { - scalarAttrs[key] = value; - } - } - } - emitLog( - state, - "error", - msg, - Object.keys(scalarAttrs).length > 0 ? (scalarAttrs as Attributes) : undefined, - ); - } - }, - child(childCtx: Partial<LogContext> & { readonly attrs?: Attributes }): Logger { - const convId = childCtx.conversationId ?? ctx.conversationId; - const tId = childCtx.turnId ?? ctx.turnId; - const sId = childCtx.spanId ?? ctx.spanId; - const pId = childCtx.parentSpanId ?? ctx.parentSpanId; - const newCtx: LogContext = { - extensionId: ctx.extensionId, - ...(convId !== undefined ? { conversationId: convId } : {}), - ...(tId !== undefined ? { turnId: tId } : {}), - ...(sId !== undefined ? { spanId: sId } : {}), - ...(pId !== undefined ? { parentSpanId: pId } : {}), - }; - const newAttrs = mergeAttributes(state.attrs, childCtx.attrs); - return createLogger(newCtx, sink, deps, newAttrs); - }, - span(name: string, attrs?: Attributes, body?: string): Span { - return makeSpan(name, attrs, undefined, body); - }, - }; + const logger: Logger = { + debug(msg: string, attrs?: Attributes): void { + emitLog(state, "debug", msg, attrs); + }, + info(msg: string, attrs?: Attributes): void { + emitLog(state, "info", msg, attrs); + }, + warn(msg: string, attrs?: Attributes): void { + emitLog(state, "warn", msg, attrs); + }, + error(msg: string, attrs?: ErrorAttributes): void { + const err = attrs?.err; + if (err !== undefined && err !== null) { + // Extract scalar attributes (everything except err). + const scalarAttrs: Record<string, string | number | boolean | null> = {}; + if (attrs !== undefined) { + for (const [key, value] of Object.entries(attrs)) { + if (key !== "err" && isScalarAttr(value)) { + scalarAttrs[key] = value; + } + } + } + const merged = mergeAttributes( + state.attrs, + Object.keys(scalarAttrs).length > 0 ? scalarAttrs : undefined, + ); + const errMsg = err instanceof Error ? err.message : String(err); + const errorAttrs: Record<string, string | number | boolean | null> = { + ...(merged ?? {}), + "error.message": errMsg, + }; + if (err instanceof Error && err.stack !== undefined) { + errorAttrs["error.stack"] = err.stack; + } + emitLog(state, "error", msg, errorAttrs as Attributes); + } else { + // No err field — filter to scalar attributes only. + const scalarAttrs: Record<string, string | number | boolean | null> = {}; + if (attrs !== undefined) { + for (const [key, value] of Object.entries(attrs)) { + if (isScalarAttr(value)) { + scalarAttrs[key] = value; + } + } + } + emitLog( + state, + "error", + msg, + Object.keys(scalarAttrs).length > 0 ? (scalarAttrs as Attributes) : undefined, + ); + } + }, + child(childCtx: Partial<LogContext> & { readonly attrs?: Attributes }): Logger { + const convId = childCtx.conversationId ?? ctx.conversationId; + const tId = childCtx.turnId ?? ctx.turnId; + const sId = childCtx.spanId ?? ctx.spanId; + const pId = childCtx.parentSpanId ?? ctx.parentSpanId; + const newCtx: LogContext = { + extensionId: ctx.extensionId, + ...(convId !== undefined ? { conversationId: convId } : {}), + ...(tId !== undefined ? { turnId: tId } : {}), + ...(sId !== undefined ? { spanId: sId } : {}), + ...(pId !== undefined ? { parentSpanId: pId } : {}), + }; + const newAttrs = mergeAttributes(state.attrs, childCtx.attrs); + return createLogger(newCtx, sink, deps, newAttrs); + }, + span(name: string, attrs?: Attributes, body?: string): Span { + return makeSpan(name, attrs, undefined, body); + }, + }; - return logger; + return logger; } |
