From 8cf184a09e130b0f3c5e10c084c391a7faa857a2 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Thu, 25 Sep 2025 18:29:12 +0100 Subject: [PATCH 01/23] vite-plugin-cloudflare: ensure that logs are printed at the correct log level --- .changeset/pretty-paths-stare.md | 7 + .../playground/vitest-setup.ts | 45 +++- .../__tests__/log-level-error/worker.spec.ts" | 12 + .../log-level-silent/worker.spec.ts" | 8 + .../__tests__/log-level-warn/worker.spec.ts" | 8 + .../__tests__/worker.spec.ts" | 8 +- .../worker-\342\231\253/src/index.ts" | 1 + .../vite.config.log-level-error.ts" | 7 + .../vite.config.log-level-silent.ts" | 7 + .../vite.config.log-level-warn.ts" | 7 + .../index.ts} | 33 +-- .../src/miniflare-options/stdio.ts | 242 ++++++++++++++++++ 12 files changed, 350 insertions(+), 35 deletions(-) create mode 100644 .changeset/pretty-paths-stare.md create mode 100644 "packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-error/worker.spec.ts" create mode 100644 "packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-silent/worker.spec.ts" create mode 100644 "packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-warn/worker.spec.ts" create mode 100644 "packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-error.ts" create mode 100644 "packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-silent.ts" create mode 100644 "packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-warn.ts" rename packages/vite-plugin-cloudflare/src/{miniflare-options.ts => miniflare-options/index.ts} (96%) create mode 100644 packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts diff --git a/.changeset/pretty-paths-stare.md b/.changeset/pretty-paths-stare.md new file mode 100644 index 00000000000..30dfa9743d5 --- /dev/null +++ b/.changeset/pretty-paths-stare.md @@ -0,0 +1,7 @@ +--- +"@cloudflare/vite-plugin": patch +--- + +Ensure that logs are printed at the correct log level + +The changes here ensure that logs generated by the workers are printed accordingly to the potential `logLevel` the user defined (either in their vite config file or via the `--logLevel` CLI flag) diff --git a/packages/vite-plugin-cloudflare/playground/vitest-setup.ts b/packages/vite-plugin-cloudflare/playground/vitest-setup.ts index ba0c842feeb..e59d336e7c9 100644 --- a/packages/vite-plugin-cloudflare/playground/vitest-setup.ts +++ b/packages/vite-plugin-cloudflare/playground/vitest-setup.ts @@ -16,6 +16,7 @@ import type { ConfigEnv, InlineConfig, Logger, + LogLevel, PluginOption, PreviewServer, ResolvedConfig, @@ -243,7 +244,8 @@ export async function loadConfig(configEnv: ConfigEnv) { customLogger: createInMemoryLogger( serverLogs.info, serverLogs.warns, - serverLogs.errors + serverLogs.errors, + config?.logLevel ), }; return mergeConfig(options, config || {}); @@ -325,11 +327,22 @@ export async function notifyRebuildComplete( return watcher.off("event", callback); } +// logLevel values taken from the vite source code: https://github.com/vitejs/vite/blob/302f8091b/packages/vite/src/node/logger.ts#L30-L35 +const logLevels: Record = { + silent: 0, + error: 1, + warn: 2, + info: 3, +}; + export function createInMemoryLogger( info: string[], warns: string[], - errors: string[] + errors: string[], + logLevel: LogLevel = "info" ): Logger { + const thresholdLogLevel = logLevels[logLevel]; + const loggedErrors = new WeakSet(); const warnedMessages = new Set(); @@ -338,22 +351,30 @@ export function createInMemoryLogger( hasErrorLogged: (err) => loggedErrors.has(err), clearScreen: () => {}, info(msg) { - info.push(msg); + if (thresholdLogLevel >= logLevels.info) { + info.push(msg); + } }, warn(msg) { - warns.push(msg); - logger.hasWarned = true; + if (thresholdLogLevel >= logLevels.warn) { + warns.push(msg); + logger.hasWarned = true; + } }, warnOnce(msg) { - if (warnedMessages.has(msg)) return; - warns.push(msg); - logger.hasWarned = true; - warnedMessages.add(msg); + if (thresholdLogLevel >= logLevels.warn) { + if (warnedMessages.has(msg)) return; + warns.push(msg); + logger.hasWarned = true; + warnedMessages.add(msg); + } }, error(msg, opts) { - errors.push(msg); - if (opts?.error) { - loggedErrors.add(opts.error); + if (thresholdLogLevel >= logLevels.error) { + errors.push(msg); + if (opts?.error) { + loggedErrors.add(opts.error); + } } }, }; diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-error/worker.spec.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-error/worker.spec.ts" new file mode 100644 index 00000000000..05c860c5edf --- /dev/null +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-error/worker.spec.ts" @@ -0,0 +1,12 @@ +import { expect, test } from "vitest"; +import { serverLogs } from "../../../__test-utils__"; + +test("basic dev logging with logLevel: error", async () => { + expect(serverLogs.info.join()).toEqual(""); + expect(serverLogs.warns.join()).toEqual(""); + + expect(serverLogs.errors.join()).toContain("__console error__"); + + // Historically we've been printing warnings as errors, that's why we also include the following check + expect(serverLogs.errors.join()).not.toContain("__console warn__"); +}); diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-silent/worker.spec.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-silent/worker.spec.ts" new file mode 100644 index 00000000000..b062f254da0 --- /dev/null +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-silent/worker.spec.ts" @@ -0,0 +1,8 @@ +import { expect, test } from "vitest"; +import { serverLogs } from "../../../__test-utils__"; + +test("basic dev logging with logLevel: silent", async () => { + expect(serverLogs.info.join()).toEqual(""); + expect(serverLogs.warns.join()).toEqual(""); + expect(serverLogs.errors.join()).toEqual(""); +}); diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-warn/worker.spec.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-warn/worker.spec.ts" new file mode 100644 index 00000000000..244a7124e38 --- /dev/null +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/log-level-warn/worker.spec.ts" @@ -0,0 +1,8 @@ +import { expect, test } from "vitest"; +import { serverLogs } from "../../../__test-utils__"; + +test("basic dev logging with logLevel: warn", async () => { + expect(serverLogs.info.join()).toEqual(""); + expect(serverLogs.warns.join()).toContain("__console warn__"); + expect(serverLogs.errors.join()).toContain("__console error__"); +}); diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/worker.spec.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/worker.spec.ts" index 0894fc2109c..c598a110808 100644 --- "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/worker.spec.ts" +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/__tests__/worker.spec.ts" @@ -26,10 +26,14 @@ test("preserves entry signatures", async () => { expect(serverLogs.info.join()).toContain("__preserves-entry-signatures__"); }); -test("basic dev logging", async () => { +test("basic dev logging (with the default logLevel: info)", async () => { expect(serverLogs.info.join()).toContain("__console log__"); + expect(serverLogs.info.join()).toContain("__console debug__"); expect(serverLogs.errors.join()).toContain("__console error__"); - expect(serverLogs.errors.join()).toContain("__console warn__"); + expect(serverLogs.warns.join()).toContain("__console warn__"); + + // Historically we've been printing warnings as errors, that's why we also include the following check + expect(serverLogs.errors.join()).not.toContain("__console warn__"); }); test("receives the original `x-forwarded-host` header if it is set", async () => { diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/src/index.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/src/index.ts" index c5e0159bbd3..ebb50008fc6 100644 --- "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/src/index.ts" +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/src/index.ts" @@ -21,6 +21,7 @@ export default { const { fn } = await import("./b"); fn(); + console.debug("__console debug__"); console.log("__console log__"); console.warn("__console warn__"); console.error("__console error__"); diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-error.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-error.ts" new file mode 100644 index 00000000000..07af8bc98c4 --- /dev/null +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-error.ts" @@ -0,0 +1,7 @@ +import { cloudflare } from "@cloudflare/vite-plugin"; +import { defineConfig } from "vite"; + +export default defineConfig({ + plugins: [cloudflare({ inspectorPort: false, persistState: false })], + logLevel: "error", +}); diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-silent.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-silent.ts" new file mode 100644 index 00000000000..d593a0b28c8 --- /dev/null +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-silent.ts" @@ -0,0 +1,7 @@ +import { cloudflare } from "@cloudflare/vite-plugin"; +import { defineConfig } from "vite"; + +export default defineConfig({ + plugins: [cloudflare({ inspectorPort: false, persistState: false })], + logLevel: "silent", +}); diff --git "a/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-warn.ts" "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-warn.ts" new file mode 100644 index 00000000000..b357f88cf87 --- /dev/null +++ "b/packages/vite-plugin-cloudflare/playground/worker-\342\231\253/vite.config.log-level-warn.ts" @@ -0,0 +1,7 @@ +import { cloudflare } from "@cloudflare/vite-plugin"; +import { defineConfig } from "vite"; + +export default defineConfig({ + plugins: [cloudflare({ inspectorPort: false, persistState: false })], + logLevel: "warn", +}); diff --git a/packages/vite-plugin-cloudflare/src/miniflare-options.ts b/packages/vite-plugin-cloudflare/src/miniflare-options/index.ts similarity index 96% rename from packages/vite-plugin-cloudflare/src/miniflare-options.ts rename to packages/vite-plugin-cloudflare/src/miniflare-options/index.ts index 45a1ef1b95e..3a7bd65ef43 100644 --- a/packages/vite-plugin-cloudflare/src/miniflare-options.ts +++ b/packages/vite-plugin-cloudflare/src/miniflare-options/index.ts @@ -23,24 +23,25 @@ import { unstable_convertConfigBindingsToStartWorkerBindings, unstable_getMiniflareWorkerOptions, } from "wrangler"; -import { getAssetsConfig } from "./asset-config"; +import { getAssetsConfig } from "../asset-config"; import { ASSET_WORKER_NAME, kRequestType, ROUTER_WORKER_NAME, VITE_PROXY_WORKER_NAME, -} from "./constants"; -import { getContainerOptions, getDockerPath } from "./containers"; -import { additionalModuleRE } from "./plugins/additional-modules"; -import { withTrailingSlash } from "./utils"; -import type { CloudflareDevEnvironment } from "./cloudflare-environment"; +} from "../constants"; +import { getContainerOptions, getDockerPath } from "../containers"; +import { additionalModuleRE } from "../plugins/additional-modules"; +import { withTrailingSlash } from "../utils"; +import { getRuntimeStdioWithStructuredLogsHandler } from "./stdio"; +import type { CloudflareDevEnvironment } from "../cloudflare-environment"; import type { AssetsOnlyResolvedConfig, PersistState, PreviewResolvedConfig, WorkerConfig, WorkersResolvedConfig, -} from "./plugin-config"; +} from "../plugin-config"; import type { MiniflareOptions, WorkerOptions } from "miniflare"; import type { FetchFunctionOptions } from "vite/module-runner"; import type { @@ -567,13 +568,8 @@ export async function getDevMiniflareOptions(config: { inspectorPort: inspectorPort === false ? undefined : inspectorPort, unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, - handleRuntimeStdio(stdout, stderr) { - const decoder = new TextDecoder(); - stdout.forEach((data) => logger.info(decoder.decode(data))); - stderr.forEach((error) => - logger.logWithLevel(LogLevel.ERROR, decoder.decode(error)) - ); - }, + structuredWorkerdLogs: true, + handleRuntimeStdio: getRuntimeStdioWithStructuredLogsHandler(logger), defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, resolvedPluginConfig.persistState @@ -856,13 +852,8 @@ export async function getPreviewMiniflareOptions(config: { inspectorPort: inspectorPort === false ? undefined : inspectorPort, unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, - handleRuntimeStdio(stdout, stderr) { - const decoder = new TextDecoder(); - stdout.forEach((data) => logger.info(decoder.decode(data))); - stderr.forEach((error) => - logger.logWithLevel(LogLevel.ERROR, decoder.decode(error)) - ); - }, + structuredWorkerdLogs: true, + handleRuntimeStdio: getRuntimeStdioWithStructuredLogsHandler(logger), defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, resolvedPluginConfig.persistState diff --git a/packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts b/packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts new file mode 100644 index 00000000000..8e9cac5cc07 --- /dev/null +++ b/packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts @@ -0,0 +1,242 @@ +/** + * Note: most of the code in this file has been copied from packages/wrangler/src/dev/miniflare/stdio.ts + * so these two files should ideally be kept as much in sync as possible + * (ideally we should have a way to share code between the two packages instead of duplicating + * code in this manner) + */ + +import { LogLevel } from "miniflare"; +import type { Log } from "miniflare"; +import type { Readable } from "node:stream"; + +/** + * Generates a handler function to pass to Miniflare instances for handling the Worker process stream. + * + * The generated function can be used when Miniflare's `structuredWorkerdLogs` option is set to `true`. + * + * @param logger The miniflare logger to use + */ +export function getRuntimeStdioWithStructuredLogsHandler(logger: Log) { + return (stdout: Readable, stderr: Readable) => { + stdout.on("data", getProcessStreamDataListener(logger, "stdout")); + stderr.on("data", getProcessStreamDataListener(logger, "stderr")); + }; +} + +/** + * Creates a listener for the "data" event of a process stream associated to Miniflare's Workerd process. + * + * This function can be used when Miniflare's `structuredWorkerdLogs` option is set to `true`. + * + * @param processStream The target process stream + * @returns the listener to set for the stream's "data" event + */ +function getProcessStreamDataListener( + logger: Log, + processStream: "stdout" | "stderr" +) { + let streamAccumulator = ""; + + return (chunk: Buffer | string) => { + const fullStreamOutput = `${streamAccumulator}${chunk}`; + + let currentLogsStr = ""; + + // Structured logs are divided by newlines so let's get the + // last one, we know that anything in between will include + // one or more structured logs + const lastNewlineIdx = fullStreamOutput.lastIndexOf("\n"); + + if (lastNewlineIdx > 0) { + // If we've found a newline we will take the structured logs + // up to that point, the rest (which is the beginning of a + // new structured log) will be saved for later + currentLogsStr = fullStreamOutput.slice(0, lastNewlineIdx); + streamAccumulator = fullStreamOutput.slice(lastNewlineIdx + 1); + } else { + // If we didn't find a newline we're dealing with a structured + // log that has been split, so let's save the whole thing for + // later (so that we can process the log once we've seen it + // in full) + streamAccumulator = fullStreamOutput; + } + + const lines = currentLogsStr.split("\n"); + + for (const line of lines) { + const structuredLog = parseStructuredLog(line); + if (structuredLog) { + logStructuredLog(logger, structuredLog, processStream); + } else { + // Unexpectedly we've received a line that is not a structured log, so we simply + // log it to the most likely appropriate logger level + if (processStream === "stdout") { + logger.info(line); + } else { + logger.logWithLevel(LogLevel.ERROR, line); + } + } + } + }; +} + +type WorkerdStructuredLog = { + timestamp: number; + level: string; + message: string; +}; + +/** + * Parses a string to obtain the potential structured log the string represents. + * + * @param str Target string + * @returns The structured log extracted from the string or null is the string doesn't represent a structured log + */ +function parseStructuredLog(str: string): WorkerdStructuredLog | null { + try { + const maybeStructuredLog = JSON.parse(str) as Record; + + if (typeof maybeStructuredLog !== "object" || maybeStructuredLog === null) { + return null; + } + + const timestamp = parseInt(maybeStructuredLog.timestamp ?? ""); + + if ( + isNaN(timestamp) || + typeof maybeStructuredLog.level !== "string" || + typeof maybeStructuredLog.message !== "string" + ) { + return null; + } + + return { + timestamp, + level: maybeStructuredLog.level, + message: maybeStructuredLog.message, + }; + } catch { + return null; + } +} + +/** + * Logs a structured log in the most appropriate way on the most appropriate log level. + * + * @param structuredLog The structured log to print + * @param processStream The process stream from where the structured log comes from + */ +function logStructuredLog( + logger: Log, + { level, message }: WorkerdStructuredLog, + processStream: "stdout" | "stderr" +): void { + // TODO: the following code analyzes the message without considering its log level, + // ideally, in order to avoid false positives, we should run this logic scoped + // to the relevant log levels (as we do for `isCodeMovedWarning`) + if (messageClassifiers.isBarf(message)) { + // this is a big chonky barf from workerd that we want to hijack to cleanup/ignore + + // CLEANABLE: + // known case to cleanup: Address in use errors + if (messageClassifiers.isAddressInUse(message)) { + const address = message.match( + /Address already in use; toString\(\) = (.+)\n/ + )?.[1]; + + logger.logWithLevel( + LogLevel.ERROR, + `Address already in use (${address}). Please check that you are not already running a server on this address or specify a different port with --port.` + ); + + // Also log the original error to the debug logs. + return logger.info(message); + } + + // In the past we have seen Access Violation errors on Windows, which may be caused by an outdated + // version of the Windows OS or the Microsoft Visual C++ Redistributable. + // See https://github.com/cloudflare/workers-sdk/issues/6170#issuecomment-2245209918 + if (messageClassifiers.isAccessViolation(message)) { + let error = "There was an access violation in the runtime."; + if (process.platform === "win32") { + error += + "\nOn Windows, this may be caused by an outdated Microsoft Visual C++ Redistributable library.\n" + + "Check that you have the latest version installed.\n" + + "See https://learn.microsoft.com/en-us/cpp/windows/latest-supported-vc-redist."; + } + + logger.logWithLevel(LogLevel.ERROR, error); + + // Also log the original error to the debug logs. + return logger.info(message); + } + + // IGNORABLE: + // anything else not handled above is considered ignorable + // so send it to the debug logs which are discarded unless + // the user explicitly sets a logLevel indicating they care + return logger.info(message); + } + + if ( + (level === "info" || level === "error") && + messageClassifiers.isCodeMovedWarning(message) + ) { + // known case: "error: CODE_MOVED for unknown code block?", warning for workerd devs, not application devs + // ignore entirely, don't even send it to the debug log file + // workerd references: + // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L566 + // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L572 + return; + } + + if (level === "warn") { + return logger.warn(message); + } + + if (level === "info" || level === "debug") { + return logger.info(message); + } + + if (level === "error") { + return logger.logWithLevel(LogLevel.ERROR, message); + } + + if (processStream === "stderr") { + return logger.logWithLevel(LogLevel.ERROR, message); + } else { + return logger.info(message); + } +} + +const messageClassifiers = { + // Is this chunk a big chonky barf from workerd that we want to hijack to cleanup/ignore? + isBarf(chunk: string) { + const containsLlvmSymbolizerWarning = chunk.includes( + "Not symbolizing stack traces because $LLVM_SYMBOLIZER is not set" + ); + const containsRecursiveIsolateLockWarning = chunk.includes( + "took recursive isolate lock" + ); + // Matches stack traces from workerd + // - on unix: groups of 9 hex digits separated by spaces + // - on windows: groups of 12 hex digits, or a single digit 0, separated by spaces + const containsHexStack = /stack:( (0|[a-f\d]{4,})){3,}/.test(chunk); + + return ( + containsLlvmSymbolizerWarning || + containsRecursiveIsolateLockWarning || + containsHexStack + ); + }, + // Is this chunk an Address In Use error? + isAddressInUse(chunk: string) { + return chunk.includes("Address already in use; toString() = "); + }, + isCodeMovedWarning(chunk: string) { + return /CODE_MOVED for unknown code block/.test(chunk); + }, + isAccessViolation(chunk: string) { + return chunk.includes("access violation;"); + }, +}; From cb0d8d32b4f390132ba225fb35a0abed3b7286eb Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Tue, 14 Oct 2025 22:30:01 +0100 Subject: [PATCH 02/23] move shared logic inside miniflare and expose new `handleStructuredLogs` option --- .changeset/fancy-spoons-chew.md | 5 + .changeset/grumpy-signs-jam.md | 5 + .changeset/stupid-ads-enter.md | 5 + packages/miniflare/src/index.ts | 14 + packages/miniflare/src/plugins/core/index.ts | 13 + packages/miniflare/src/runtime/index.ts | 21 +- .../miniflare/src/runtime/structured-logs.ts | 186 ++++++++++++++ packages/miniflare/src/shared/error.ts | 1 + .../index.ts => miniflare-options.ts} | 46 +++- .../src/miniflare-options/stdio.ts | 242 ------------------ packages/wrangler/src/dev/miniflare/index.ts | 38 ++- packages/wrangler/src/dev/miniflare/stdio.ts | 240 ----------------- 12 files changed, 319 insertions(+), 497 deletions(-) create mode 100644 .changeset/fancy-spoons-chew.md create mode 100644 .changeset/grumpy-signs-jam.md create mode 100644 .changeset/stupid-ads-enter.md create mode 100644 packages/miniflare/src/runtime/structured-logs.ts rename packages/vite-plugin-cloudflare/src/{miniflare-options/index.ts => miniflare-options.ts} (96%) delete mode 100644 packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts delete mode 100644 packages/wrangler/src/dev/miniflare/stdio.ts diff --git a/.changeset/fancy-spoons-chew.md b/.changeset/fancy-spoons-chew.md new file mode 100644 index 00000000000..affb0e45c19 --- /dev/null +++ b/.changeset/fancy-spoons-chew.md @@ -0,0 +1,5 @@ +--- +"wrangler": patch +--- + +Update logs handling via the new `handleStructuredLogs` miniflare option diff --git a/.changeset/grumpy-signs-jam.md b/.changeset/grumpy-signs-jam.md new file mode 100644 index 00000000000..527b3d19da7 --- /dev/null +++ b/.changeset/grumpy-signs-jam.md @@ -0,0 +1,5 @@ +--- +"@vite-plugin-cloudflare": patch +--- + +Improve how the plugin prints the workerd logged (making sure that all the logs are printed on the correct log level) diff --git a/.changeset/stupid-ads-enter.md b/.changeset/stupid-ads-enter.md new file mode 100644 index 00000000000..8b23a6a5b32 --- /dev/null +++ b/.changeset/stupid-ads-enter.md @@ -0,0 +1,5 @@ +--- +"miniflare": patch +--- + +Add `handleStructuredLogs` option that allows consumers of the workerd structured logs to print such logs without additional necessary boilerplate diff --git a/packages/miniflare/src/index.ts b/packages/miniflare/src/index.ts index 83e693dcddc..9b314f187b9 100644 --- a/packages/miniflare/src/index.ts +++ b/packages/miniflare/src/index.ts @@ -81,6 +81,7 @@ import { NameSourceOptions, reviveError, ServiceDesignatorSchema, + WorkerdStructuredLog, } from "./plugins/core"; import { InspectorProxyController } from "./plugins/core/inspector-proxy"; import { imagesLocalFetcher } from "./plugins/images/fetcher"; @@ -1965,6 +1966,16 @@ export class Miniflare { requiredSockets.push(kInspectorSocket); } + if ( + !this.#sharedOpts.core.structuredWorkerdLogs && + this.#sharedOpts.core.handleStructuredLogs + ) { + throw new MiniflareCoreError( + "ERR_INVALID_STRUCTURED_LOGS_HANDLER", + "A `handleStructuredLogs` has been provided but `structuredWorkerdLogs` is set to `false`" + ); + } + // Reload runtime const entryAddress = this.#getSocketAddress( SOCKET_ENTRY, @@ -1997,6 +2008,7 @@ export class Miniflare { inspectorAddress: runtimeInspectorAddress, verbose: this.#sharedOpts.core.verbose, handleRuntimeStdio: this.#sharedOpts.core.handleRuntimeStdio, + handleStructuredLogs: this.#sharedOpts.core.handleStructuredLogs, }; const maybeSocketPorts = await this.#runtime.updateConfig( configBuffer, @@ -2690,6 +2702,8 @@ export class Miniflare { } } +export type { WorkerdStructuredLog } from "./plugins/core"; + export * from "./http"; export * from "./plugins"; export * from "./runtime"; diff --git a/packages/miniflare/src/plugins/core/index.ts b/packages/miniflare/src/plugins/core/index.ts index 2e97d8bf381..07afefab77c 100644 --- a/packages/miniflare/src/plugins/core/index.ts +++ b/packages/miniflare/src/plugins/core/index.ts @@ -216,6 +216,14 @@ export const CoreOptionsSchema = CoreOptionsSchemaInput.transform((value) => { return value; }); +export type WorkerdStructuredLog = z.infer; + +const workerdStructuredLogSchema = z.object({ + timestamp: z.number(), + level: z.string(), + message: z.string(), +}); + export const CoreSharedOptionsSchema = z.object({ rootPath: UnusableStringSchema.optional(), @@ -237,6 +245,11 @@ export const CoreSharedOptionsSchema = z.object({ .function(z.tuple([z.instanceof(Readable), z.instanceof(Readable)])) .optional(), + handleStructuredLogs: z + .function(z.tuple([workerdStructuredLogSchema])) + .returns(z.void()) + .optional(), + upstream: z.string().optional(), // TODO: add back validation of cf object cf: z.union([z.boolean(), z.string(), z.record(z.any())]).optional(), diff --git a/packages/miniflare/src/runtime/index.ts b/packages/miniflare/src/runtime/index.ts index d76bfde46b7..2caf580e761 100644 --- a/packages/miniflare/src/runtime/index.ts +++ b/packages/miniflare/src/runtime/index.ts @@ -11,8 +11,10 @@ import workerdPath, { } from "workerd"; import { z } from "zod"; import { SERVICE_LOOPBACK, SOCKET_ENTRY } from "../plugins"; +import { WorkerdStructuredLog } from "../plugins/core"; import { MiniflareCoreError } from "../shared"; import { Awaitable } from "../workers"; +import { getProcessStructuredLogStreamListener } from "./structured-logs"; const ControlMessageSchema = z.discriminatedUnion("event", [ z.object({ @@ -37,6 +39,7 @@ export interface RuntimeOptions { inspectorAddress?: string; verbose?: boolean; handleRuntimeStdio?: (stdout: Readable, stderr: Readable) => void; + handleStructuredLogs?: (structuredLog: WorkerdStructuredLog) => void; } async function waitForPorts( @@ -226,13 +229,29 @@ export class Runtime { this.#process = runtimeProcess; this.#processExitPromise = waitForExit(runtimeProcess); - const handleRuntimeStdio = options.handleRuntimeStdio ?? pipeOutput; + const handleRuntimeStdio = + options.handleRuntimeStdio ?? + (options.handleStructuredLogs + ? // If `handleStructuredLogs` is provided then be default Miniflare should not pipe through the stream's output + () => {} + : pipeOutput); handleRuntimeStdio( runtimeProcess.stdout.pipe(startupLogBuffer.stdoutStream), runtimeProcess.stderr.pipe(startupLogBuffer.stderrStream) ); + if (options.handleStructuredLogs) { + runtimeProcess.stdout.on( + "data", + getProcessStructuredLogStreamListener(options.handleStructuredLogs) + ); + runtimeProcess.stderr.on( + "data", + getProcessStructuredLogStreamListener(options.handleStructuredLogs) + ); + } + const controlPipe = runtimeProcess.stdio[3]; assert(controlPipe instanceof Readable); diff --git a/packages/miniflare/src/runtime/structured-logs.ts b/packages/miniflare/src/runtime/structured-logs.ts new file mode 100644 index 00000000000..d765fb8407f --- /dev/null +++ b/packages/miniflare/src/runtime/structured-logs.ts @@ -0,0 +1,186 @@ +import { WorkerdStructuredLog } from "../plugins/core"; + +/** + * TODO + */ +export function getProcessStructuredLogStreamListener( + structuredLogsHandler: (structuredLog: WorkerdStructuredLog) => void +) { + let streamAccumulator = ""; + + return (chunk: Buffer | string) => { + const fullStreamOutput = `${streamAccumulator}${chunk}`; + + let currentLogsStr = ""; + + // Structured logs are divided by newlines so let's get the + // last one, we know that anything in between will include + // one or more structured logs + const lastNewlineIdx = fullStreamOutput.lastIndexOf("\n"); + + const adjustedStructuredLogsHandler = getAdjustedStructuredLogsHandler( + structuredLogsHandler + ); + + if (lastNewlineIdx > 0) { + // If we've found a newline we will take the structured logs + // up to that point, the rest (which is the beginning of a + // new structured log) will be saved for later + currentLogsStr = fullStreamOutput.slice(0, lastNewlineIdx); + streamAccumulator = fullStreamOutput.slice(lastNewlineIdx + 1); + } else { + // If we didn't find a newline we're dealing with a structured + // log that has been split, so let's save the whole thing for + // later (so that we can process the log once we've seen it + // in full) + streamAccumulator = fullStreamOutput; + } + + const lines = currentLogsStr.split("\n"); + + for (const line of lines) { + const structuredLog = parseStructuredLog(line); + if (structuredLog) { + adjustedStructuredLogsHandler(structuredLog); + } else { + // Unexpectedly we've received a line that is not a structured log. + // We then log it at an unknown level. + adjustedStructuredLogsHandler({ + timestamp: Date.now(), + level: "unknown", + message: line, + }); + } + } + }; +} + +const messageClassifiers = { + // Is this chunk a big chonky barf from workerd that we want to hijack to cleanup/ignore? + isBarf(chunk: string) { + const containsLlvmSymbolizerWarning = chunk.includes( + "Not symbolizing stack traces because $LLVM_SYMBOLIZER is not set" + ); + const containsRecursiveIsolateLockWarning = chunk.includes( + "took recursive isolate lock" + ); + // Matches stack traces from workerd + // - on unix: groups of 9 hex digits separated by spaces + // - on windows: groups of 12 hex digits, or a single digit 0, separated by spaces + const containsHexStack = /stack:( (0|[a-f\d]{4,})){3,}/.test(chunk); + + return ( + containsLlvmSymbolizerWarning || + containsRecursiveIsolateLockWarning || + containsHexStack + ); + }, + // Is this chunk an Address In Use error? + isAddressInUse(chunk: string) { + return chunk.includes("Address already in use; toString() = "); + }, + isCodeMovedWarning(chunk: string) { + return /CODE_MOVED for unknown code block/.test(chunk); + }, + isAccessViolation(chunk: string) { + return chunk.includes("access violation;"); + }, +}; + +function getAdjustedStructuredLogsHandler( + structuredLogsHandler: (structuredLog: WorkerdStructuredLog) => void +) { + return (structuredLog: WorkerdStructuredLog) => { + // TODO: the following code analyzes the message without considering its log level, + // ideally, in order to avoid false positives, we should run this logic scoped + // to the relevant log levels (as we do for `isCodeMovedWarning`) + if (messageClassifiers.isBarf(structuredLog.message)) { + // this is a big chonky barf from workerd that we want to hijack to cleanup/ignore + + // CLEANABLE: + // known case to cleanup: Address in use errors + if (messageClassifiers.isAddressInUse(structuredLog.message)) { + const address = structuredLog.message.match( + /Address already in use; toString\(\) = (.+)\n/ + )?.[1]; + + return structuredLogsHandler({ + timestamp: structuredLog.timestamp, + level: "error", + message: `Address already in use (${address}). Please check that you are not already running a server on this address or specify a different port with --port.`, + }); + } + + // In the past we have seen Access Violation errors on Windows, which may be caused by an outdated + // version of the Windows OS or the Microsoft Visual C++ Redistributable. + // See https://github.com/cloudflare/workers-sdk/issues/6170#issuecomment-2245209918 + if (messageClassifiers.isAccessViolation(structuredLog.message)) { + let error = "There was an access violation in the runtime."; + if (process.platform === "win32") { + error += + "\nOn Windows, this may be caused by an outdated Microsoft Visual C++ Redistributable library.\n" + + "Check that you have the latest version installed.\n" + + "See https://learn.microsoft.com/en-us/cpp/windows/latest-supported-vc-redist."; + } + + return structuredLogsHandler({ + timestamp: structuredLog.timestamp, + level: "error", + message: error, + }); + } + + // IGNORABLE: + // anything else not handled above is considered ignorable + return; + } + + if ( + (structuredLog.level === "info" || structuredLog.level === "error") && + messageClassifiers.isCodeMovedWarning(structuredLog.message) + ) { + // known case: "error: CODE_MOVED for unknown code block?", warning for workerd devs, not application devs + // ignore entirely, don't even send it to the debug log file + // workerd references: + // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L566 + // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L572 + return; + } + + return structuredLogsHandler(structuredLog); + }; +} + +/** + * Parses a string to obtain the potential structured log the string represents. + * + * @param str Target string + * @returns The structured log extracted from the string or null is the string doesn't represent a structured log + */ +function parseStructuredLog(str: string): WorkerdStructuredLog | null { + try { + const maybeStructuredLog = JSON.parse(str) as Record; + + if (typeof maybeStructuredLog !== "object" || maybeStructuredLog === null) { + return null; + } + + const timestamp = parseInt(maybeStructuredLog.timestamp); + + if ( + isNaN(timestamp) || + typeof maybeStructuredLog.level !== "string" || + typeof maybeStructuredLog.message !== "string" + ) { + return null; + } + + return { + timestamp, + level: maybeStructuredLog.level, + message: maybeStructuredLog.message, + }; + } catch { + return null; + } +} diff --git a/packages/miniflare/src/shared/error.ts b/packages/miniflare/src/shared/error.ts index fd500c18221..a773522da6f 100644 --- a/packages/miniflare/src/shared/error.ts +++ b/packages/miniflare/src/shared/error.ts @@ -16,6 +16,7 @@ export const USER_ERROR_CODES = new Set([ "ERR_MULTIPLE_OUTBOUNDS", // Both `outboundService` and `fetchMock` specified "ERR_INVALID_WRAPPED", // Worker not allowed to be used as wrapped binding "ERR_MISSING_INSPECTOR_PROXY_PORT", // An inspector proxy has been requested but no inspector port to use has been specified + "ERR_INVALID_STRUCTURED_LOGS_HANDLER", // A handler for structured logs has been provided but without using structured logs ] as const); export const SYSTEM_ERROR_CODES = new Set([ diff --git a/packages/vite-plugin-cloudflare/src/miniflare-options/index.ts b/packages/vite-plugin-cloudflare/src/miniflare-options.ts similarity index 96% rename from packages/vite-plugin-cloudflare/src/miniflare-options/index.ts rename to packages/vite-plugin-cloudflare/src/miniflare-options.ts index 3a7bd65ef43..99e391d1ebe 100644 --- a/packages/vite-plugin-cloudflare/src/miniflare-options/index.ts +++ b/packages/vite-plugin-cloudflare/src/miniflare-options.ts @@ -23,26 +23,29 @@ import { unstable_convertConfigBindingsToStartWorkerBindings, unstable_getMiniflareWorkerOptions, } from "wrangler"; -import { getAssetsConfig } from "../asset-config"; +import { getAssetsConfig } from "./asset-config"; import { ASSET_WORKER_NAME, kRequestType, ROUTER_WORKER_NAME, VITE_PROXY_WORKER_NAME, -} from "../constants"; -import { getContainerOptions, getDockerPath } from "../containers"; -import { additionalModuleRE } from "../plugins/additional-modules"; -import { withTrailingSlash } from "../utils"; -import { getRuntimeStdioWithStructuredLogsHandler } from "./stdio"; -import type { CloudflareDevEnvironment } from "../cloudflare-environment"; +} from "./constants"; +import { getContainerOptions, getDockerPath } from "./containers"; +import { additionalModuleRE } from "./plugins/additional-modules"; +import { withTrailingSlash } from "./utils"; +import type { CloudflareDevEnvironment } from "./cloudflare-environment"; import type { AssetsOnlyResolvedConfig, PersistState, PreviewResolvedConfig, WorkerConfig, WorkersResolvedConfig, -} from "../plugin-config"; -import type { MiniflareOptions, WorkerOptions } from "miniflare"; +} from "./plugin-config"; +import type { + MiniflareOptions, + WorkerdStructuredLog, + WorkerOptions, +} from "miniflare"; import type { FetchFunctionOptions } from "vite/module-runner"; import type { Binding, @@ -569,7 +572,7 @@ export async function getDevMiniflareOptions(config: { unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, structuredWorkerdLogs: true, - handleRuntimeStdio: getRuntimeStdioWithStructuredLogsHandler(logger), + handleStructuredLogs: getStructuredLogsLogger(logger), defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, resolvedPluginConfig.persistState @@ -852,8 +855,7 @@ export async function getPreviewMiniflareOptions(config: { inspectorPort: inspectorPort === false ? undefined : inspectorPort, unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, - structuredWorkerdLogs: true, - handleRuntimeStdio: getRuntimeStdioWithStructuredLogsHandler(logger), + handleStructuredLogs: getStructuredLogsLogger(logger), defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, resolvedPluginConfig.persistState @@ -904,3 +906,23 @@ function miniflareLogLevelFromViteLogLevel( return LogLevel.NONE; } } + +/** + * Generates a log handler to be passed as the `handleStructuredLogs` option to miniflare + * + * @param logger the vite logger to use + * @returns the log handler to pass to miniflare + */ +function getStructuredLogsLogger(logger: Log) { + return ({ level, message }: WorkerdStructuredLog) => { + if (level === "warn") { + return logger.warn(message); + } + + if (level === "error") { + return logger.logWithLevel(LogLevel.ERROR, message); + } + + return logger.info(message); + }; +} diff --git a/packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts b/packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts deleted file mode 100644 index 8e9cac5cc07..00000000000 --- a/packages/vite-plugin-cloudflare/src/miniflare-options/stdio.ts +++ /dev/null @@ -1,242 +0,0 @@ -/** - * Note: most of the code in this file has been copied from packages/wrangler/src/dev/miniflare/stdio.ts - * so these two files should ideally be kept as much in sync as possible - * (ideally we should have a way to share code between the two packages instead of duplicating - * code in this manner) - */ - -import { LogLevel } from "miniflare"; -import type { Log } from "miniflare"; -import type { Readable } from "node:stream"; - -/** - * Generates a handler function to pass to Miniflare instances for handling the Worker process stream. - * - * The generated function can be used when Miniflare's `structuredWorkerdLogs` option is set to `true`. - * - * @param logger The miniflare logger to use - */ -export function getRuntimeStdioWithStructuredLogsHandler(logger: Log) { - return (stdout: Readable, stderr: Readable) => { - stdout.on("data", getProcessStreamDataListener(logger, "stdout")); - stderr.on("data", getProcessStreamDataListener(logger, "stderr")); - }; -} - -/** - * Creates a listener for the "data" event of a process stream associated to Miniflare's Workerd process. - * - * This function can be used when Miniflare's `structuredWorkerdLogs` option is set to `true`. - * - * @param processStream The target process stream - * @returns the listener to set for the stream's "data" event - */ -function getProcessStreamDataListener( - logger: Log, - processStream: "stdout" | "stderr" -) { - let streamAccumulator = ""; - - return (chunk: Buffer | string) => { - const fullStreamOutput = `${streamAccumulator}${chunk}`; - - let currentLogsStr = ""; - - // Structured logs are divided by newlines so let's get the - // last one, we know that anything in between will include - // one or more structured logs - const lastNewlineIdx = fullStreamOutput.lastIndexOf("\n"); - - if (lastNewlineIdx > 0) { - // If we've found a newline we will take the structured logs - // up to that point, the rest (which is the beginning of a - // new structured log) will be saved for later - currentLogsStr = fullStreamOutput.slice(0, lastNewlineIdx); - streamAccumulator = fullStreamOutput.slice(lastNewlineIdx + 1); - } else { - // If we didn't find a newline we're dealing with a structured - // log that has been split, so let's save the whole thing for - // later (so that we can process the log once we've seen it - // in full) - streamAccumulator = fullStreamOutput; - } - - const lines = currentLogsStr.split("\n"); - - for (const line of lines) { - const structuredLog = parseStructuredLog(line); - if (structuredLog) { - logStructuredLog(logger, structuredLog, processStream); - } else { - // Unexpectedly we've received a line that is not a structured log, so we simply - // log it to the most likely appropriate logger level - if (processStream === "stdout") { - logger.info(line); - } else { - logger.logWithLevel(LogLevel.ERROR, line); - } - } - } - }; -} - -type WorkerdStructuredLog = { - timestamp: number; - level: string; - message: string; -}; - -/** - * Parses a string to obtain the potential structured log the string represents. - * - * @param str Target string - * @returns The structured log extracted from the string or null is the string doesn't represent a structured log - */ -function parseStructuredLog(str: string): WorkerdStructuredLog | null { - try { - const maybeStructuredLog = JSON.parse(str) as Record; - - if (typeof maybeStructuredLog !== "object" || maybeStructuredLog === null) { - return null; - } - - const timestamp = parseInt(maybeStructuredLog.timestamp ?? ""); - - if ( - isNaN(timestamp) || - typeof maybeStructuredLog.level !== "string" || - typeof maybeStructuredLog.message !== "string" - ) { - return null; - } - - return { - timestamp, - level: maybeStructuredLog.level, - message: maybeStructuredLog.message, - }; - } catch { - return null; - } -} - -/** - * Logs a structured log in the most appropriate way on the most appropriate log level. - * - * @param structuredLog The structured log to print - * @param processStream The process stream from where the structured log comes from - */ -function logStructuredLog( - logger: Log, - { level, message }: WorkerdStructuredLog, - processStream: "stdout" | "stderr" -): void { - // TODO: the following code analyzes the message without considering its log level, - // ideally, in order to avoid false positives, we should run this logic scoped - // to the relevant log levels (as we do for `isCodeMovedWarning`) - if (messageClassifiers.isBarf(message)) { - // this is a big chonky barf from workerd that we want to hijack to cleanup/ignore - - // CLEANABLE: - // known case to cleanup: Address in use errors - if (messageClassifiers.isAddressInUse(message)) { - const address = message.match( - /Address already in use; toString\(\) = (.+)\n/ - )?.[1]; - - logger.logWithLevel( - LogLevel.ERROR, - `Address already in use (${address}). Please check that you are not already running a server on this address or specify a different port with --port.` - ); - - // Also log the original error to the debug logs. - return logger.info(message); - } - - // In the past we have seen Access Violation errors on Windows, which may be caused by an outdated - // version of the Windows OS or the Microsoft Visual C++ Redistributable. - // See https://github.com/cloudflare/workers-sdk/issues/6170#issuecomment-2245209918 - if (messageClassifiers.isAccessViolation(message)) { - let error = "There was an access violation in the runtime."; - if (process.platform === "win32") { - error += - "\nOn Windows, this may be caused by an outdated Microsoft Visual C++ Redistributable library.\n" + - "Check that you have the latest version installed.\n" + - "See https://learn.microsoft.com/en-us/cpp/windows/latest-supported-vc-redist."; - } - - logger.logWithLevel(LogLevel.ERROR, error); - - // Also log the original error to the debug logs. - return logger.info(message); - } - - // IGNORABLE: - // anything else not handled above is considered ignorable - // so send it to the debug logs which are discarded unless - // the user explicitly sets a logLevel indicating they care - return logger.info(message); - } - - if ( - (level === "info" || level === "error") && - messageClassifiers.isCodeMovedWarning(message) - ) { - // known case: "error: CODE_MOVED for unknown code block?", warning for workerd devs, not application devs - // ignore entirely, don't even send it to the debug log file - // workerd references: - // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L566 - // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L572 - return; - } - - if (level === "warn") { - return logger.warn(message); - } - - if (level === "info" || level === "debug") { - return logger.info(message); - } - - if (level === "error") { - return logger.logWithLevel(LogLevel.ERROR, message); - } - - if (processStream === "stderr") { - return logger.logWithLevel(LogLevel.ERROR, message); - } else { - return logger.info(message); - } -} - -const messageClassifiers = { - // Is this chunk a big chonky barf from workerd that we want to hijack to cleanup/ignore? - isBarf(chunk: string) { - const containsLlvmSymbolizerWarning = chunk.includes( - "Not symbolizing stack traces because $LLVM_SYMBOLIZER is not set" - ); - const containsRecursiveIsolateLockWarning = chunk.includes( - "took recursive isolate lock" - ); - // Matches stack traces from workerd - // - on unix: groups of 9 hex digits separated by spaces - // - on windows: groups of 12 hex digits, or a single digit 0, separated by spaces - const containsHexStack = /stack:( (0|[a-f\d]{4,})){3,}/.test(chunk); - - return ( - containsLlvmSymbolizerWarning || - containsRecursiveIsolateLockWarning || - containsHexStack - ); - }, - // Is this chunk an Address In Use error? - isAddressInUse(chunk: string) { - return chunk.includes("Address already in use; toString() = "); - }, - isCodeMovedWarning(chunk: string) { - return /CODE_MOVED for unknown code block/.test(chunk); - }, - isAccessViolation(chunk: string) { - return chunk.includes("access violation;"); - }, -}; diff --git a/packages/wrangler/src/dev/miniflare/index.ts b/packages/wrangler/src/dev/miniflare/index.ts index 50898de2566..010871e5477 100644 --- a/packages/wrangler/src/dev/miniflare/index.ts +++ b/packages/wrangler/src/dev/miniflare/index.ts @@ -16,6 +16,7 @@ import { getImagesRemoteFetcher, } from "../../images/fetcher"; import { logger } from "../../logger"; +import { getSourceMappedString } from "../../sourcemap"; import { updateCheck } from "../../update-check"; import { warnOrError } from "../../utils/print-bindings"; import { @@ -24,7 +25,6 @@ import { MakeVectorizeFetcher, } from "../../vectorize/fetcher"; import { getClassNamesWhichUseSQLite } from "../class-names-sqlite"; -import { handleRuntimeStdioWithStructuredLogs } from "./stdio"; import type { ServiceFetch } from "../../api"; import type { AssetsOptions } from "../../assets"; import type { Config } from "../../config"; @@ -50,6 +50,7 @@ import type { MiniflareOptions, RemoteProxyConnectionString, SourceOptions, + WorkerdStructuredLog, WorkerOptions, WorkerRegistry, } from "miniflare"; @@ -1028,8 +1029,8 @@ export async function buildMiniflareOptions( logRequests: false, log, verbose: logger.loggerLevel === "debug", - handleRuntimeStdio: handleRuntimeStdioWithStructuredLogs, structuredWorkerdLogs: true, + handleStructuredLogs, defaultPersistRoot, workers: [ { @@ -1102,3 +1103,36 @@ export function isUnsafeServiceBindingWithDevCfg( ): b is Required { return b.dev !== undefined; } + +/** + * handler for workerd's structured logs to pass to miniflare + * + * @param structuredLog log to print + */ +function handleStructuredLogs({ level, message }: WorkerdStructuredLog) { + if (level === "warn") { + return logger.warn(message); + } + + if (level === "info") { + return logger.info(message); + } + + if (level === "debug") { + // note that debug logs are logged at the info level, this is like so because before structured logs + // were introduced developers were used to call `console.debug` and get their logs in the terminal + // during local development and we don't want to break such workflow in a non-major release + // (For more context see: https://github.com/cloudflare/workers-sdk/issues/10690) + // + // TODO: for the next major release we do want the debug logs to be logged at the debug level instead, + // we should also introduce some mechanism to allows users to get their worker debug logs without + // also getting all the wrangler debug logs + return logger.info(message); + } + + if (level === "error") { + return logger.error(getSourceMappedString(message)); + } + + return logger.log(getSourceMappedString(message)); +} diff --git a/packages/wrangler/src/dev/miniflare/stdio.ts b/packages/wrangler/src/dev/miniflare/stdio.ts deleted file mode 100644 index 7edba3fe2e0..00000000000 --- a/packages/wrangler/src/dev/miniflare/stdio.ts +++ /dev/null @@ -1,240 +0,0 @@ -import { logger } from "../../logger"; -import { getSourceMappedString } from "../../sourcemap"; -import type { Readable } from "node:stream"; - -/** - * Handler function to pass to Miniflare instances for handling the Worker process stream. - * - * This function can be used when Miniflare's `structuredWorkerdLogs` option is set to `true`. - * - * @param stdout The stdout stream connected to Miniflare's Workerd process - * @param stderr The stderr stream connected to Miniflare's Workerd process - */ -export function handleRuntimeStdioWithStructuredLogs( - stdout: Readable, - stderr: Readable -) { - stdout.on("data", getProcessStreamDataListener("stdout")); - stderr.on("data", getProcessStreamDataListener("stderr")); -} - -/** - * Creates a listener for the "data" event of a process stream associated to Miniflare's Workerd process. - * - * This function can be used when Miniflare's `structuredWorkerdLogs` option is set to `true`. - * - * @param processStream The target process stream - * @returns the listener to set for the stream's "data" event - */ -function getProcessStreamDataListener(processStream: "stdout" | "stderr") { - let streamAccumulator = ""; - - return (chunk: Buffer | string) => { - const fullStreamOutput = `${streamAccumulator}${chunk}`; - - let currentLogsStr = ""; - - // Structured logs are divided by newlines so let's get the - // last one, we know that anything in between will include - // one or more structured logs - const lastNewlineIdx = fullStreamOutput.lastIndexOf("\n"); - - if (lastNewlineIdx > 0) { - // If we've found a newline we will take the structured logs - // up to that point, the rest (which is the beginning of a - // new structured log) will be saved for later - currentLogsStr = fullStreamOutput.slice(0, lastNewlineIdx); - streamAccumulator = fullStreamOutput.slice(lastNewlineIdx + 1); - } else { - // If we didn't find a newline we're dealing with a structured - // log that has been split, so let's save the whole thing for - // later (so that we can process the log once we've seen it - // in full) - streamAccumulator = fullStreamOutput; - } - - const lines = currentLogsStr.split("\n"); - - for (const line of lines) { - const structuredLog = parseStructuredLog(line); - if (structuredLog) { - logStructuredLog(structuredLog, processStream); - } else { - const level = processStream === "stdout" ? "log" : "error"; - // Unexpectedly we've received a line that is not a structured log. - // Directly logging it would bypass the filtering in `logStructuredLog()`, so - // we construct a "fake" structured log - logStructuredLog( - { - timestamp: Date.now(), - level, - message: line, - }, - processStream - ); - } - } - }; -} - -type WorkerdStructuredLog = { - timestamp: number; - level: string; - message: string; -}; - -/** - * Parses a string to obtain the potential structured log the string represents. - * - * @param str Target string - * @returns The structured log extracted from the string or null is the string doesn't represent a structured log - */ -function parseStructuredLog(str: string): WorkerdStructuredLog | null { - try { - const maybeStructuredLog = JSON.parse(str) as Record; - - if (typeof maybeStructuredLog !== "object" || maybeStructuredLog === null) { - return null; - } - - const timestamp = parseInt(maybeStructuredLog.timestamp); - - if ( - isNaN(timestamp) || - typeof maybeStructuredLog.level !== "string" || - typeof maybeStructuredLog.message !== "string" - ) { - return null; - } - - return { - timestamp, - level: maybeStructuredLog.level, - message: maybeStructuredLog.message, - }; - } catch { - return null; - } -} - -/** - * Logs a structured log in the most appropriate way on the most appropriate log level. - * - * @param structuredLog The structured log to print - * @param processStream The process stream from where the structured log comes from - */ -function logStructuredLog( - { level, message }: WorkerdStructuredLog, - processStream: "stdout" | "stderr" -): void { - // TODO: the following code analyzes the message without considering its log level, - // ideally, in order to avoid false positives, we should run this logic scoped - // to the relevant log levels (as we do for `isCodeMovedWarning`) - if (messageClassifiers.isInternal(message)) { - // this is an internal message from workerd that we want to hijack to cleanup/ignore - - // In the past we have seen Access Violation errors on Windows, which may be caused by an outdated - // version of the Windows OS or the Microsoft Visual C++ Redistributable. - // See https://github.com/cloudflare/workers-sdk/issues/6170#issuecomment-2245209918 - if (messageClassifiers.isAccessViolation(message)) { - let error = "There was an access violation in the runtime."; - if (process.platform === "win32") { - error += - "\nOn Windows, this may be caused by an outdated Microsoft Visual C++ Redistributable library.\n" + - "Check that you have the latest version installed.\n" + - "See https://learn.microsoft.com/en-us/cpp/windows/latest-supported-vc-redist."; - } - logger.error(error); - - // Also log the original error to the debug logs. - return logger.debug(message); - } - - // IGNORABLE: - // anything else not handled above is considered ignorable - // so send it to the debug logs which are discarded unless - // the user explicitly sets a logLevel indicating they care - return logger.debug(message); - } - - if (level === "error" && messageClassifiers.isAddressInUse(message)) { - // Miniflare handles startup failures that result in an address in use message - // and will turn them into thrown MiniflareCoreErrors. As such, don't show the log to - // the user, or they'd see it twice - return logger.debug(message); - } - - if ( - (level === "info" || level === "error") && - messageClassifiers.isCodeMovedWarning(message) - ) { - // known case: "error: CODE_MOVED for unknown code block?", warning for workerd devs, not application devs - // ignore entirely, don't even send it to the debug log file - // workerd references: - // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L566 - // - https://github.com/cloudflare/workerd/blob/d170f4d9b/src/workerd/jsg/setup.c%2B%2B#L572 - return; - } - - if (level === "warn") { - return logger.warn(message); - } - - if (level === "info") { - return logger.info(message); - } - - if (level === "debug") { - // note that debug logs are logged at the info level, this is like so because before structured logs - // were introduced developers were used to call `console.debug` and get their logs in the terminal - // during local development and we don't want to break such workflow in a non-major release - // (For more context see: https://github.com/cloudflare/workers-sdk/issues/10690) - // - // TODO: for the next major release we do want the debug logs to be logged at the debug level instead, - // we should also introduce some mechanism to allows users to get their worker debug logs without - // also getting all the wrangler debug logs - return logger.info(message); - } - - if (level === "error") { - return logger.error(getSourceMappedString(message)); - } - - if (processStream === "stderr") { - return logger.error(getSourceMappedString(message)); - } else { - return logger.log(getSourceMappedString(message)); - } -} - -const messageClassifiers = { - // Is this chunk an internal message from workerd that we want to hijack to cleanup/ignore? - isInternal(chunk: string) { - const containsLlvmSymbolizerWarning = chunk.includes( - "Not symbolizing stack traces because $LLVM_SYMBOLIZER is not set" - ); - const containsRecursiveIsolateLockWarning = chunk.includes( - "took recursive isolate lock" - ); - // Matches stack traces from workerd - // - on unix: groups of 9 hex digits separated by spaces - // - on windows: groups of 12 hex digits, or a single digit 0, separated by spaces - const containsHexStack = /stack:( (0|[a-f\d]{4,})){3,}/.test(chunk); - - return ( - containsLlvmSymbolizerWarning || - containsRecursiveIsolateLockWarning || - containsHexStack - ); - }, - // Is this chunk an Address In Use error? - isAddressInUse(chunk: string) { - return chunk.includes("Address already in use; toString() = "); - }, - isCodeMovedWarning(chunk: string) { - return /CODE_MOVED for unknown code block/.test(chunk); - }, - isAccessViolation(chunk: string) { - return chunk.includes("access violation;"); - }, -}; From dfadbd47cff66611319cdd414fb3cdda869cb5e8 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Tue, 14 Oct 2025 22:37:58 +0100 Subject: [PATCH 03/23] remove redundant changeset --- .changeset/grumpy-signs-jam.md | 5 ----- 1 file changed, 5 deletions(-) delete mode 100644 .changeset/grumpy-signs-jam.md diff --git a/.changeset/grumpy-signs-jam.md b/.changeset/grumpy-signs-jam.md deleted file mode 100644 index 527b3d19da7..00000000000 --- a/.changeset/grumpy-signs-jam.md +++ /dev/null @@ -1,5 +0,0 @@ ---- -"@vite-plugin-cloudflare": patch ---- - -Improve how the plugin prints the workerd logged (making sure that all the logs are printed on the correct log level) From 3b3e346ad4f3c8083fb084378c402d33d3373e35 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Tue, 14 Oct 2025 22:53:40 +0100 Subject: [PATCH 04/23] fix miniflare issues --- packages/miniflare/src/index.ts | 1 - packages/miniflare/src/plugins/core/index.ts | 6 +++--- packages/miniflare/src/plugins/index.ts | 1 + 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/miniflare/src/index.ts b/packages/miniflare/src/index.ts index 9b314f187b9..a3f62c1de96 100644 --- a/packages/miniflare/src/index.ts +++ b/packages/miniflare/src/index.ts @@ -81,7 +81,6 @@ import { NameSourceOptions, reviveError, ServiceDesignatorSchema, - WorkerdStructuredLog, } from "./plugins/core"; import { InspectorProxyController } from "./plugins/core/inspector-proxy"; import { imagesLocalFetcher } from "./plugins/images/fetcher"; diff --git a/packages/miniflare/src/plugins/core/index.ts b/packages/miniflare/src/plugins/core/index.ts index 07afefab77c..e02451dcbde 100644 --- a/packages/miniflare/src/plugins/core/index.ts +++ b/packages/miniflare/src/plugins/core/index.ts @@ -216,9 +216,9 @@ export const CoreOptionsSchema = CoreOptionsSchemaInput.transform((value) => { return value; }); -export type WorkerdStructuredLog = z.infer; +export type WorkerdStructuredLog = z.infer; -const workerdStructuredLogSchema = z.object({ +export const WorkerdStructuredLogSchema = z.object({ timestamp: z.number(), level: z.string(), message: z.string(), @@ -246,7 +246,7 @@ export const CoreSharedOptionsSchema = z.object({ .optional(), handleStructuredLogs: z - .function(z.tuple([workerdStructuredLogSchema])) + .function(z.tuple([WorkerdStructuredLogSchema])) .returns(z.void()) .optional(), diff --git a/packages/miniflare/src/plugins/index.ts b/packages/miniflare/src/plugins/index.ts index d956fec9daf..c342b2d48c2 100644 --- a/packages/miniflare/src/plugins/index.ts +++ b/packages/miniflare/src/plugins/index.ts @@ -166,6 +166,7 @@ export { getFreshSourceMapSupport, kCurrentWorker, getNodeCompat, + WorkerdStructuredLogSchema as workerdStructuredLogSchema, } from "./core"; export type { CompiledModuleRule, From ce3c06ade4739008f0d2426298535fb0844fe57b Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Tue, 14 Oct 2025 23:35:21 +0100 Subject: [PATCH 05/23] update ProxyController --- .../wrangler/src/api/startDevWorker/ProxyController.ts | 9 ++++++--- packages/wrangler/src/dev/miniflare/index.ts | 2 +- 2 files changed, 7 insertions(+), 4 deletions(-) diff --git a/packages/wrangler/src/api/startDevWorker/ProxyController.ts b/packages/wrangler/src/api/startDevWorker/ProxyController.ts index 24b6f7f7165..eca3203a556 100644 --- a/packages/wrangler/src/api/startDevWorker/ProxyController.ts +++ b/packages/wrangler/src/api/startDevWorker/ProxyController.ts @@ -10,8 +10,11 @@ import { logConsoleMessage, maybeHandleNetworkLoadResource, } from "../../dev/inspect"; -import { castLogLevel, WranglerLog } from "../../dev/miniflare"; -import { handleRuntimeStdioWithStructuredLogs } from "../../dev/miniflare/stdio"; +import { + castLogLevel, + handleStructuredLogs, + WranglerLog, +} from "../../dev/miniflare"; import { getHttpsOptions } from "../../https-options"; import { logger } from "../../logger"; import { getSourceMappedStack } from "../../sourcemap"; @@ -137,7 +140,7 @@ export class ProxyController extends Controller { }, this.localServerReady.promise ), - handleRuntimeStdio: handleRuntimeStdioWithStructuredLogs, + handleStructuredLogs, structuredWorkerdLogs: true, liveReload: false, }; diff --git a/packages/wrangler/src/dev/miniflare/index.ts b/packages/wrangler/src/dev/miniflare/index.ts index 010871e5477..3e51e09c9a9 100644 --- a/packages/wrangler/src/dev/miniflare/index.ts +++ b/packages/wrangler/src/dev/miniflare/index.ts @@ -1109,7 +1109,7 @@ export function isUnsafeServiceBindingWithDevCfg( * * @param structuredLog log to print */ -function handleStructuredLogs({ level, message }: WorkerdStructuredLog) { +export function handleStructuredLogs({ level, message }: WorkerdStructuredLog) { if (level === "warn") { return logger.warn(message); } From d2726ff358c5e3152cf5f143cb44f81b625f18e9 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 15:40:01 +0100 Subject: [PATCH 06/23] apply changes made to stdio from #10769 --- .../miniflare/src/runtime/structured-logs.ts | 21 +++++++------------ 1 file changed, 8 insertions(+), 13 deletions(-) diff --git a/packages/miniflare/src/runtime/structured-logs.ts b/packages/miniflare/src/runtime/structured-logs.ts index d765fb8407f..a240dd49600 100644 --- a/packages/miniflare/src/runtime/structured-logs.ts +++ b/packages/miniflare/src/runtime/structured-logs.ts @@ -56,8 +56,8 @@ export function getProcessStructuredLogStreamListener( } const messageClassifiers = { - // Is this chunk a big chonky barf from workerd that we want to hijack to cleanup/ignore? - isBarf(chunk: string) { + // Is this chunk an internal message from workerd that we want to hijack to cleanup/ignore? + isInternal(chunk: string) { const containsLlvmSymbolizerWarning = chunk.includes( "Not symbolizing stack traces because $LLVM_SYMBOLIZER is not set" ); @@ -94,21 +94,16 @@ function getAdjustedStructuredLogsHandler( // TODO: the following code analyzes the message without considering its log level, // ideally, in order to avoid false positives, we should run this logic scoped // to the relevant log levels (as we do for `isCodeMovedWarning`) - if (messageClassifiers.isBarf(structuredLog.message)) { - // this is a big chonky barf from workerd that we want to hijack to cleanup/ignore + if (messageClassifiers.isInternal(structuredLog.message)) { + // this is an internal message from workerd that we want to hijack to cleanup/ignore // CLEANABLE: // known case to cleanup: Address in use errors if (messageClassifiers.isAddressInUse(structuredLog.message)) { - const address = structuredLog.message.match( - /Address already in use; toString\(\) = (.+)\n/ - )?.[1]; - - return structuredLogsHandler({ - timestamp: structuredLog.timestamp, - level: "error", - message: `Address already in use (${address}). Please check that you are not already running a server on this address or specify a different port with --port.`, - }); + // Miniflare handles startup failures that result in an address in use message + // and will turn them into thrown MiniflareCoreErrors. As such, don't show the log to + // the user, or they'd see it twice + return; } // In the past we have seen Access Violation errors on Windows, which may be caused by an outdated From 7eeaa7fde3127138d6b725fb4aba55a3e0e3dede Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 17:39:12 +0100 Subject: [PATCH 07/23] use startupLogBuffers instead of process plain streams --- packages/miniflare/src/runtime/index.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/miniflare/src/runtime/index.ts b/packages/miniflare/src/runtime/index.ts index 2caf580e761..837c09ed4b0 100644 --- a/packages/miniflare/src/runtime/index.ts +++ b/packages/miniflare/src/runtime/index.ts @@ -242,11 +242,11 @@ export class Runtime { ); if (options.handleStructuredLogs) { - runtimeProcess.stdout.on( + startupLogBuffer.stdoutStream.on( "data", getProcessStructuredLogStreamListener(options.handleStructuredLogs) ); - runtimeProcess.stderr.on( + startupLogBuffer.stderrStream.on( "data", getProcessStructuredLogStreamListener(options.handleStructuredLogs) ); From b5d3c3c7b00b6617f2d02f3b06303e5cdb29007e Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 17:42:22 +0100 Subject: [PATCH 08/23] ignore empty lines --- packages/miniflare/src/runtime/structured-logs.ts | 3 +++ 1 file changed, 3 insertions(+) diff --git a/packages/miniflare/src/runtime/structured-logs.ts b/packages/miniflare/src/runtime/structured-logs.ts index a240dd49600..40e5337a6a2 100644 --- a/packages/miniflare/src/runtime/structured-logs.ts +++ b/packages/miniflare/src/runtime/structured-logs.ts @@ -39,6 +39,9 @@ export function getProcessStructuredLogStreamListener( const lines = currentLogsStr.split("\n"); for (const line of lines) { + if (!line) { + continue; + } const structuredLog = parseStructuredLog(line); if (structuredLog) { adjustedStructuredLogsHandler(structuredLog); From 96c71cabfd23aef1b18f34f6f790af8a36c1fbb4 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 19:05:05 +0100 Subject: [PATCH 09/23] add missing `structuredWorkerdLogs: true` --- packages/vite-plugin-cloudflare/src/miniflare-options.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/vite-plugin-cloudflare/src/miniflare-options.ts b/packages/vite-plugin-cloudflare/src/miniflare-options.ts index 99e391d1ebe..8c85c40f30b 100644 --- a/packages/vite-plugin-cloudflare/src/miniflare-options.ts +++ b/packages/vite-plugin-cloudflare/src/miniflare-options.ts @@ -856,6 +856,7 @@ export async function getPreviewMiniflareOptions(config: { unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, handleStructuredLogs: getStructuredLogsLogger(logger), + structuredWorkerdLogs: true, defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, resolvedPluginConfig.persistState From 721bd570997486eacf55097c854bab85be301860 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 19:17:13 +0100 Subject: [PATCH 10/23] default `structuredWorkerdLogs` to `true` if `handleStrcturedLogs` is set --- packages/miniflare/src/index.ts | 7 +++++-- packages/miniflare/src/plugins/core/index.ts | 5 +++-- packages/vite-plugin-cloudflare/src/miniflare-options.ts | 2 -- .../wrangler/src/api/startDevWorker/ProxyController.ts | 1 - packages/wrangler/src/dev/miniflare/index.ts | 1 - 5 files changed, 8 insertions(+), 8 deletions(-) diff --git a/packages/miniflare/src/index.ts b/packages/miniflare/src/index.ts index a3f62c1de96..3016e6cd78e 100644 --- a/packages/miniflare/src/index.ts +++ b/packages/miniflare/src/index.ts @@ -979,7 +979,10 @@ export class Miniflare { this.#log = this.#sharedOpts.core.log ?? new NoOpLog(); this.#structuredWorkerdLogs = - this.#sharedOpts.core.structuredWorkerdLogs ?? false; + this.#sharedOpts.core.structuredWorkerdLogs ?? + // If there is a `handleStructuredLogs` set then `structuredWorkerdLogs` defaults + // to true, otherwise it defaults to false + (this.#sharedOpts.core.handleStructuredLogs ? true : false); // If we're in a JavaScript Debug terminal, Miniflare will send the inspector ports directly to VSCode for registration // As such, we don't need our inspector proxy and in fact including it causes issue with multiple clients connected to the @@ -1966,7 +1969,7 @@ export class Miniflare { } if ( - !this.#sharedOpts.core.structuredWorkerdLogs && + !this.#sharedOpts.core.structuredWorkerdLogs === false && this.#sharedOpts.core.handleStructuredLogs ) { throw new MiniflareCoreError( diff --git a/packages/miniflare/src/plugins/core/index.ts b/packages/miniflare/src/plugins/core/index.ts index e02451dcbde..08c16cf275a 100644 --- a/packages/miniflare/src/plugins/core/index.ts +++ b/packages/miniflare/src/plugins/core/index.ts @@ -282,9 +282,10 @@ export const CoreSharedOptionsSchema = z.object({ // Strip the MF-DISABLE_PRETTY_ERROR header from user request stripDisablePrettyError: z.boolean().default(true), - // Whether to get structured logs from workerd or not (default to `false`) + // Whether to get structured logs from workerd or not (defaults to `true` is a + // `handleStructuredLogs` is set, to `false` otherwise) // This option is useful in combination with a custom handleRuntimeStdio. - structuredWorkerdLogs: z.boolean().default(false), + structuredWorkerdLogs: z.boolean().optional(), }); export const CORE_PLUGIN_NAME = "core"; diff --git a/packages/vite-plugin-cloudflare/src/miniflare-options.ts b/packages/vite-plugin-cloudflare/src/miniflare-options.ts index 8c85c40f30b..ee83a7bd5bc 100644 --- a/packages/vite-plugin-cloudflare/src/miniflare-options.ts +++ b/packages/vite-plugin-cloudflare/src/miniflare-options.ts @@ -571,7 +571,6 @@ export async function getDevMiniflareOptions(config: { inspectorPort: inspectorPort === false ? undefined : inspectorPort, unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, - structuredWorkerdLogs: true, handleStructuredLogs: getStructuredLogsLogger(logger), defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, @@ -856,7 +855,6 @@ export async function getPreviewMiniflareOptions(config: { unsafeDevRegistryPath: getDefaultDevRegistryPath(), unsafeTriggerHandlers: true, handleStructuredLogs: getStructuredLogsLogger(logger), - structuredWorkerdLogs: true, defaultPersistRoot: getPersistenceRoot( resolvedViteConfig.root, resolvedPluginConfig.persistState diff --git a/packages/wrangler/src/api/startDevWorker/ProxyController.ts b/packages/wrangler/src/api/startDevWorker/ProxyController.ts index eca3203a556..c5a8a9002b2 100644 --- a/packages/wrangler/src/api/startDevWorker/ProxyController.ts +++ b/packages/wrangler/src/api/startDevWorker/ProxyController.ts @@ -141,7 +141,6 @@ export class ProxyController extends Controller { this.localServerReady.promise ), handleStructuredLogs, - structuredWorkerdLogs: true, liveReload: false, }; diff --git a/packages/wrangler/src/dev/miniflare/index.ts b/packages/wrangler/src/dev/miniflare/index.ts index 3e51e09c9a9..a4d8443bcef 100644 --- a/packages/wrangler/src/dev/miniflare/index.ts +++ b/packages/wrangler/src/dev/miniflare/index.ts @@ -1029,7 +1029,6 @@ export async function buildMiniflareOptions( logRequests: false, log, verbose: logger.loggerLevel === "debug", - structuredWorkerdLogs: true, handleStructuredLogs, defaultPersistRoot, workers: [ From e12ac07fda04a6aaaacbcb6aacfcbec8d1d97747 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 19:21:14 +0100 Subject: [PATCH 11/23] add missing backticks --- packages/miniflare/src/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/miniflare/src/index.ts b/packages/miniflare/src/index.ts index 3016e6cd78e..7c963725a64 100644 --- a/packages/miniflare/src/index.ts +++ b/packages/miniflare/src/index.ts @@ -981,7 +981,7 @@ export class Miniflare { this.#structuredWorkerdLogs = this.#sharedOpts.core.structuredWorkerdLogs ?? // If there is a `handleStructuredLogs` set then `structuredWorkerdLogs` defaults - // to true, otherwise it defaults to false + // to `true`, otherwise it defaults to `false` (this.#sharedOpts.core.handleStructuredLogs ? true : false); // If we're in a JavaScript Debug terminal, Miniflare will send the inspector ports directly to VSCode for registration From 560baa0067c881144d320eb1cc1c9d9616a2658b Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 21:51:24 +0100 Subject: [PATCH 12/23] Update packages/miniflare/src/index.ts Co-authored-by: Pete Bacon Darwin --- packages/miniflare/src/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/miniflare/src/index.ts b/packages/miniflare/src/index.ts index 7c963725a64..ec48be722b2 100644 --- a/packages/miniflare/src/index.ts +++ b/packages/miniflare/src/index.ts @@ -1969,7 +1969,7 @@ export class Miniflare { } if ( - !this.#sharedOpts.core.structuredWorkerdLogs === false && + this.#sharedOpts.core.structuredWorkerdLogs === false && this.#sharedOpts.core.handleStructuredLogs ) { throw new MiniflareCoreError( From 0713eb62a840f172a195312cec602e879e6f82bd Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 22:01:06 +0100 Subject: [PATCH 13/23] update incorrect patch bump to minor --- .changeset/stupid-ads-enter.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.changeset/stupid-ads-enter.md b/.changeset/stupid-ads-enter.md index 8b23a6a5b32..43bf08a194a 100644 --- a/.changeset/stupid-ads-enter.md +++ b/.changeset/stupid-ads-enter.md @@ -1,5 +1,5 @@ --- -"miniflare": patch +"miniflare": minor --- Add `handleStructuredLogs` option that allows consumers of the workerd structured logs to print such logs without additional necessary boilerplate From 374cfa2a01b4c6462c0dd0dacbb77c68c38fbf5f Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 22:17:32 +0100 Subject: [PATCH 14/23] improve code structure slightly --- packages/miniflare/src/runtime/index.ts | 20 ++++++------ .../miniflare/src/runtime/structured-logs.ts | 32 ++++++++++++++----- 2 files changed, 35 insertions(+), 17 deletions(-) diff --git a/packages/miniflare/src/runtime/index.ts b/packages/miniflare/src/runtime/index.ts index 837c09ed4b0..416fc8d1c1f 100644 --- a/packages/miniflare/src/runtime/index.ts +++ b/packages/miniflare/src/runtime/index.ts @@ -11,10 +11,12 @@ import workerdPath, { } from "workerd"; import { z } from "zod"; import { SERVICE_LOOPBACK, SOCKET_ENTRY } from "../plugins"; -import { WorkerdStructuredLog } from "../plugins/core"; import { MiniflareCoreError } from "../shared"; import { Awaitable } from "../workers"; -import { getProcessStructuredLogStreamListener } from "./structured-logs"; +import { + handleStructuredLogsFromStream, + StructuredLogsHandler, +} from "./structured-logs"; const ControlMessageSchema = z.discriminatedUnion("event", [ z.object({ @@ -39,7 +41,7 @@ export interface RuntimeOptions { inspectorAddress?: string; verbose?: boolean; handleRuntimeStdio?: (stdout: Readable, stderr: Readable) => void; - handleStructuredLogs?: (structuredLog: WorkerdStructuredLog) => void; + handleStructuredLogs?: StructuredLogsHandler; } async function waitForPorts( @@ -242,13 +244,13 @@ export class Runtime { ); if (options.handleStructuredLogs) { - startupLogBuffer.stdoutStream.on( - "data", - getProcessStructuredLogStreamListener(options.handleStructuredLogs) + handleStructuredLogsFromStream( + startupLogBuffer.stdoutStream, + options.handleStructuredLogs ); - startupLogBuffer.stderrStream.on( - "data", - getProcessStructuredLogStreamListener(options.handleStructuredLogs) + handleStructuredLogsFromStream( + startupLogBuffer.stderrStream, + options.handleStructuredLogs ); } diff --git a/packages/miniflare/src/runtime/structured-logs.ts b/packages/miniflare/src/runtime/structured-logs.ts index 40e5337a6a2..a2b5d3b694e 100644 --- a/packages/miniflare/src/runtime/structured-logs.ts +++ b/packages/miniflare/src/runtime/structured-logs.ts @@ -1,14 +1,23 @@ import { WorkerdStructuredLog } from "../plugins/core"; +import type { Stream } from "node:stream"; + +export type StructuredLogsHandler = ( + structuredLog: WorkerdStructuredLog +) => void; /** - * TODO + * Handles the structured logs emitted by a given stream + * + * @param stream The target stream + * @param structuredLogsHandler The handler function to use to process the structured logs */ -export function getProcessStructuredLogStreamListener( - structuredLogsHandler: (structuredLog: WorkerdStructuredLog) => void +export function handleStructuredLogsFromStream( + stream: Stream, + structuredLogsHandler: StructuredLogsHandler ) { let streamAccumulator = ""; - return (chunk: Buffer | string) => { + stream.on("data", (chunk: Buffer | string) => { const fullStreamOutput = `${streamAccumulator}${chunk}`; let currentLogsStr = ""; @@ -18,7 +27,7 @@ export function getProcessStructuredLogStreamListener( // one or more structured logs const lastNewlineIdx = fullStreamOutput.lastIndexOf("\n"); - const adjustedStructuredLogsHandler = getAdjustedStructuredLogsHandler( + const adjustedStructuredLogsHandler = improveStructuredLogsHandler( structuredLogsHandler ); @@ -55,7 +64,7 @@ export function getProcessStructuredLogStreamListener( }); } } - }; + }); } const messageClassifiers = { @@ -90,8 +99,15 @@ const messageClassifiers = { }, }; -function getAdjustedStructuredLogsHandler( - structuredLogsHandler: (structuredLog: WorkerdStructuredLog) => void +/** + * Improves a structuredLogsHandler function so that it then performs extra filtering and + * remapping to logs so that known unhelpful/noisy logs are improved or removed altogether + * + * @param structuredLogsHandler The target handler function to improve + * @returns The improved handler function + */ +function improveStructuredLogsHandler( + structuredLogsHandler: StructuredLogsHandler ) { return (structuredLog: WorkerdStructuredLog) => { // TODO: the following code analyzes the message without considering its log level, From 41bd790ddb0af87ab0f456ce25c1daefd7f48a72 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 22:52:11 +0100 Subject: [PATCH 15/23] export StructuredLogsHandler type --- packages/miniflare/src/runtime/index.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/miniflare/src/runtime/index.ts b/packages/miniflare/src/runtime/index.ts index 416fc8d1c1f..932d9de16ab 100644 --- a/packages/miniflare/src/runtime/index.ts +++ b/packages/miniflare/src/runtime/index.ts @@ -34,6 +34,8 @@ export const kInspectorSocket = Symbol("kInspectorSocket"); export type SocketIdentifier = string | typeof kInspectorSocket; export type SocketPorts = Map; +export type { StructuredLogsHandler } from "./structured-logs"; + export interface RuntimeOptions { entryAddress: string; loopbackAddress: string; From dceea7f1e7101c1478cd35775ae8bcb025277216 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Wed, 15 Oct 2025 23:13:59 +0100 Subject: [PATCH 16/23] add logs tests to miniflare --- packages/miniflare/test/index.spec.ts | 93 --------- packages/miniflare/test/logs.spec.ts | 260 ++++++++++++++++++++++++++ 2 files changed, 260 insertions(+), 93 deletions(-) create mode 100644 packages/miniflare/test/logs.spec.ts diff --git a/packages/miniflare/test/index.spec.ts b/packages/miniflare/test/index.spec.ts index c24e6c2d2f1..b21d126a760 100644 --- a/packages/miniflare/test/index.spec.ts +++ b/packages/miniflare/test/index.spec.ts @@ -3427,96 +3427,3 @@ test("Miniflare: MINIFLARE_WORKERD_CONFIG_DEBUG controls workerd config file cre ); await mf.dispose(); }); - -test("Miniflare: logs are treated as standard stdout/stderr chunks be default", async (t) => { - const collected = { - stdout: "", - stderr: "", - }; - const mf = new Miniflare({ - modules: true, - handleRuntimeStdio(stdout, stderr) { - stdout.forEach((data) => { - collected.stdout += `${data}`; - }); - stderr.forEach((error) => { - collected.stderr += `${error}`; - }); - }, - script: ` - export default { - async fetch(req, env) { - console.log('__LOG__'); - console.warn('__WARN__'); - console.error('__ERROR__'); - console.info('__INFO__'); - console.debug('__DEBUG__'); - return new Response('Hello world!'); - } - }`, - }); - t.teardown(() => mf.dispose()); - - const response = await mf.dispatchFetch("http://localhost"); - await response.text(); - - t.is(collected.stdout, "__LOG__\n__INFO__\n__DEBUG__\n"); - t.is(collected.stderr, "__WARN__\n__ERROR__\n"); -}); - -test("Miniflare: logs are structured and all sent to stdout when structuredWorkerdLogs is true", async (t) => { - const collected = { - stdout: "", - stderr: "", - }; - const mf = new Miniflare({ - modules: true, - structuredWorkerdLogs: true, - handleRuntimeStdio(stdout, stderr) { - stdout.forEach((data) => { - collected.stdout += `${data}`; - }); - stderr.forEach((error) => { - collected.stderr += `${error}`; - }); - }, - script: ` - export default { - async fetch(req, env) { - console.log('__LOG__'); - console.warn('__WARN__'); - console.error('__ERROR__'); - console.info('__INFO__'); - console.debug('__DEBUG__'); - return new Response('Hello world!'); - } - }`, - }); - t.teardown(() => mf.dispose()); - - const response = await mf.dispatchFetch("http://localhost"); - await response.text(); - - t.regex( - collected.stdout, - /{"timestamp":\d+,"level":"log","message":"__LOG__"}/ - ); - t.regex( - collected.stdout, - /{"timestamp":\d+,"level":"warn","message":"__WARN__"}/ - ); - t.regex( - collected.stdout, - /{"timestamp":\d+,"level":"error","message":"__ERROR__"}/ - ); - t.regex( - collected.stdout, - /{"timestamp":\d+,"level":"info","message":"__INFO__"}/ - ); - t.regex( - collected.stdout, - /{"timestamp":\d+,"level":"debug","message":"__DEBUG__"}/ - ); - - t.is(collected.stderr, ""); -}); diff --git a/packages/miniflare/test/logs.spec.ts b/packages/miniflare/test/logs.spec.ts new file mode 100644 index 00000000000..3dfd4245e45 --- /dev/null +++ b/packages/miniflare/test/logs.spec.ts @@ -0,0 +1,260 @@ +import test from "ava"; +import { Miniflare, MiniflareError, WorkerdStructuredLog } from "miniflare"; + +test("logs are treated as standard stdout/stderr chunks be default", async (t) => { + const collected = { + stdout: "", + stderr: "", + }; + const mf = new Miniflare({ + modules: true, + handleRuntimeStdio(stdout, stderr) { + stdout.forEach((data) => { + collected.stdout += `${data}`; + }); + stderr.forEach((error) => { + collected.stderr += `${error}`; + }); + }, + script: ` + export default { + async fetch(req, env) { + console.log('__LOG__'); + console.warn('__WARN__'); + console.error('__ERROR__'); + console.info('__INFO__'); + console.debug('__DEBUG__'); + return new Response('Hello world!'); + } + }`, + }); + t.teardown(() => mf.dispose()); + + const response = await mf.dispatchFetch("http://localhost"); + await response.text(); + + t.is(collected.stdout, "__LOG__\n__INFO__\n__DEBUG__\n"); + t.is(collected.stderr, "__WARN__\n__ERROR__\n"); +}); + +test("logs are structured and all sent to stdout when `structuredWorkerdLogs` is `true`", async (t) => { + const collected = { + stdout: "", + stderr: "", + }; + const mf = new Miniflare({ + modules: true, + structuredWorkerdLogs: true, + handleRuntimeStdio(stdout, stderr) { + stdout.forEach((data) => { + collected.stdout += `${data}`; + }); + stderr.forEach((error) => { + collected.stderr += `${error}`; + }); + }, + script: ` + export default { + async fetch(req, env) { + console.log('__LOG__'); + console.warn('__WARN__'); + console.error('__ERROR__'); + console.info('__INFO__'); + console.debug('__DEBUG__'); + return new Response('Hello world!'); + } + }`, + }); + t.teardown(() => mf.dispose()); + + const response = await mf.dispatchFetch("http://localhost"); + await response.text(); + + t.regex( + collected.stdout, + /{"timestamp":\d+,"level":"log","message":"__LOG__"}/ + ); + t.regex( + collected.stdout, + /{"timestamp":\d+,"level":"warn","message":"__WARN__"}/ + ); + t.regex( + collected.stdout, + /{"timestamp":\d+,"level":"error","message":"__ERROR__"}/ + ); + t.regex( + collected.stdout, + /{"timestamp":\d+,"level":"info","message":"__INFO__"}/ + ); + t.regex( + collected.stdout, + /{"timestamp":\d+,"level":"debug","message":"__DEBUG__"}/ + ); + + t.is(collected.stderr, ""); +}); + +test("logs are structured and handled via `handleStructuredLogs` when such option is provided (no `structuredWorkerdLogs: true` needed)", async (t) => { + const collectedLogs: (Pick & { + timestamp: string; + })[] = []; + const mf = new Miniflare({ + modules: true, + handleStructuredLogs(log) { + collectedLogs.push({ + ...log, + timestamp: `<${typeof log.timestamp}>`, + }); + }, + script: ` + export default { + async fetch(req, env) { + console.log('__LOG__'); + console.warn('__WARN__'); + console.error('__ERROR__'); + console.info('__INFO__'); + console.debug('__DEBUG__'); + return new Response('Hello world!'); + } + }`, + }); + t.teardown(() => mf.dispose()); + + const response = await mf.dispatchFetch("http://localhost"); + await response.text(); + + t.deepEqual(collectedLogs, [ + { + level: "log", + message: "__LOG__", + timestamp: "", + }, + { + level: "warn", + message: "__WARN__", + timestamp: "", + }, + { + level: "error", + message: "__ERROR__", + timestamp: "", + }, + { + level: "info", + message: "__INFO__", + timestamp: "", + }, + { + level: "debug", + message: "__DEBUG__", + timestamp: "", + }, + ]); +}); + +test("even when `handleStructuredLogs` is provided, `handleRuntimeStdio` can still be used to read the raw stream values", async (t) => { + let numOfCollectedStructuredLogs = 0; + const collectedRaw = { + stdout: "", + stderr: "", + }; + const mf = new Miniflare({ + modules: true, + handleRuntimeStdio(stdout, stderr) { + stdout.forEach((data) => { + collectedRaw.stdout += `${data}`; + }); + stderr.forEach((error) => { + collectedRaw.stderr += `${error}`; + }); + }, + handleStructuredLogs() { + numOfCollectedStructuredLogs++; + }, + script: ` + export default { + async fetch(req, env) { + console.log('__LOG__'); + console.error('__ERROR__'); + return new Response('Hello world!'); + } + }`, + }); + t.teardown(() => mf.dispose()); + + const response = await mf.dispatchFetch("http://localhost"); + await response.text(); + + t.is(numOfCollectedStructuredLogs, 2); + + t.regex( + collectedRaw.stdout, + /{"timestamp":\d+,"level":"log","message":"__LOG__"}/ + ); + t.regex( + collectedRaw.stdout, + /{"timestamp":\d+,"level":"error","message":"__ERROR__"}/ + ); + t.is(collectedRaw.stderr, ""); +}); + +test("setting `handleStructuredLogs` when `structuredWorkerdLogs` is `false` triggers an error", async (t) => { + const mf = new Miniflare({ modules: true, script: "" }); + t.teardown(() => mf.dispose()); + + await t.throwsAsync( + mf.setOptions({ + modules: true, + script: "", + structuredWorkerdLogs: false, + handleStructuredLogs() {}, + }), + { + instanceOf: MiniflareError, + code: "ERR_INVALID_STRUCTURED_LOGS_HANDLER", + message: + "A `handleStructuredLogs` has been provided but `structuredWorkerdLogs` is set to `false`", + } + ); +}); + +test("when using `handleStructuredLogs` some known unhelpful logs are filtered out (e.g. CODE_MOVED warnings)", async (t) => { + const collectedLogs: (Pick & { + timestamp: string; + })[] = []; + const mf = new Miniflare({ + modules: true, + handleStructuredLogs(log) { + collectedLogs.push({ + ...log, + timestamp: `<${typeof log.timestamp}>`, + }); + }, + script: ` + export default { + async fetch(req, env) { + console.log('__LOG__'); + console.error('CODE_MOVED for unknown code block'); + console.error('__ERROR__'); + return new Response('Hello world!'); + } + }`, + }); + t.teardown(() => mf.dispose()); + + const response = await mf.dispatchFetch("http://localhost"); + await response.text(); + + t.deepEqual(collectedLogs, [ + { + level: "log", + message: "__LOG__", + timestamp: "", + }, + { + level: "error", + message: "__ERROR__", + timestamp: "", + }, + ]); +}); From b4328f7c52b76501737a7acbb0f6aaa497886239 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Thu, 16 Oct 2025 14:01:40 +0100 Subject: [PATCH 17/23] Update packages/miniflare/test/logs.spec.ts Co-authored-by: Pete Bacon Darwin --- packages/miniflare/test/logs.spec.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/miniflare/test/logs.spec.ts b/packages/miniflare/test/logs.spec.ts index 3dfd4245e45..20e34315fc8 100644 --- a/packages/miniflare/test/logs.spec.ts +++ b/packages/miniflare/test/logs.spec.ts @@ -1,7 +1,7 @@ import test from "ava"; import { Miniflare, MiniflareError, WorkerdStructuredLog } from "miniflare"; -test("logs are treated as standard stdout/stderr chunks be default", async (t) => { +test("logs are treated as standard stdout/stderr chunks by default", async (t) => { const collected = { stdout: "", stderr: "", From 91b7d9a3fb3f54072f1c29add138b9fe09c664a8 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Thu, 16 Oct 2025 14:02:32 +0100 Subject: [PATCH 18/23] Update packages/miniflare/src/runtime/index.ts Co-authored-by: Pete Bacon Darwin --- packages/miniflare/src/runtime/index.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/miniflare/src/runtime/index.ts b/packages/miniflare/src/runtime/index.ts index 932d9de16ab..ae705d77e0b 100644 --- a/packages/miniflare/src/runtime/index.ts +++ b/packages/miniflare/src/runtime/index.ts @@ -236,7 +236,7 @@ export class Runtime { const handleRuntimeStdio = options.handleRuntimeStdio ?? (options.handleStructuredLogs - ? // If `handleStructuredLogs` is provided then be default Miniflare should not pipe through the stream's output + ? // If `handleStructuredLogs` is provided then by default Miniflare should not pipe through the stream's output () => {} : pipeOutput); From b6b3afc4fb8537ec1646e402dba33f700eebd7cd Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Thu, 16 Oct 2025 14:19:49 +0100 Subject: [PATCH 19/23] move fallback strcutured log logic into `parseStructuredLog` and log at the `log` level instead of `unknown` --- .../miniflare/src/runtime/structured-logs.ts | 16 +++++++--------- 1 file changed, 7 insertions(+), 9 deletions(-) diff --git a/packages/miniflare/src/runtime/structured-logs.ts b/packages/miniflare/src/runtime/structured-logs.ts index a2b5d3b694e..f605ad51c0f 100644 --- a/packages/miniflare/src/runtime/structured-logs.ts +++ b/packages/miniflare/src/runtime/structured-logs.ts @@ -54,14 +54,6 @@ export function handleStructuredLogsFromStream( const structuredLog = parseStructuredLog(line); if (structuredLog) { adjustedStructuredLogsHandler(structuredLog); - } else { - // Unexpectedly we've received a line that is not a structured log. - // We then log it at an unknown level. - adjustedStructuredLogsHandler({ - timestamp: Date.now(), - level: "unknown", - message: line, - }); } } }); @@ -195,6 +187,12 @@ function parseStructuredLog(str: string): WorkerdStructuredLog | null { message: maybeStructuredLog.message, }; } catch { - return null; + // Unexpectedly we've received a line that is not a structured log. + // For now we simply log it at the log level, if this turns out problematic we can refine this as needed. + return { + timestamp: Date.now(), + level: "log", + message: str, + }; } } From ea663850969887a8e34e431839724c798415b091 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Thu, 16 Oct 2025 14:22:36 +0100 Subject: [PATCH 20/23] rename `improveStructuredLogsHandler` to `wrapStructuredLogsHandler` --- packages/miniflare/src/runtime/structured-logs.ts | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/miniflare/src/runtime/structured-logs.ts b/packages/miniflare/src/runtime/structured-logs.ts index f605ad51c0f..e350d8f0660 100644 --- a/packages/miniflare/src/runtime/structured-logs.ts +++ b/packages/miniflare/src/runtime/structured-logs.ts @@ -27,7 +27,7 @@ export function handleStructuredLogsFromStream( // one or more structured logs const lastNewlineIdx = fullStreamOutput.lastIndexOf("\n"); - const adjustedStructuredLogsHandler = improveStructuredLogsHandler( + const adjustedStructuredLogsHandler = wrapStructuredLogsHandler( structuredLogsHandler ); @@ -92,13 +92,13 @@ const messageClassifiers = { }; /** - * Improves a structuredLogsHandler function so that it then performs extra filtering and - * remapping to logs so that known unhelpful/noisy logs are improved or removed altogether + * Wraps a structuredLogsHandler function so that it then performs extra filtering and + * remapping of logs so that known unhelpful/noisy logs are improved or removed altogether * * @param structuredLogsHandler The target handler function to improve * @returns The improved handler function */ -function improveStructuredLogsHandler( +function wrapStructuredLogsHandler( structuredLogsHandler: StructuredLogsHandler ) { return (structuredLog: WorkerdStructuredLog) => { From 6fbfcadc138884c7c2eef49ab493ed49cc99a7c8 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Thu, 16 Oct 2025 15:35:58 +0100 Subject: [PATCH 21/23] remove new `ERR_INVALID_STRUCTURED_LOGS_HANDLER` and validate `structuredLogsHandler` via zod's `refine` instead --- packages/miniflare/src/index.ts | 10 -- packages/miniflare/src/plugins/core/index.ts | 139 ++++++++++--------- packages/miniflare/src/shared/error.ts | 1 - packages/miniflare/test/logs.spec.ts | 28 ++-- 4 files changed, 92 insertions(+), 86 deletions(-) diff --git a/packages/miniflare/src/index.ts b/packages/miniflare/src/index.ts index ec48be722b2..47fd81f2b09 100644 --- a/packages/miniflare/src/index.ts +++ b/packages/miniflare/src/index.ts @@ -1968,16 +1968,6 @@ export class Miniflare { requiredSockets.push(kInspectorSocket); } - if ( - this.#sharedOpts.core.structuredWorkerdLogs === false && - this.#sharedOpts.core.handleStructuredLogs - ) { - throw new MiniflareCoreError( - "ERR_INVALID_STRUCTURED_LOGS_HANDLER", - "A `handleStructuredLogs` has been provided but `structuredWorkerdLogs` is set to `false`" - ); - } - // Reload runtime const entryAddress = this.#getSocketAddress( SOCKET_ENTRY, diff --git a/packages/miniflare/src/plugins/core/index.ts b/packages/miniflare/src/plugins/core/index.ts index 08c16cf275a..c762f4cb65e 100644 --- a/packages/miniflare/src/plugins/core/index.ts +++ b/packages/miniflare/src/plugins/core/index.ts @@ -224,69 +224,82 @@ export const WorkerdStructuredLogSchema = z.object({ message: z.string(), }); -export const CoreSharedOptionsSchema = z.object({ - rootPath: UnusableStringSchema.optional(), - - host: z.string().optional(), - port: z.number().optional(), - - https: z.boolean().optional(), - httpsKey: z.string().optional(), - httpsKeyPath: z.string().optional(), - httpsCert: z.string().optional(), - httpsCertPath: z.string().optional(), - - inspectorPort: z.number().optional(), - - verbose: z.boolean().optional(), - - log: z.instanceof(Log).optional(), - handleRuntimeStdio: z - .function(z.tuple([z.instanceof(Readable), z.instanceof(Readable)])) - .optional(), - - handleStructuredLogs: z - .function(z.tuple([WorkerdStructuredLogSchema])) - .returns(z.void()) - .optional(), - - upstream: z.string().optional(), - // TODO: add back validation of cf object - cf: z.union([z.boolean(), z.string(), z.record(z.any())]).optional(), - - liveReload: z.boolean().optional(), - - // Enable auto service / durable objects discovery with the dev registry - unsafeDevRegistryPath: z.string().optional(), - // Enable External Durable Objects Proxy / Internal DOs registration - unsafeDevRegistryDurableObjectProxy: z.boolean().default(false), - // Called when external workers this instance depends on are updated in the dev registry - unsafeHandleDevRegistryUpdate: z - .function(z.tuple([z.custom()])) - .optional(), - // This is a shared secret between a proxy server and miniflare that can be - // passed in a header to prove that the request came from the proxy and not - // some malicious attacker. - unsafeProxySharedSecret: z.string().optional(), - unsafeModuleFallbackService: CustomFetchServiceSchema.optional(), - // Keep blobs when deleting/overwriting keys, required for stacked storage - unsafeStickyBlobs: z.boolean().optional(), - // Enable directly triggering user Worker handlers with paths like `/cdn-cgi/handler/scheduled` - unsafeTriggerHandlers: z.boolean().optional(), - // Enable logging requests - logRequests: z.boolean().default(true), - - // Path to the root directory for persisting data - // Used as the default for all plugins with the plugin name as the subdirectory name - defaultPersistRoot: z.string().optional(), - // Strip the MF-DISABLE_PRETTY_ERROR header from user request - stripDisablePrettyError: z.boolean().default(true), - - // Whether to get structured logs from workerd or not (defaults to `true` is a - // `handleStructuredLogs` is set, to `false` otherwise) - // This option is useful in combination with a custom handleRuntimeStdio. - structuredWorkerdLogs: z.boolean().optional(), -}); +export const CoreSharedOptionsSchema = z + .object({ + rootPath: UnusableStringSchema.optional(), + + host: z.string().optional(), + port: z.number().optional(), + + https: z.boolean().optional(), + httpsKey: z.string().optional(), + httpsKeyPath: z.string().optional(), + httpsCert: z.string().optional(), + httpsCertPath: z.string().optional(), + + inspectorPort: z.number().optional(), + + verbose: z.boolean().optional(), + + log: z.instanceof(Log).optional(), + handleRuntimeStdio: z + .function(z.tuple([z.instanceof(Readable), z.instanceof(Readable)])) + .optional(), + + handleStructuredLogs: z + .function(z.tuple([WorkerdStructuredLogSchema])) + .returns(z.void()) + .optional(), + + upstream: z.string().optional(), + // TODO: add back validation of cf object + cf: z.union([z.boolean(), z.string(), z.record(z.any())]).optional(), + + liveReload: z.boolean().optional(), + + // Enable auto service / durable objects discovery with the dev registry + unsafeDevRegistryPath: z.string().optional(), + // Enable External Durable Objects Proxy / Internal DOs registration + unsafeDevRegistryDurableObjectProxy: z.boolean().default(false), + // Called when external workers this instance depends on are updated in the dev registry + unsafeHandleDevRegistryUpdate: z + .function(z.tuple([z.custom()])) + .optional(), + // This is a shared secret between a proxy server and miniflare that can be + // passed in a header to prove that the request came from the proxy and not + // some malicious attacker. + unsafeProxySharedSecret: z.string().optional(), + unsafeModuleFallbackService: CustomFetchServiceSchema.optional(), + // Keep blobs when deleting/overwriting keys, required for stacked storage + unsafeStickyBlobs: z.boolean().optional(), + // Enable directly triggering user Worker handlers with paths like `/cdn-cgi/handler/scheduled` + unsafeTriggerHandlers: z.boolean().optional(), + // Enable logging requests + logRequests: z.boolean().default(true), + + // Path to the root directory for persisting data + // Used as the default for all plugins with the plugin name as the subdirectory name + defaultPersistRoot: z.string().optional(), + // Strip the MF-DISABLE_PRETTY_ERROR header from user request + stripDisablePrettyError: z.boolean().default(true), + + // Whether to get structured logs from workerd or not (defaults to `true` is a + // `handleStructuredLogs` is set, to `false` otherwise) + // This option is useful in combination with a custom handleRuntimeStdio. + structuredWorkerdLogs: z.boolean().optional(), + }) + .refine( + ({ structuredWorkerdLogs, handleStructuredLogs }) => { + if (structuredWorkerdLogs === false && handleStructuredLogs) { + return false; + } + return true; + }, + { + message: + "A `handleStructuredLogs` has been provided but `structuredWorkerdLogs` is set to `false`", + } + ); export const CORE_PLUGIN_NAME = "core"; diff --git a/packages/miniflare/src/shared/error.ts b/packages/miniflare/src/shared/error.ts index a773522da6f..fd500c18221 100644 --- a/packages/miniflare/src/shared/error.ts +++ b/packages/miniflare/src/shared/error.ts @@ -16,7 +16,6 @@ export const USER_ERROR_CODES = new Set([ "ERR_MULTIPLE_OUTBOUNDS", // Both `outboundService` and `fetchMock` specified "ERR_INVALID_WRAPPED", // Worker not allowed to be used as wrapped binding "ERR_MISSING_INSPECTOR_PROXY_PORT", // An inspector proxy has been requested but no inspector port to use has been specified - "ERR_INVALID_STRUCTURED_LOGS_HANDLER", // A handler for structured logs has been provided but without using structured logs ] as const); export const SYSTEM_ERROR_CODES = new Set([ diff --git a/packages/miniflare/test/logs.spec.ts b/packages/miniflare/test/logs.spec.ts index 20e34315fc8..a81347d2853 100644 --- a/packages/miniflare/test/logs.spec.ts +++ b/packages/miniflare/test/logs.spec.ts @@ -1,5 +1,5 @@ import test from "ava"; -import { Miniflare, MiniflareError, WorkerdStructuredLog } from "miniflare"; +import { Miniflare, MiniflareCoreError, WorkerdStructuredLog } from "miniflare"; test("logs are treated as standard stdout/stderr chunks by default", async (t) => { const collected = { @@ -202,18 +202,22 @@ test("setting `handleStructuredLogs` when `structuredWorkerdLogs` is `false` tri const mf = new Miniflare({ modules: true, script: "" }); t.teardown(() => mf.dispose()); - await t.throwsAsync( - mf.setOptions({ - modules: true, - script: "", - structuredWorkerdLogs: false, - handleStructuredLogs() {}, - }), + t.throws( + () => + new Miniflare({ + modules: true, + script: "", + structuredWorkerdLogs: false, + handleStructuredLogs() {}, + }), { - instanceOf: MiniflareError, - code: "ERR_INVALID_STRUCTURED_LOGS_HANDLER", - message: - "A `handleStructuredLogs` has been provided but `structuredWorkerdLogs` is set to `false`", + instanceOf: MiniflareCoreError, + code: "ERR_VALIDATION", + message(message) { + return message.includes( + "A `handleStructuredLogs` has been provided but `structuredWorkerdLogs` is set to `false`" + ); + }, } ); }); From cbf96fee5c975dbf0745b38500c50d5cd526656f Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Fri, 17 Oct 2025 11:06:37 +0100 Subject: [PATCH 22/23] Apply suggestions from code review Co-authored-by: James Opstad <13586373+jamesopstad@users.noreply.github.com> --- .changeset/pretty-paths-stare.md | 2 +- .changeset/stupid-ads-enter.md | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/.changeset/pretty-paths-stare.md b/.changeset/pretty-paths-stare.md index 30dfa9743d5..04c85ab9adc 100644 --- a/.changeset/pretty-paths-stare.md +++ b/.changeset/pretty-paths-stare.md @@ -4,4 +4,4 @@ Ensure that logs are printed at the correct log level -The changes here ensure that logs generated by the workers are printed accordingly to the potential `logLevel` the user defined (either in their vite config file or via the `--logLevel` CLI flag) +The changes here ensure that logs generated by Workers are printed accordingly to the `logLevel` the user defines (either in their Vite config file or via the `--logLevel` CLI flag) diff --git a/.changeset/stupid-ads-enter.md b/.changeset/stupid-ads-enter.md index 43bf08a194a..46a0888dd12 100644 --- a/.changeset/stupid-ads-enter.md +++ b/.changeset/stupid-ads-enter.md @@ -2,4 +2,4 @@ "miniflare": minor --- -Add `handleStructuredLogs` option that allows consumers of the workerd structured logs to print such logs without additional necessary boilerplate +Add `handleStructuredLogs` option that allows consumers of the workerd structured logs to print such logs without additional boilerplate From d2b1382a29d1be4246bc0ce9ee32af622a727916 Mon Sep 17 00:00:00 2001 From: Dario Piotrowicz Date: Fri, 17 Oct 2025 11:10:53 +0100 Subject: [PATCH 23/23] Update .changeset/fancy-spoons-chew.md Co-authored-by: James Opstad <13586373+jamesopstad@users.noreply.github.com> --- .changeset/fancy-spoons-chew.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.changeset/fancy-spoons-chew.md b/.changeset/fancy-spoons-chew.md index affb0e45c19..5342a2257e2 100644 --- a/.changeset/fancy-spoons-chew.md +++ b/.changeset/fancy-spoons-chew.md @@ -2,4 +2,4 @@ "wrangler": patch --- -Update logs handling via the new `handleStructuredLogs` miniflare option +Update logs handling to use the new `handleStructuredLogs` miniflare option