From 3a1d99d6805a2b658cd31ff366d8aa9d6ce4e583 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Mon, 30 Mar 2026 22:55:32 +0100 Subject: [PATCH] Use miniflare's `handleStructuredLogs` option instead of `handleRuntimeStdio` for processing workerd output --- .../vitest-pool-workers-structured-logs.md | 7 ++ .../vitest-pool-workers/src/pool/index.ts | 68 ++++++++++++------- .../test/structured-logs.test.ts | 35 ++++++++++ 3 files changed, 86 insertions(+), 24 deletions(-) create mode 100644 .changeset/vitest-pool-workers-structured-logs.md create mode 100644 packages/vitest-pool-workers/test/structured-logs.test.ts diff --git a/.changeset/vitest-pool-workers-structured-logs.md b/.changeset/vitest-pool-workers-structured-logs.md new file mode 100644 index 0000000000..1c3f1c4648 --- /dev/null +++ b/.changeset/vitest-pool-workers-structured-logs.md @@ -0,0 +1,7 @@ +--- +"@cloudflare/vitest-pool-workers": patch +--- + +Use miniflare's `handleStructuredLogs` option instead of `handleRuntimeStdio` for processing workerd output + +Previously, `vitest-pool-workers` manually processed raw stdout/stderr streams from the workerd runtime via `handleRuntimeStdio`, with its own filtering of known noisy messages (e.g. LLVM symbolizer warnings). This switches to miniflare's `handleStructuredLogs` option, which parses workerd's structured JSON log output and automatically filters known unhelpful messages. This aligns with how both `wrangler` and `vite-plugin-cloudflare` handle workerd logs. diff --git a/packages/vitest-pool-workers/src/pool/index.ts b/packages/vitest-pool-workers/src/pool/index.ts index 2259668fd4..1605656c92 100644 --- a/packages/vitest-pool-workers/src/pool/index.ts +++ b/packages/vitest-pool-workers/src/pool/index.ts @@ -34,8 +34,12 @@ import type { WorkersPoolOptions, WorkersPoolOptionsWithDefines, } from "./config"; -import type { MiniflareOptions, SharedOptions, WorkerOptions } from "miniflare"; -import type { Readable } from "node:stream"; +import type { + MiniflareOptions, + SharedOptions, + WorkerOptions, + WorkerdStructuredLog, +} from "miniflare"; import type { TestProject, Vitest } from "vitest/node"; export function structuredSerializableStringify(value: unknown): string { @@ -75,32 +79,34 @@ const POOL_WORKER_PATH = path.join(DIST_PATH, "worker/index.mjs"); const symbolizerWarning = "warning: Not symbolizing stack traces because $LLVM_SYMBOLIZER is not set."; const ignoreMessages = [ + symbolizerWarning, // Not user actionable // TODO(someday): this is normal operation and really shouldn't error "disconnected: operation canceled", "disconnected: worker_do_not_log; Request failed due to internal error", "disconnected: WebSocket was aborted", ]; -function trimSymbolizerWarning(chunk: string): string { - return chunk.includes(symbolizerWarning) - ? chunk.substring(chunk.indexOf("\n") + 1) - : chunk; -} -function handleRuntimeStdio(stdout: Readable, stderr: Readable): void { - stdout.on("data", (chunk: Buffer) => { - process.stdout.write(chunk); - }); - stderr.on("data", (chunk: Buffer) => { - const str = trimSymbolizerWarning(chunk.toString()); - if (ignoreMessages.some((message) => str.includes(message))) { - return; - } - process.stderr.write(str); - }); +function handleStructuredLogs({ level, message }: WorkerdStructuredLog): void { + if (ignoreMessages.some((ignore) => message.includes(ignore))) { + return; + } + + switch (level) { + case "error": + case "warn": + process.stderr.write(`${message}\n`); + break; + default: + process.stdout.write(`${message}\n`); + break; + } } export function getRunnerName(project: TestProject, testFile?: string) { - const name = `${WORKER_NAME_PREFIX}runner-${project.name.replace(/[^a-z0-9-]/gi, "_")}`; + const name = `${WORKER_NAME_PREFIX}runner-${project.name.replace( + /[^a-z0-9-]/gi, + "_" + )}`; if (testFile === undefined) { return name; } @@ -305,7 +311,11 @@ async function buildProjectWorkerOptions( // No compatibility date was provided, so infer the latest supported date runnerWorker.compatibilityDate ??= supportedCompatibilityDate; log.info( - `No compatibility date was provided for project ${getRelativeProjectPath(project)}, defaulting to latest supported date ${runnerWorker.compatibilityDate}.` + `No compatibility date was provided for project ${getRelativeProjectPath( + project + )}, defaulting to latest supported date ${ + runnerWorker.compatibilityDate + }.` ); } @@ -534,13 +544,19 @@ async function buildProjectWorkerOptions( worker.name === "" ) { throw new Error( - `In project ${getRelativeProjectPath(project)}, \`miniflare.workers[${i}].name\` must be non-empty` + `In project ${getRelativeProjectPath( + project + )}, \`miniflare.workers[${i}].name\` must be non-empty` ); } // ...that doesn't start with our reserved prefix if (worker.name.startsWith(WORKER_NAME_PREFIX)) { throw new Error( - `In project ${getRelativeProjectPath(project)}, \`miniflare.workers[${i}].name\` must not start with "${WORKER_NAME_PREFIX}", got ${worker.name}` + `In project ${getRelativeProjectPath( + project + )}, \`miniflare.workers[${i}].name\` must not start with "${WORKER_NAME_PREFIX}", got ${ + worker.name + }` ); } @@ -556,7 +572,7 @@ async function buildProjectWorkerOptions( const SHARED_MINIFLARE_OPTIONS: SharedOptions = { log: mfLog, verbose: true, - handleRuntimeStdio, + handleStructuredLogs, unsafeStickyBlobs: true, } satisfies Partial; @@ -645,7 +661,11 @@ export async function getProjectMiniflare( ); log.info( `Starting runtime for ${getRelativeProjectPath(project)}` + - `${mfOptions.inspectorPort !== undefined ? ` with inspector on port ${mfOptions.inspectorPort}` : ""}` + + `${ + mfOptions.inspectorPort !== undefined + ? ` with inspector on port ${mfOptions.inspectorPort}` + : "" + }` + `...` ); const mf = new Miniflare(mfOptions); diff --git a/packages/vitest-pool-workers/test/structured-logs.test.ts b/packages/vitest-pool-workers/test/structured-logs.test.ts new file mode 100644 index 0000000000..4d67c0d9d0 --- /dev/null +++ b/packages/vitest-pool-workers/test/structured-logs.test.ts @@ -0,0 +1,35 @@ +import dedent from "ts-dedent"; +import { test, vitestConfig } from "./helpers"; + +test("routes workerd structured logs to the correct output stream", async ({ + expect, + seed, + vitestRun, +}) => { + await seed({ + "vitest.config.mts": vitestConfig(), + "index.test.ts": dedent` + import { it, expect } from "vitest"; + it("emits structured logs at various levels", () => { + // __console is the original workerd console, saved before Vitest + // patches globalThis.console. Output from __console goes through + // workerd stdout -> structured log parsing -> handleStructuredLogs, + // which routes error/warn to process.stderr and everything else + // to process.stdout. + __console.log("__STDOUT_LOG__"); + __console.warn("__STDERR_WARN__"); + __console.error("__STDERR_ERROR__"); + expect(true).toBe(true); + }); + `, + }); + const result = await vitestRun(); + expect(await result.exitCode).toBe(0); + + // handleStructuredLogs routes log-level output to stdout + expect(result.stdout).toContain("__STDOUT_LOG__"); + + // handleStructuredLogs routes warn/error-level output to stderr + expect(result.stderr).toContain("__STDERR_WARN__"); + expect(result.stderr).toContain("__STDERR_ERROR__"); +});