/** * Unit: the pino-otel correlation bridge — the spec's "requestId on every * log line" + the trace fields when a span is active. */ import { describe, expect, it } from "vitest"; import { Writable } from "node:stream"; import { context, trace } from "@opentelemetry/api"; import { AsyncLocalStorageContextManager } from "@opentelemetry/context-async-hooks"; import { BasicTracerProvider } from "@opentelemetry/sdk-trace-base"; import { makeOtelPino, otelLogBindings, requestChild } from "../pino-otel.js"; // The API's default context manager is a no-op — register the real one so // "active span" contexts are visible inside synchronous callbacks. const CM = new AsyncLocalStorageContextManager(); CM.enable(); context.setGlobalContextManager(CM); /** A writable that collects pino's JSON lines. */ class Collector extends Writable { lines: string[] = []; override _write(chunk: string | Buffer, _enc: BufferEncoding, cb: (err?: Error) => void): void { for (const line of String(chunk).split("\n")) { if (line.trim()) this.lines.push(line); } cb(); } } describe("otelLogBindings", () => { it("always carries requestId (unknown when absent)", () => { expect(otelLogBindings(undefined)).toEqual({ requestId: "unknown" }); expect(otelLogBindings("req-123")).toEqual({ requestId: "req-123" }); }); it("omits trace fields when no span is active (exactOptionalPropertyTypes shape)", () => { const b = otelLogBindings("r1"); expect(Object.keys(b).sort()).toEqual(["requestId"]); }); it("carries traceId/spanId when a span is active + workspaceId when given", () => { const provider = new BasicTracerProvider(); trace.setGlobalTracerProvider(provider); try { const tracer = trace.getTracer("t"); const bindings = tracer.startActiveSpan("op", (span) => { const b = otelLogBindings("r1", "ws_9"); span.end(); return b; }); expect(bindings.requestId).toBe("r1"); expect(bindings.workspaceId).toBe("ws_9"); expect(bindings.traceId).toMatch(/^[0-9a-f]{32}$/); expect(bindings.spanId).toMatch(/^[0-9a-f]{16}$/); } finally { void provider.shutdown(); } }); }); describe("makeOtelPino (the requestId log-capture test)", () => { it("emits requestId on every line (the spec's log-capture assertion)", async () => { const col = new Collector(); const logger = makeOtelPino({ service: "factory-test", dest: col }); const req = requestChild(logger, "req-abc"); req.info("hello world"); req.warn("watch out"); logger.info("background line"); await new Promise((r) => setTimeout(r, 50)); const lines = col.lines.map((l) => JSON.parse(l) as Record); expect(lines.length).toBe(3); for (const line of lines) { expect(line["service"]).toBe("factory-test"); expect(typeof line["requestId"]).toBe("string"); } // the request child's static binding wins over the mixin's "unknown" expect(lines[0]!["requestId"]).toBe("req-abc"); expect(lines[1]!["requestId"]).toBe("req-abc"); expect(lines[2]!["requestId"]).toBe("unknown"); }); it("carries traceId/spanId on lines written inside an active span", async () => { trace.disable(); // fresh provider (a previous one may hold the global) const provider = new BasicTracerProvider(); trace.setGlobalTracerProvider(provider); const col = new Collector(); const logger = makeOtelPino({ service: "factory-test", dest: col }); const tracer = trace.getTracer("t"); tracer.startActiveSpan("op", (span) => { logger.info("inside span"); span.end(); }); await new Promise((r) => setTimeout(r, 50)); const line = JSON.parse(col.lines[0]!) as Record; expect(line["traceId"]).toMatch(/^[0-9a-f]{32}$/); expect(line["spanId"]).toMatch(/^[0-9a-f]{16}$/); void provider.shutdown(); }); });