diff --git a/src/trace/patch-console.spec.ts b/src/trace/patch-console.spec.ts index 6d8a087d..7b6a5987 100644 --- a/src/trace/patch-console.spec.ts +++ b/src/trace/patch-console.spec.ts @@ -41,55 +41,114 @@ describe("patchConsole", () => { unpatchConsole(cnsole as any); }); - it("injects trace context into log messages", () => { + it.each([ + { method: "log", mock: () => log }, + { method: "info", mock: () => info }, + { method: "debug", mock: () => debug }, + { method: "error", mock: () => error }, + { method: "warn", mock: () => warn }, + { method: "trace", mock: () => trace }, + ] as const)("injects trace context into $method messages", ({ method, mock }) => { + patchConsole(cnsole as any, contextService); + cnsole[method]("Hello"); + expect(mock()).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + }); + + it("doesn't inject trace context when none is present", () => { + contextService["rootTraceContext"] = undefined as any; patchConsole(cnsole as any, contextService); cnsole.log("Hello"); - expect(log).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + expect(log).toHaveBeenCalledWith("Hello"); }); - it("injects trace context into debug messages", () => { + it("injects trace context into empty message", () => { patchConsole(cnsole as any, contextService); - cnsole.info("Hello"); - expect(info).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + cnsole.log(); + expect(log).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910]"); }); - it("injects trace context into debug messages", () => { + it("injects trace context into JSON-style log by adding dd property", () => { patchConsole(cnsole as any, contextService); - cnsole.debug("Hello"); - expect(debug).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + + cnsole.log({ objectKey: "objectValue", otherObjectKey: "otherObjectValue" }); + expect(log).toHaveBeenCalledWith({ + objectKey: "objectValue", + otherObjectKey: "otherObjectValue", + dd: { + trace_id: "123456", + span_id: "78910", + }, + }); }); - it("injects trace context into error messages", () => { + + it.each([ + { name: "array", value: [1, 2, 3], expected: "[dd.trace_id=123456 dd.span_id=78910] 1,2,3" }, + { name: "null", value: null, expected: "[dd.trace_id=123456 dd.span_id=78910] null" }, + { name: "number", value: 42, expected: "[dd.trace_id=123456 dd.span_id=78910] 42" }, + { name: "undefined", value: undefined, expected: "[dd.trace_id=123456 dd.span_id=78910] undefined" }, + ])("injects trace context as string prefix for $name", ({ value, expected }) => { patchConsole(cnsole as any, contextService); - cnsole.error("Hello"); - expect(error).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + cnsole.log(value); + expect(log).toHaveBeenCalledWith(expected); }); - it("injects trace context into error messages", () => { + + it("injects trace context as string prefix when multiple arguments provided", () => { patchConsole(cnsole as any, contextService); - cnsole.warn("Hello"); - expect(warn).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + + cnsole.log({ key: "value" }, "extra arg"); + expect(log).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] [object Object]", "extra arg"); }); - it("injects trace context into error messages", () => { + + it("injects trace context as string prefix for class instances", () => { patchConsole(cnsole as any, contextService); - cnsole.trace("Hello"); - expect(trace).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] Hello"); + + class MyClass { + value = "test"; + } + const instance = new MyClass(); + cnsole.log(instance); + expect(log).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910] [object Object]"); }); - it("doesn't inject trace context when none is present", () => { - contextService["rootTraceContext"] = undefined as any; + it("injects trace context into JSON-style log created with Object.create(null)", () => { patchConsole(cnsole as any, contextService); - cnsole.log("Hello"); - expect(log).toHaveBeenCalledWith("Hello"); + + const obj = Object.create(null); + obj.message = "test"; + cnsole.log(obj); + expect(log).toHaveBeenCalledWith({ + message: "test", + dd: { + trace_id: "123456", + span_id: "78910", + }, + }); }); - it("injects trace context into empty message", () => { + + it("preserves nested objects in JSON format", () => { patchConsole(cnsole as any, contextService); - cnsole.log(); - expect(log).toHaveBeenCalledWith("[dd.trace_id=123456 dd.span_id=78910]"); + + cnsole.log({ level: "info", nested: { foo: "bar" } }); + expect(log).toHaveBeenCalledWith({ + level: "info", + nested: { foo: "bar" }, + dd: { + trace_id: "123456", + span_id: "78910", + }, + }); }); - it("injects trace context into logged object message", () => { + + it("merges trace context with existing dd property", () => { patchConsole(cnsole as any, contextService); - cnsole.log({ objectKey: "objectValue", otherObjectKey: "otherObjectValue" }); - expect(log).toHaveBeenCalledWith( - "[dd.trace_id=123456 dd.span_id=78910] { objectKey: 'objectValue', otherObjectKey: 'otherObjectValue' }", - ); + cnsole.log({ message: "test", dd: { existing: "value" } }); + expect(log).toHaveBeenCalledWith({ + message: "test", + dd: { + existing: "value", + trace_id: "123456", + span_id: "78910", + }, + }); }); it("leaves empty message unmodified when there is no trace context", () => { contextService["rootTraceContext"] = undefined as any; diff --git a/src/trace/patch-console.ts b/src/trace/patch-console.ts index 1d4c4438..073fe6e7 100644 --- a/src/trace/patch-console.ts +++ b/src/trace/patch-console.ts @@ -1,5 +1,4 @@ import * as shimmer from "shimmer"; -import { inspect } from "util"; type Console = typeof console; @@ -10,6 +9,37 @@ import { TraceContextService } from "./trace-context-service"; type LogMethod = "log" | "info" | "debug" | "error" | "warn" | "trace"; +/** + * Checks if a value is a JSON-style structured log (plain object). + * When true, trace context will be injected as a `dd` property to preserve JSON format. + * When false, trace context will be prepended as a string prefix. + */ +function isJsonStyleLog(value: unknown): value is Record { + if (value === null || typeof value !== "object") { + return false; + } + if (Array.isArray(value)) { + return false; + } + const proto = Object.getPrototypeOf(value); + return proto === null || proto === Object.prototype; +} + +/** + * Checks if a value is a plain object (not null, not an array). + */ +function isPlainObject(value: unknown): value is Record { + return value !== null && typeof value === "object" && !Array.isArray(value); +} + +/** + * Extracts the existing `dd` property from a log object if it's a plain object. + * Returns an empty object if `dd` is missing or not a plain object. + */ +function getExistingDdContext(logObject: Record): Record { + return isPlainObject(logObject.dd) ? logObject.dd : {}; +} + /** * Patches console output to include DataDog's trace context. * @param contextService Provides up to date tracing context. @@ -51,27 +81,33 @@ function patchMethod(mod: wrappedConsole, method: LogMethod, contextService: Tra } isLogging = true; - let prefix = ""; const oldLogLevel = getLogLevel(); setLogLevel(LogLevel.NONE); try { const context = contextService.currentTraceContext; if (context !== null) { const traceId = context.toTraceId(); - const parentId = context.toSpanId(); - prefix = `[dd.trace_id=${traceId} dd.span_id=${parentId}]`; + const spanId = context.toSpanId(); + if (arguments.length === 0) { + // No arguments: emit just the trace context prefix arguments.length = 1; - arguments[0] = prefix; + arguments[0] = `[dd.trace_id=${traceId} dd.span_id=${spanId}]`; + } else if (arguments.length === 1 && isJsonStyleLog(arguments[0])) { + // Single plain object: inject dd property to preserve JSON format + arguments[0] = { + ...arguments[0], + dd: { + ...getExistingDdContext(arguments[0]), + // Overwrite trace_id and span_id to ensure we have the latest values + trace_id: traceId, + span_id: spanId, + }, + }; } else { - let logContent = arguments[0]; - - // If what's being logged is not a string, use util.inspect to get a str representation - if (typeof logContent !== "string") { - logContent = inspect(logContent); - } - - arguments[0] = `${prefix} ${logContent}`; + // String or multiple arguments: use string prefix + const prefix = `[dd.trace_id=${traceId} dd.span_id=${spanId}]`; + arguments[0] = `${prefix} ${arguments[0]}`; } } } catch (error) {