/** * @factory/observability — pino correlation bridge (TASK-0135). * * The spec's log requirement: pino → stdout (JSON) with `requestId` on EVERY * line (the correlation id from `X-Request-Id`/generated) + `traceId`/ * `spanId` (the OTel span context) whenever a span is active. * * Implementation: a pino `redact`/serialize-adjacent bridge built from * `pino.final` + child bindings is NOT used (the apps own their logger * instances and pass explicit bindings). Instead this module gives: * * - {@link otelLogBindings(reqId)} — the bindings object every log line * should carry: `requestId` (always; `"unknown"` when absent — the API * logger's existing convention) + `traceId`/`spanId`/`traceFlags` read * from the ACTIVE span context (absent when no span / OTel disabled — * exactOptionalPropertyTypes: keys are omitted, never `undefined`); * - {@link makeOtelPino} — a ready pino logger with those bindings applied * via a `syncMessage`-free child: every line pino emits carries them. * * The bridge reads ONLY `@opentelemetry/api` (global tracer) — it works with * or without the SDK (no span → no trace fields, no crash). */ import { context as otelContext, trace } from "@opentelemetry/api"; import pino from "pino"; import type { Logger as PinoLogger } from "pino"; import type { Writable } from "node:stream"; export interface OtelLogBindings { /** The correlation id (X-Request-Id / generated uuid; "unknown" when absent). */ requestId: string; /** W3C trace id (32 hex) — only present when a span is active. */ traceId?: string; /** W3C span id (16 hex) — only present when a span is active. */ spanId?: string; /** Workspace id — only present when the caller resolved one. */ workspaceId?: string; } /** * Build the correlation bindings for one log call. Safe to call at any time * (no active context → just `{ requestId }`). */ export function otelLogBindings(requestId: string | undefined, workspaceId?: string): OtelLogBindings { const out: OtelLogBindings = { requestId: requestId ?? "unknown" }; const sc = trace.getSpanContext(otelContext.active()); if (sc && sc.traceId && sc.spanId) { out.traceId = sc.traceId; out.spanId = sc.spanId; } if (workspaceId) out.workspaceId = workspaceId; return out; } export interface MakeOtelPinoOptions { /** Service name — logged on every line (the NFR §7.1 `service` field). */ service: string; /** pino level (default: the LOG_LEVEL env or `info`). */ level?: string; /** Extra static bindings (e.g. `env`). */ base?: Record; /** Output destination (default: process.stdout; tests pass a collector). */ dest?: Writable; } /** * Create a pino logger whose EVERY line carries the correlation bindings. * The per-line dynamic part (the ACTIVE span context at write time) is * applied via a `pino.final`-style wrapper: pino's child bindings are * per-logger-static, so the span-aware part rides on a custom * `onChild`/child factory — the simplest correct shape is a `child()` * factory the app calls per request, BUT the spec wants it on EVERY line * (including request-less background work), so we use pino's `mixin` hook: * pino calls `mixin()` on every log write and merges the returned object * into the line. That is exactly "add traceId/spanId to every log line". */ export function makeOtelPino(opts: MakeOtelPinoOptions): PinoLogger { const base: Record = { service: opts.service, ...(opts.base ?? {}) }; return pino( { level: opts.level ?? process.env.LOG_LEVEL ?? "info", // pino 9 calls the mixin on EVERY write with the WRITING logger as the // third arg — so a request child's static `requestId` binding is read // here and the mixin's value agrees with it (pino's default merge // gives child bindings priority over the mixin anyway). Root-logger // (background) lines have no requestId binding → "unknown". mixin: ( _obj: object, _level: number, logger: PinoLogger ): { requestId: string; traceId?: string; spanId?: string; workspaceId?: string } => { const b = logger.bindings() as Record; const requestId = typeof b["requestId"] === "string" ? b["requestId"] : undefined; const workspaceId = typeof b["workspaceId"] === "string" ? b["workspaceId"] : undefined; return otelLogBindings(requestId, workspaceId); }, base: { ...base } }, opts.dest ?? process.stdout ); } /** * The per-REQUEST child: `logger.child(otelLogBindings(req.id))` — the * request's lines carry `requestId` + the ACTIVE span's `traceId`/`spanId` * (the mixin still runs, so background children of this child keep their * own bindings; the child's static requestId wins over the mixin's * "unknown" — pino's child precedence is child > parent > mixin… actually * pino merges mixin UNDER the child's bindings, so the static requestId * here shadows the mixin's — the intended behavior). */ export function requestChild(parent: PinoLogger, requestId: string | undefined, workspaceId?: string): PinoLogger { return parent.child(otelLogBindings(requestId, workspaceId)); }