From 6b2688f5b7fecc57e2dc791e06f5bcf7fd50dbca Mon Sep 17 00:00:00 2001 From: Alex Suraci Date: Fri, 8 May 2026 14:45:48 -0400 Subject: [PATCH] feat(jest): emit test logs as otel logs Export Jest console output through the OpenTelemetry logs pipeline on the active test span, including support for Jest's buffered/custom consoles. Add a local fixture and cache-bust check runs so output routing is exercised. Signed-off-by: Alex Suraci --- README.md | 5 + bun.lock | 1 + jest.dang | 1 + package.json | 1 + src/wrapper.ts | 208 +++++++++++++++++- tests/log_output_toolchain_local/dagger.json | 16 ++ .../log-output.test.js | 26 +++ tests/log_output_toolchain_local/package.json | 13 ++ 8 files changed, 266 insertions(+), 5 deletions(-) create mode 100644 tests/log_output_toolchain_local/dagger.json create mode 100644 tests/log_output_toolchain_local/log-output.test.js create mode 100644 tests/log_output_toolchain_local/package.json diff --git a/README.md b/README.md index e1a4ed7..1b0bb73 100644 --- a/README.md +++ b/README.md @@ -76,6 +76,11 @@ Test spans include `dagger.io/ui.boundary` plus OpenTelemetry test semantic conv Suite spans include `dagger.io/ui.boundary`, `test.suite.name`, and `test.suite.run.status`. +### Test output + +Console output emitted with `console.log`, `console.info`, `console.debug`, `console.warn`, +and `console.error` is exported as OpenTelemetry logs on the active test span. + ### Installation Install `@dagger.io/jest` in your project diff --git a/bun.lock b/bun.lock index c0727f8..99a1bf4 100644 --- a/bun.lock +++ b/bun.lock @@ -6,6 +6,7 @@ "name": "@dagger.io/jest", "dependencies": { "@dagger.io/telemetry": "^0.0.5", + "@opentelemetry/api-logs": "^0.209.0", "@opentelemetry/sdk-node": "^0.209.0", "@opentelemetry/semantic-conventions": "^1.29.0", "jest-environment-node": "^30.2.0", diff --git a/jest.dang b/jest.dang index 7de75d2..3e22acd 100644 --- a/jest.dang +++ b/jest.dang @@ -68,6 +68,7 @@ type Jest { # mount and install the otel library and then execute the tests runtime + .withEnvVariable("DAGGER_JEST_CACHE_BUSTER", UUID.v7) .withExec(["npx", "jest"] + flags + files) .sync diff --git a/package.json b/package.json index 33914c5..f58a893 100644 --- a/package.json +++ b/package.json @@ -59,6 +59,7 @@ "homepage": "https://github.com/dagger/jest", "dependencies": { "@dagger.io/telemetry": "^0.0.5", + "@opentelemetry/api-logs": "^0.209.0", "@opentelemetry/sdk-node": "^0.209.0", "@opentelemetry/semantic-conventions": "^1.29.0", "jest-environment-node": "^30.2.0", diff --git a/src/wrapper.ts b/src/wrapper.ts index 4593679..6e4694d 100644 --- a/src/wrapper.ts +++ b/src/wrapper.ts @@ -1,8 +1,10 @@ +import { format } from "node:util"; import { OtelSDK } from "@dagger.io/telemetry"; import type { EnvironmentContext, JestEnvironmentConfig } from "@jest/environment"; import type { Circus } from "@jest/types"; import type { Attributes, Context, Span } from "@opentelemetry/api"; -import { context, SpanStatusCode, trace } from "@opentelemetry/api"; +import { context, isSpanContextValid, SpanStatusCode, trace } from "@opentelemetry/api"; +import { logs, SeverityNumber } from "@opentelemetry/api-logs"; import { ATTR_TEST_CASE_NAME, ATTR_TEST_CASE_RESULT_STATUS, @@ -16,10 +18,92 @@ import { } from "@opentelemetry/semantic-conventions/incubating"; import type { TestEnvironment } from "jest-environment-node"; -const tracer = trace.getTracer("dagger.io/jest"); +__prepareLogExporterEnv(); const JEST_ROOT_BLOCK_NAME = "ROOT_DESCRIBE_BLOCK"; const ATTR_UI_BOUNDARY = "dagger.io/ui.boundary"; +const STDIO_STREAM_ATTR = "stdio.stream"; +const STDIO_STREAM_STDOUT = 1; +const STDIO_STREAM_STDERR = 2; +const __PATCHED_CONSOLE_METHOD = Symbol.for("dagger.io/jest.console.telemetry"); +let __emittingConsoleTelemetry = false; + +type ConsoleMethodName = "debug" | "error" | "info" | "log" | "warn"; +type ConsoleStream = "stderr" | "stdout"; + +function __prepareLogExporterEnv(): void { + if (!process.env.OTEL_EXPORTER_OTLP_ENDPOINT) { + __setEnvIfUnset( + "OTEL_EXPORTER_OTLP_LOGS_ENDPOINT", + __logEndpoint(process.env.OTEL_EXPORTER_OTLP_TRACES_ENDPOINT), + ); + } + + __setEnvIfUnset( + "OTEL_EXPORTER_OTLP_LOGS_PROTOCOL", + process.env.OTEL_EXPORTER_OTLP_TRACES_PROTOCOL ?? process.env.OTEL_EXPORTER_OTLP_PROTOCOL, + ); +} + +function __setEnvIfUnset(name: string, value?: string): void { + if (process.env[name] === undefined && value !== undefined) { + process.env[name] = value; + } +} + +function __logEndpoint(endpoint?: string): string | undefined { + const logEndpoint = endpoint?.replace(/\/v1\/traces\/?$/, "/v1/logs"); + return logEndpoint !== endpoint ? logEndpoint : undefined; +} + +function __tracer() { + return trace.getTracer("dagger.io/jest"); +} + +function __logger() { + return logs.getLogger("dagger.io/jest"); +} + +function __consoleTypeStream(type: string): ConsoleStream | undefined { + if (type === "error" || type === "warn") { + return "stderr"; + } + if (type === "debug" || type === "info" || type === "log") { + return "stdout"; + } + return undefined; +} + +function __emitConsoleTelemetry(stream: ConsoleStream, body: string): void { + if (__emittingConsoleTelemetry) { + return; + } + + const activeContext = context.active(); + const activeSpan = trace.getSpan(activeContext); + if (!activeSpan || !isSpanContextValid(activeSpan.spanContext())) { + return; + } + + __emittingConsoleTelemetry = true; + try { + __logger().emit({ + timestamp: Date.now(), + observedTimestamp: Date.now(), + severityNumber: stream === "stderr" ? SeverityNumber.ERROR : SeverityNumber.INFO, + severityText: stream === "stderr" ? "ERROR" : "INFO", + body, + attributes: { + [STDIO_STREAM_ATTR]: stream === "stderr" ? STDIO_STREAM_STDERR : STDIO_STREAM_STDOUT, + }, + context: activeContext, + }); + } catch { + // Do not let telemetry log emission affect the test run. + } finally { + __emittingConsoleTelemetry = false; + } +} // A function that take any jest environment and add otel instrumentation on existing tests. export function wrapEnvironmentClass(BaseEnv: typeof TestEnvironment): any { @@ -76,8 +160,10 @@ export function wrapEnvironmentClass(BaseEnv: typeof TestEnvironment): any { const apiKey = Symbol.for("opentelemetry.js.api.1"); (this.global as any)[apiKey] = (globalThis as any)[apiKey]; + this.patchConsoleTelemetry(); + // Create a testspan and root context based on the test filename. - this.__topLevelSpan = tracer.startSpan( + this.__topLevelSpan = __tracer().startSpan( this.__testfile, { attributes: { @@ -99,9 +185,11 @@ export function wrapEnvironmentClass(BaseEnv: typeof TestEnvironment): any { // the test span context so any span created inside it will be correctly // nested. if (event.name === "test_start") { + this.patchConsoleTelemetry(); + const ctx = this.getOrCreateContext(event.test.parent); - const testSpan = tracer.startSpan( + const testSpan = __tracer().startSpan( event.test.name, { attributes: this.testSpanAttributes(event.test) }, ctx, @@ -173,7 +261,7 @@ export function wrapEnvironmentClass(BaseEnv: typeof TestEnvironment): any { event.describeBlock.name !== JEST_ROOT_BLOCK_NAME ) { const ctx = this.getOrCreateContext(event.describeBlock.parent); - const span = tracer.startSpan( + const span = __tracer().startSpan( event.describeBlock.name, { attributes: this.testSuiteSpanAttributes(event.describeBlock) }, ctx, @@ -246,6 +334,116 @@ export function wrapEnvironmentClass(BaseEnv: typeof TestEnvironment): any { // Utility functions ////// + patchConsoleTelemetry(): void { + const testConsole = (this.global as any).console; + if (!testConsole) { + return; + } + + if (this.patchBufferedConsole(testConsole)) { + return; + } + + if (this.patchJestConsole(testConsole)) { + return; + } + + this.patchConsoleMethod(testConsole, "debug", "stdout"); + this.patchConsoleMethod(testConsole, "info", "stdout"); + this.patchConsoleMethod(testConsole, "log", "stdout"); + this.patchConsoleMethod(testConsole, "warn", "stderr"); + this.patchConsoleMethod(testConsole, "error", "stderr"); + } + + patchBufferedConsole(testConsole: any): boolean { + const consoleCtor = testConsole.constructor as + | { write?: ((...args: any[]) => any) & { [__PATCHED_CONSOLE_METHOD]?: boolean } } + | undefined; + const current = consoleCtor?.write; + + if (!consoleCtor || typeof current !== "function") { + return false; + } + if (current[__PATCHED_CONSOLE_METHOD]) { + return true; + } + + const patched = function patchedBufferedConsoleWrite(this: any, ...args: any[]) { + const [, type, message] = args; + const stream = __consoleTypeStream(String(type)); + if (stream) { + __emitConsoleTelemetry( + stream, + `${typeof message === "string" ? message : format(message)}\n`, + ); + } + return current.apply(this, args); + } as typeof current; + + patched[__PATCHED_CONSOLE_METHOD] = true; + consoleCtor.write = patched; + return true; + } + + patchJestConsole(testConsole: any): boolean { + let patched = false; + patched = this.patchJestConsoleMethod(testConsole, "_log", "stdout") || patched; + patched = this.patchJestConsoleMethod(testConsole, "_logError", "stderr") || patched; + return patched; + } + + patchJestConsoleMethod( + testConsole: any, + method: string, + fallbackStream: ConsoleStream, + ): boolean { + const current = testConsole[method] as + | (((...args: any[]) => any) & { + [__PATCHED_CONSOLE_METHOD]?: boolean; + }) + | undefined; + + if (typeof current !== "function") { + return false; + } + if (current[__PATCHED_CONSOLE_METHOD]) { + return true; + } + + const patched = function patchedJestConsoleMethod(this: any, ...args: any[]) { + const [type, message] = args; + const stream = __consoleTypeStream(String(type)) ?? fallbackStream; + __emitConsoleTelemetry( + stream, + `${typeof message === "string" ? message : format(message)}\n`, + ); + return current.apply(this, args); + } as typeof current; + + patched[__PATCHED_CONSOLE_METHOD] = true; + testConsole[method] = patched; + return true; + } + + patchConsoleMethod(testConsole: any, method: ConsoleMethodName, stream: ConsoleStream): void { + const current = testConsole[method] as + | (((...args: any[]) => void) & { [__PATCHED_CONSOLE_METHOD]?: boolean }) + | undefined; + + if (typeof current !== "function" || current[__PATCHED_CONSOLE_METHOD]) { + return; + } + + const original = current.bind(testConsole); + const patched = ((...args: any[]) => { + __emitConsoleTelemetry(stream, `${format(...args)}\n`); + return original(...args); + }) as typeof current; + + patched[__PATCHED_CONSOLE_METHOD] = true; + testConsole[method] = patched; + } + /** * Return the attributes for a Jest test case span. */ diff --git a/tests/log_output_toolchain_local/dagger.json b/tests/log_output_toolchain_local/dagger.json new file mode 100644 index 0000000..24bb1ad --- /dev/null +++ b/tests/log_output_toolchain_local/dagger.json @@ -0,0 +1,16 @@ +{ + "name": "jest-log-output", + "engineVersion": "v0.19.10", + "toolchains": [ + { + "name": "jest", + "source": "../../", + "customizations": [ + { + "argument": "source", + "defaultPath": "/tests/log_output_toolchain_local" + } + ] + } + ] +} diff --git a/tests/log_output_toolchain_local/log-output.test.js b/tests/log_output_toolchain_local/log-output.test.js new file mode 100644 index 0000000..b8d0ea5 --- /dev/null +++ b/tests/log_output_toolchain_local/log-output.test.js @@ -0,0 +1,26 @@ +const delay = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); + +describe("OTel log routing example", () => { + test("routes stdout and stderr to the first test", () => { + console.log("[otel-log-routing:first] stdout from first test"); + console.error("[otel-log-routing:first] stderr from first test"); + + expect(true).toBe(true); + }); + + test("routes async logs to the second test", async () => { + console.log("[otel-log-routing:second] stdout before await"); + await delay(25); + console.error("[otel-log-routing:second] stderr after await"); + + expect(1 + 1).toBe(2); + }); + + describe("nested suite", () => { + test("keeps nested test logs under the nested test", () => { + console.log("[otel-log-routing:nested] stdout from nested test"); + + expect("nested").toContain("nest"); + }); + }); +}); diff --git a/tests/log_output_toolchain_local/package.json b/tests/log_output_toolchain_local/package.json new file mode 100644 index 0000000..c9bf1cf --- /dev/null +++ b/tests/log_output_toolchain_local/package.json @@ -0,0 +1,13 @@ +{ + "name": "jest-log-output-example", + "version": "1.0.0", + "private": true, + "type": "module", + "scripts": { + "test": "NODE_OPTIONS=\"$NODE_OPTIONS --experimental-vm-modules --import @dagger.io/jest/register\" jest" + }, + "devDependencies": { + "@dagger.io/jest": "file:../..", + "jest": "^30.2.0" + } +}