Use miniflare's handleStructuredLogs option instead of handleRuntimeStdio for processing workerd output

.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.

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<MiniflareOptions>;
 
@@ -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);

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__");
+});