fix(miniflare): improve log formatting with error cause (#9843)

Author: edmundhung

.changeset/plain-views-drop.md

@@ -0,0 +1,5 @@
+---
+"miniflare": minor
+---
+
+Improved error logging to include error causes in stack traces with internal stack frames removed.

packages/miniflare/src/plugins/core/errors/index.ts

@@ -3,7 +3,7 @@ import path from "path";
 import { fileURLToPath } from "url";
 import { z } from "zod";
 import { Request, Response } from "../../../http";
-import { Log } from "../../../shared";
+import { Log, processStackTrace } from "../../../shared";
 import { maybeParseURL } from "../../shared";
 import {
 	contentsToString,
@@ -235,7 +235,14 @@ export function reviveError(
 	error.stack = jsonError.stack;
 
 	// Try to apply source-mapping to the stack trace
-	error.stack = getSourceMappedStack(workerSrcOpts, error);
+	error.stack = processStackTrace(
+		getSourceMappedStack(workerSrcOpts, error),
+		(line, location) =>
+			!location.includes(".wrangler/tmp") &&
+			!location.includes("wrangler/templates/middleware")
+				? line
+				: null
+	);
 
 	return error;
 }
@@ -278,19 +285,6 @@ export async function handlePrettyErrorRequest(
 	const youch = new Youch();
 
 	youch.useTransformer((error) => {
-		error.frames = error.frames
-			.filter(
-				(frame) =>
-					!frame.fileName?.includes(".wrangler/tmp") &&
-					!frame.fileName?.includes("wrangler/templates/middleware")
-			)
-			.map((frame) => {
-				// To avoid Youch throwing an error if the frame has no fileName
-				// This happens in tests which hides some parts of the stack trace
-				frame.fileName ??= "";
-
-				return frame;
-			});
 		error.hint = [
 			'<a href="https://developers.cloudflare.com/workers/" target="_blank" style="text-decoration:none;font-style:normal;padding:5px">📚 Workers Docs</a>',
 			'<a href="https://discord.cloudflare.com" target="_blank" style="text-decoration:none;font-style: normal;padding:5px">💬 Workers Discord</a>',

packages/miniflare/src/plugins/core/modules.ts

@@ -30,9 +30,9 @@ const builtinModulesWithPrefix = builtinModules.concat(
 
 // Module identifier used if script came from `script` option
 export function buildStringScriptPath(workerIndex: number) {
-	return `script:${workerIndex}`;
+	return `script-${workerIndex}`;
 }
-const stringScriptRegexp = /^script:(\d+)$/;
+const stringScriptRegexp = /^script-(\d+)$/;
 export function maybeGetStringScriptPathIndex(
 	scriptPath: string
 ): number | undefined {

packages/miniflare/src/shared/log.ts

@@ -35,14 +35,73 @@ export function prefixError(prefix: string, e: any): Error {
 	return e;
 }
 
-function dimInternalStackLine(line: string): string {
-	if (
-		line.startsWith("    at") &&
-		(!line.includes(cwd) || line.includes(cwdNodeModules))
-	) {
-		return dim(line);
+// Regex matches V8 stack frame lines with and without function name:
+//   at fnName (location)
+const frameRegex = /^\s*at\s+[^\s]+\s+\((.+?)\)$/;
+/**
+ * Processes a stack trace by applying a custom frame transformer.
+ * The transformer receives each frame line and its location (file:line:column);
+ * if it returns null, that frame is dropped; otherwise its return value replaces the line.
+ */
+export function processStackTrace(
+	stack: string,
+	transformFrame: (line: string, location: string) => string | null
+): string {
+	const lines = stack.split("\n");
+	const result: string[] = [];
+
+	for (const line of lines) {
+		const match = frameRegex.exec(line);
+
+		if (match) {
+			const location = match[1];
+			const transformed = transformFrame(line, location);
+			if (transformed !== null) {
+				result.push(transformed);
+			}
+
+			continue; // if transformed is null, drop the frame
+		}
+
+		// Non-frame lines (e.g., error message) are preserved
+		result.push(line);
 	}
-	return line;
+
+	return result.join("\n");
+}
+
+/**
+ * Format an error into a string, including the error cause if available.
+ *
+ * @example
+ * ```
+ * Error: Something went wrong
+ *    at Object.<anonymous> (/path/to/file.js:10:15)
+ * Caused by: Error: Another error
+ *   at Object.<anonymous> (/path/to/another-file.js:5:10)
+ * ```
+ */
+export function formatError(error: Error): string {
+	let message: string;
+
+	if (error.stack) {
+		message = processStackTrace(error.stack, (line) => {
+			if (!line.includes(cwd) || line.includes(cwdNodeModules)) {
+				// Dim internal stack trace lines to highlight user code
+				return dim(line);
+			}
+
+			return line;
+		});
+	} else {
+		message = error.toString();
+	}
+
+	if (error.cause instanceof Error) {
+		message += `\nCaused by: ${formatError(error.cause)}`;
+	}
+
+	return message;
 }
 
 export interface LogOptions {
@@ -94,15 +153,8 @@ export class Log {
 	error(message: Error): void {
 		if (this.level < LogLevel.ERROR) {
 			// Ignore message if it won't get logged
-		} else if (message.stack) {
-			// Dim internal stack trace lines to highlight user code
-			const lines = message.stack.split("\n").map(dimInternalStackLine);
-			this.logWithLevel(LogLevel.ERROR, lines.join("\n"));
 		} else {
-			this.logWithLevel(LogLevel.ERROR, message.toString());
-		}
-		if ((message as any).cause) {
-			this.error(prefixError("Cause", (message as any).cause));
+			this.logWithLevel(LogLevel.ERROR, formatError(message));
 		}
 	}
 

packages/miniflare/test/plugins/core/errors/index.spec.ts

@@ -244,7 +244,11 @@ function getSourceMapURL(
 				if (params.sourceMapURL === undefined || params.sourceMapURL === "") {
 					return;
 				}
-				sourceMapURL = new URL(params.sourceMapURL, params.url).toString();
+				// If sourceMapURL is relative
+				sourceMapURL = new URL(
+					params.sourceMapURL,
+					!params.url.startsWith("script-") ? params.url : undefined
+				).toString();
 				ws.close();
 			}
 		} catch (e) {
@@ -277,32 +281,66 @@ async function getSources(inspectorBaseURL: URL, serviceName: string) {
 		.sort();
 }
 
-// TODO(soon): just use `NoOpLog` when `Log#error()` no longer throws
-class SafeLog extends Log {
-	error(message: Error) {
-		this.logWithLevel(LogLevel.ERROR, String(message));
+class CustomLog extends Log {
+	logs: [LogLevel, string][] = [];
+
+	log(message: string): void {
+		this.logs.push([LogLevel.NONE, message]);
+	}
+
+	logWithLevel(level: LogLevel, message: string) {
+		this.logs.push([level, message]);
+	}
+
+	getLogs(level: LogLevel): string[] {
+		return this.logs
+			.filter(([logLevel]) => logLevel === level)
+			.map(([, message]) => message);
 	}
 }
 
 test("responds with pretty error page", async (t) => {
+	const log = new CustomLog();
 	const mf = new Miniflare({
-		log: new SafeLog(LogLevel.NONE),
+		log,
 		modules: true,
 		script: `
+		function doSomething() {
+			try {
+				oops();
+			} catch (e) {
+			 	throw new Error("Unusual oops!", {
+					cause: e,
+				})
+			}
+		}
+
+        function oops() {
+		  throw new Error("Test error");
+		}
+
+		// This emulates the reduceError function in the Wrangler middleware template
+		// See packages/wrangler/templates/middleware/middleware-miniflare3-json-error.ts
 		function reduceError(e) {
 			return {
 				name: e?.name,
 				message: e?.message ?? String(e),
 				stack: e?.stack,
+				cause: e?.cause === undefined ? undefined : reduceError(e.cause),
 			};
 		}
+
 		export default {
 			async fetch() {
-				const error = reduceError(new Error("Unusual oops!"));
-				return Response.json(error, {
-					status: 500,
-					headers: { "MF-Experimental-Error-Stack": "true" },
-				});
+				try {
+					doSomething();
+				} catch (e) {
+					const error = reduceError(e);
+					return Response.json(error, {
+						status: 500,
+						headers: { "MF-Experimental-Error-Stack": "true" },
+					});
+				}
 			}
 		}`,
 	});
@@ -323,6 +361,18 @@ test("responds with pretty error page", async (t) => {
 	t.regex(text, /URL.+some-unusual-path/is);
 	t.regex(text, /X-Unusual-Key.+some-unusual-value/is);
 
+	// Check error logged
+	const errorLogs = log.getLogs(LogLevel.ERROR);
+	t.deepEqual(errorLogs, [
+		`Error: Unusual oops!
+    at doSomething (script-0:6:12)
+    at Object.fetch (script-0:30:6)
+Caused by: Error: Test error
+    at oops (script-0:13:11)
+    at doSomething (script-0:4:5)
+    at Object.fetch (script-0:30:6)`,
+	]);
+
 	// Check `fetch()` accepting HTML returns pretty-error page
 	res = await fetch(url, { headers: { Accept: "text/html" } });
 	t.is(res.status, 500);

packages/miniflare/test/plugins/core/modules.spec.ts

@@ -195,7 +195,7 @@ test("Miniflare: cannot automatically collect modules without script path", asyn
 			instanceOf: MiniflareCoreError,
 			code: "ERR_MODULE_STRING_SCRIPT",
 			message:
-				'Unable to resolve "script:0" dependency: imports are unsupported in string `script` without defined `scriptPath`',
+				'Unable to resolve "script-0" dependency: imports are unsupported in string `script` without defined `scriptPath`',
 		}
 	);
 });