Add configurable logger (#434)

This PR copies the `Log` implementation from Miniflare 2, and allows
logging to be configured via the `log` shared option.

packages/miniflare/README.md

@@ -132,6 +132,58 @@ Represents where data should be persisted, if anywhere.
 - Otherwise, if this is just a regular `string`, data will be stored on the
   file-system, using the value as the directory path.
 
+### `enum LogLevel`
+
+`NONE, ERROR, WARN, INFO, DEBUG, VERBOSE`
+
+Controls which messages Miniflare logs. All messages at or below the selected
+level will be logged.
+
+### `interface LogOptions`
+
+- `prefix?: string`
+
+  String to add before the level prefix when logging messages. Defaults to `mf`.
+
+- `suffix?: string`
+
+  String to add after the level prefix when logging messages.
+
+### `class Log`
+
+- `constructor(level?: LogLevel, opts?: LogOptions)`
+
+  Creates a new logger that logs all messages at or below the specified level to
+  the `console`.
+
+- `error(message: Error)`
+
+  Logs a message at the `ERROR` level. If the constructed log `level` is less
+  than `ERROR`, `throw`s the `message` instead.
+
+- `warn(message: string)`
+
+  Logs a message at the `WARN` level.
+
+- `info(message: string)`
+
+  Logs a message at the `INFO` level.
+
+- `debug(message: string)`
+
+  Logs a message at the `DEBUG` level.
+
+- `verbose(message: string)`
+
+  Logs a message at the `VERBOSE` level.
+
+### `class NoOpLog extends Log`
+
+- `constructor()`
+
+  Creates a new logger that logs nothing to the `console`, and always `throw`s
+  `message`s logged at the `ERROR` level.
+
 ### `interface WorkerOptions`
 
 Options for an individual Worker/"nanoservice". All bindings are accessible on
@@ -337,6 +389,11 @@ Options shared between all Workers/"nanoservices".
   Enable `workerd`'s `--verbose` flag for verbose logging. This can be used to
   see simplified `console.log`s.
 
+- `log?: Log`
+
+  Logger implementation for Miniflare's errors, warnings and informative
+  messages.
+
 - `cf?: boolean | string | Record<string, any>`
 
   Controls the object returned from incoming `Request`'s `cf` property.

packages/miniflare/src/cf.ts

@@ -1,10 +1,10 @@
 import assert from "assert";
 import { mkdir, readFile, stat, writeFile } from "fs/promises";
 import path from "path";
-import { bold, dim, grey, red } from "kleur/colors";
+import { dim } from "kleur/colors";
 import { fetch } from "undici";
 import { Plugins } from "./plugins";
-import { OptionalZodTypeOf } from "./shared";
+import { Log, OptionalZodTypeOf } from "./shared";
 
 const defaultCfPath = path.resolve("node_modules", ".mf", "cf.json");
 const defaultCfFetchEndpoint = "https://workers.cloudflare.com/cf.json";
@@ -48,6 +48,7 @@ export const CF_DAYS = 30;
 type CoreOptions = OptionalZodTypeOf<Plugins["core"]["sharedOptions"]>;
 
 export async function setupCf(
+	log: Log,
 	cf: CoreOptions["cf"]
 ): Promise<Record<string, any>> {
 	if (!(cf ?? process.env.NODE_ENV !== "test")) {
@@ -80,14 +81,12 @@ export async function setupCf(
 		// Write cf so we can reuse it later
 		await mkdir(path.dirname(cfPath), { recursive: true });
 		await writeFile(cfPath, cfText, "utf8");
-		console.log(grey("Updated `Request.cf` object cache!"));
+		log.debug("Updated `Request.cf` object cache!");
 		return storedCf;
 	} catch (e: any) {
-		console.log(
-			bold(
-				red(`Unable to fetch the \`Request.cf\` object! Falling back to a default placeholder...
-${dim(e.cause ? e.cause.stack : e.stack)}`)
-			)
+		log.warn(
+			"Unable to fetch the `Request.cf` object! Falling back to a default placeholder...\n" +
+				dim(e.cause ? e.cause.stack : e.stack)
 		);
 		return fallbackCf;
 	}

packages/miniflare/src/index.ts

@@ -4,7 +4,6 @@ import net from "net";
 import { Duplex } from "stream";
 import exitHook from "exit-hook";
 import getPort from "get-port";
-import { bold, green, grey } from "kleur/colors";
 import stoppable from "stoppable";
 import {
 	HeadersInit,
@@ -43,8 +42,10 @@ import {
 } from "./runtime";
 import {
 	HttpError,
+	Log,
 	MiniflareCoreError,
 	Mutex,
+	NoOpLog,
 	OptionalZodTypeOf,
 	UnionToIntersection,
 	ValueOf,
@@ -150,6 +151,7 @@ export class Miniflare {
 	#optionsVersion: number;
 	#sharedOpts: PluginSharedOptions;
 	#workerOpts: PluginWorkerOptions[];
+	#log: Log;
 
 	readonly #runtimeConstructor: RuntimeConstructor;
 	#runtime?: Runtime;
@@ -193,16 +195,14 @@ export class Miniflare {
 		this.#optionsVersion = 1;
 		this.#sharedOpts = sharedOpts;
 		this.#workerOpts = workerOpts;
+		this.#log = this.#sharedOpts.core.log ?? new NoOpLog();
 		this.#initPlugins();
 
 		// Get supported shell for executing runtime binary
 		// TODO: allow this to be configured if necessary
 		this.#runtimeConstructor = getSupportedRuntime();
-		// TODO: use logger
 		const desc = this.#runtimeConstructor.description;
-		console.log(
-			grey(`Running the 🦄 Cloudflare Workers Runtime 🦄 ${desc}...`)
-		);
+		this.#log.debug(`Running workerd ${desc}...`);
 
 		this.#disposeController = new AbortController();
 		this.#liveReloadServer = new WebSocketServer({ noServer: true });
@@ -214,12 +214,13 @@ export class Miniflare {
 		for (const [key, plugin] of PLUGIN_ENTRIES) {
 			if (plugin.gateway !== undefined && plugin.router !== undefined) {
 				const gatewayFactory = new GatewayFactory<any>(
+					this.#log,
 					this.#sharedOpts.core.cloudflareFetch,
 					key,
 					plugin.gateway,
 					plugin.remoteStorage
 				);
-				const router = new plugin.router(gatewayFactory);
+				const router = new plugin.router(this.#log, gatewayFactory);
 				// @ts-expect-error this.#gatewayFactories[key] could be any plugin's
 				this.#gatewayFactories[key] = gatewayFactory;
 				// @ts-expect-error this.#routers[key] could be any plugin's
@@ -269,7 +270,7 @@ export class Miniflare {
 		// Wait for runtime to start
 		if ((await this.#waitForRuntime()) && !this.#runtimeMutex.hasWaiting) {
 			// Only log and trigger reload if there aren't pending updates
-			console.log(bold(green(`Ready on ${this.#runtimeEntryURL} 🎉`)));
+			this.#log.info(`Ready on ${this.#runtimeEntryURL}`);
 			this.#handleReload();
 		}
 	}
@@ -454,7 +455,7 @@ export class Miniflare {
 		// #assembleConfig is always called after the loopback server is created
 		assert(loopbackPort !== undefined);
 
-		sharedOpts.core.cf = await setupCf(sharedOpts.core.cf);
+		sharedOpts.core.cf = await setupCf(this.#log, sharedOpts.core.cf);
 
 		const services: Service[] = [];
 		const sockets: Socket[] = [
@@ -492,6 +493,7 @@ export class Miniflare {
 			// Collect all services required by this worker
 			for (const [key, plugin] of PLUGIN_ENTRIES) {
 				const pluginServices = await plugin.getServices({
+					log: this.#log,
 					options: workerOpts[key],
 					optionsVersion,
 					sharedOptions: sharedOpts[key],
@@ -544,6 +546,7 @@ export class Miniflare {
 		const [sharedOpts, workerOpts] = validateOptions(opts);
 		this.#sharedOpts = sharedOpts;
 		this.#workerOpts = workerOpts;
+		this.#log = this.#sharedOpts.core.log ?? this.#log;
 
 		// Increment version, so we know when the runtime has processed updates
 		this.#optionsVersion++;
@@ -557,9 +560,7 @@ export class Miniflare {
 
 		if ((await this.#waitForRuntime()) && !this.#runtimeMutex.hasWaiting) {
 			// Only log and trigger reload if this was the last pending update
-			console.log(
-				bold(green(`Updated and ready on ${this.#runtimeEntryURL} 🎉`))
-			);
+			this.#log.info(`Updated and ready on ${this.#runtimeEntryURL}`);
 			this.#handleReload();
 		}
 	}

packages/miniflare/src/plugins/cache/gateway.ts

@@ -3,7 +3,7 @@ import http from "http";
 import { AddressInfo } from "net";
 import CachePolicy from "http-cache-semantics";
 import { Headers, HeadersInit, Request, Response, fetch } from "undici";
-import { Clock, millisToSeconds } from "../../shared";
+import { Clock, Log, millisToSeconds } from "../../shared";
 import { Storage } from "../../storage";
 import { CacheMiss, PurgeFailure, StorageFailure } from "./errors";
 import { _getRangeResponse } from "./range";
@@ -204,6 +204,7 @@ class HttpParser {
 
 export class CacheGateway {
 	constructor(
+		private readonly log: Log,
 		private readonly storage: Storage,
 		private readonly clock: Clock
 	) {}

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

@@ -1,7 +1,7 @@
 import { readFileSync } from "fs";
 import fs from "fs/promises";
 import { TextEncoder } from "util";
-import { bold, yellow } from "kleur/colors";
+import { bold } from "kleur/colors";
 import { Request, Response } from "undici";
 import { z } from "zod";
 import {
@@ -14,6 +14,7 @@ import {
 import {
 	Awaitable,
 	JsonSchema,
+	Log,
 	MiniflareCoreError,
 	zAwaitable,
 } from "../../shared";
@@ -73,6 +74,7 @@ export const CoreSharedOptionsSchema = z.object({
 	inspectorPort: z.number().optional(),
 	verbose: z.boolean().optional(),
 
+	log: z.instanceof(Log).optional(),
 	cloudflareFetch: CloudflareFetchSchema.optional(),
 
 	// TODO: add back validation of cf object
@@ -197,7 +199,7 @@ const CURRENT_COMPATIBILITY_DATE = [
 
 const FALLBACK_COMPATIBILITY_DATE = "2000-01-01";
 
-function validateCompatibilityDate(compatibilityDate: string) {
+function validateCompatibilityDate(log: Log, compatibilityDate: string) {
 	if (numericCompare(compatibilityDate, CURRENT_COMPATIBILITY_DATE) > 0) {
 		// If this compatibility date is in the future, throw
 		throw new MiniflareCoreError(
@@ -210,18 +212,16 @@ function validateCompatibilityDate(compatibilityDate: string) {
 		// If this compatibility date is greater than the maximum supported
 		// compatibility date of the runtime, but not in the future, warn,
 		// and use the maximum supported date instead
-		console.warn(
-			yellow(
-				[
-					"The latest compatibility date supported by the installed Cloudflare Workers Runtime is ",
-					bold(`"${supportedCompatibilityDate}"`),
-					",\nbut you've requested ",
-					bold(`"${compatibilityDate}"`),
-					". Falling back to ",
-					bold(`"${supportedCompatibilityDate}"`),
-					"...",
-				].join("")
-			)
+		log.warn(
+			[
+				"The latest compatibility date supported by the installed Cloudflare Workers Runtime is ",
+				bold(`"${supportedCompatibilityDate}"`),
+				",\nbut you've requested ",
+				bold(`"${compatibilityDate}"`),
+				". Falling back to ",
+				bold(`"${supportedCompatibilityDate}"`),
+				"...",
+			].join("")
 		);
 		return supportedCompatibilityDate;
 	}
@@ -291,6 +291,7 @@ export const CORE_PLUGIN: Plugin<
 		durableObjectClassNames,
 		additionalModules,
 		loopbackPort,
+		log,
 	}) {
 		// Define core/shared services.
 		// Services get de-duped by name, so only the first worker's
@@ -341,6 +342,7 @@ export const CORE_PLUGIN: Plugin<
 			const name = getUserServiceName(options.name);
 			const classNames = durableObjectClassNames.get(name) ?? [];
 			const compatibilityDate = validateCompatibilityDate(
+				log,
 				options.compatibilityDate ?? FALLBACK_COMPATIBILITY_DATE
 			);
 

packages/miniflare/src/plugins/do/gateway.ts

@@ -1,8 +1,9 @@
-import { Clock } from "../../shared";
+import { Clock, Log } from "../../shared";
 import { Storage } from "../../storage";
 
 export class DurableObjectsStorageGateway {
 	constructor(
+		private readonly log: Log,
 		private readonly storage: Storage,
 		private readonly clock: Clock
 	) {}

packages/miniflare/src/plugins/kv/gateway.ts

@@ -1,4 +1,4 @@
-import { Clock, HttpError, millisToSeconds } from "../../shared";
+import { Clock, HttpError, Log, millisToSeconds } from "../../shared";
 import { Storage, StoredKeyMeta, StoredValueMeta } from "../../storage";
 import {
 	MAX_KEY_SIZE,
@@ -70,6 +70,7 @@ export interface KVGatewayListResult<Meta = unknown> {
 
 export class KVGateway {
 	constructor(
+		private readonly log: Log,
 		private readonly storage: Storage,
 		private readonly clock: Clock
 	) {}

packages/miniflare/src/plugins/r2/gateway.ts

@@ -1,3 +1,4 @@
+import { Log } from "../../shared";
 import { RangeStoredValueMeta, Storage } from "../../storage";
 import { InvalidRange, NoSuchKey } from "./errors";
 import {
@@ -90,7 +91,10 @@ const MAX_LIST_KEYS = 1_000;
 const validate = new Validator();
 
 export class R2Gateway {
-	constructor(private readonly storage: Storage) {}
+	constructor(
+		private readonly log: Log,
+		private readonly storage: Storage
+	) {}
 
 	async head(key: string): Promise<R2Object> {
 		validate.key(key);

packages/miniflare/src/plugins/shared/gateway.ts

@@ -5,6 +5,7 @@ import { z } from "zod";
 import {
 	Awaitable,
 	Clock,
+	Log,
 	MiniflareCoreError,
 	defaultClock,
 	sanitisePath,
@@ -34,7 +35,7 @@ export const CloudflareFetchSchema =
 export type CloudflareFetch = z.infer<typeof CloudflareFetchSchema>;
 
 export interface GatewayConstructor<Gateway> {
-	new (storage: Storage, clock: Clock): Gateway;
+	new (log: Log, storage: Storage, clock: Clock): Gateway;
 }
 
 export interface RemoteStorageConstructor {
@@ -60,6 +61,7 @@ export class GatewayFactory<Gateway> {
 	readonly #gateways = new Map<string, [Persistence, Gateway]>();
 
 	constructor(
+		private readonly log: Log,
 		private readonly cloudflareFetch: CloudflareFetch | undefined,
 		private readonly pluginName: string,
 		private readonly gatewayClass: GatewayConstructor<Gateway>,
@@ -134,7 +136,7 @@ export class GatewayFactory<Gateway> {
 		if (cached !== undefined && cached[0] === persist) return cached[1];
 
 		const storage = this.getStorage(namespace, persist);
-		const gateway = new this.gatewayClass(storage, defaultClock);
+		const gateway = new this.gatewayClass(this.log, storage, defaultClock);
 		this.#gateways.set(namespace, [persist, gateway]);
 		return gateway;
 	}