Fix dev-env logging (#6909)

.changeset/gentle-apricots-kiss.md

@@ -0,0 +1,5 @@
+---
+"wrangler": patch
+---
+
+fix: Various fixes for logging in `--x-dev-env`, primarily to ensure the hotkeys don't wipe useful output and are cleaned up correctly

.prettierignore

@@ -35,4 +35,7 @@ vscode.*.d.ts
 templates/*/build
 templates/*/dist
 
-.github/pull_request_template.md
+.github/pull_request_template.md
+
+# This file intentionally has a syntax error
+fixtures/interactive-dev-tests/src/startup-error.ts

fixtures/interactive-dev-tests/src/startup-error.ts

@@ -0,0 +1,5 @@
+export default {
+	async fetch(): Promise<Response {
+		return new Response("body");
+	},
+};

fixtures/interactive-dev-tests/tests/index.test.ts

@@ -86,7 +86,7 @@ const processes: PtyProcess[] = [];
 afterEach(() => {
 	for (const p of processes.splice(0)) {
 		// If the process didn't exit cleanly, log its output for debugging
-		if (p.exitCode !== 0) console.log(stripAnsi(p.stdout));
+		if (p.exitCode !== 0) console.log(p.stdout);
 		// If the process hasn't exited yet, kill it
 		if (p.exitCode === null) {
 			// `node-pty` throws if signal passed on Windows
@@ -97,7 +97,7 @@ afterEach(() => {
 });
 
 const readyRegexp = /Ready on (http:\/\/[a-z0-9.]+:[0-9]+)/;
-async function startWranglerDev(args: string[]) {
+async function startWranglerDev(args: string[], skipWaitingForReady = false) {
 	const stdoutStream = new stream.PassThrough();
 	const stdoutInterface = rl.createInterface(stdoutStream);
 
@@ -134,13 +134,14 @@ async function startWranglerDev(args: string[]) {
 		stdoutStream.end();
 	});
 
-	let readyMatch: RegExpMatchArray | null = null;
-	for await (const line of stdoutInterface) {
-		if ((readyMatch = readyRegexp.exec(line)) !== null) break;
+	if (!skipWaitingForReady) {
+		let readyMatch: RegExpMatchArray | null = null;
+		for await (const line of stdoutInterface) {
+			if ((readyMatch = readyRegexp.exec(line)) !== null) break;
+		}
+		assert(readyMatch !== null, "Expected ready message");
+		result.url = readyMatch[1];
 	}
-	assert(readyMatch !== null, "Expected ready message");
-	result.url = readyMatch[1];
-
 	return result;
 }
 
@@ -196,8 +197,8 @@ function getStartedWorkerdProcesses(): Process[] {
 }
 
 const devScripts = [
-	{ args: ["dev"], expectedBody: "body" },
 	{ args: ["dev", "--x-dev-env"], expectedBody: "body" },
+	{ args: ["dev", "--no-x-dev-env"], expectedBody: "body" },
 	{ args: ["pages", "dev", "public"], expectedBody: "<p>body</p>" },
 ];
 const exitKeys = [
@@ -228,3 +229,27 @@ describe.each(devScripts)("wrangler $args", ({ args, expectedBody }) => {
 		}
 	});
 });
+
+it.runIf(RUN_IF && nodePtySupported)(
+	"hotkeys should be unregistered when the initial build fails",
+	async () => {
+		const wrangler = await startWranglerDev(
+			["dev", "--x-dev-env", "src/startup-error.ts"],
+			true
+		);
+
+		expect(await wrangler.exitPromise).toBe(1);
+
+		const hotkeysRenderCount = [
+			...wrangler.stdout.matchAll(/\[b\] open a browser/g),
+		];
+
+		const clearHotkeysCount = [
+			// This is the control sequence for moving the cursor up and then clearing from the cursor to the end
+			...wrangler.stdout.matchAll(/\[\dA\[0J/g),
+		];
+
+		// The hotkeys should be rendered the same number of times as the control sequence for clearing them from the screen
+		expect(hotkeysRenderCount.length).toBe(clearHotkeysCount.length);
+	}
+);

packages/wrangler/src/cfetch/internal.ts

@@ -247,7 +247,7 @@ export async function fetchWorker(
 	});
 
 	if (!response.ok || !response.body) {
-		console.error(response.ok, response.body);
+		logger.error(response.ok, response.body);
 		throw new Error(
 			`Failed to fetch ${resource} - ${response.status}: ${response.statusText});`
 		);

packages/wrangler/src/deployment-bundle/guess-worker-format.ts

@@ -39,6 +39,7 @@ export default async function guessWorkerFormat(
 		bundle: false,
 		write: false,
 		...(tsconfig && { tsconfig }),
+		logLevel: "silent",
 	});
 
 	// result.metafile is defined because of the `metafile: true` option above.

packages/wrangler/src/dev.tsx

@@ -399,11 +399,15 @@ This is currently not supported 😭, but we think that we'll get it to work soo
 			() => startDev(args)
 		);
 		if (args.experimentalDevEnv) {
-			assert(devInstance instanceof DevEnv);
-			await events.once(devInstance, "teardown");
+			assert(devInstance.devEnv !== undefined);
+			await events.once(devInstance.devEnv, "teardown");
+			if (devInstance.teardownRegistryPromise) {
+				const teardownRegistry = await devInstance.teardownRegistryPromise;
+				await teardownRegistry(devInstance.devEnv.config.latestConfig?.name);
+			}
+			devInstance.unregisterHotKeys?.();
 		} else {
-			assert(!(devInstance instanceof DevEnv));
-
+			assert(devInstance.devEnv === undefined);
 			configFileWatcher = devInstance.configFileWatcher;
 			assetsWatcher = devInstance.assetsWatcher;
 
@@ -546,6 +550,12 @@ export async function startDev(args: StartDevOptions) {
 	let configFileWatcher: ReturnType<typeof watch> | undefined;
 	let assetsWatcher: ReturnType<typeof watch> | undefined;
 	let rerender: (node: React.ReactNode) => void | undefined;
+	const devEnv = new DevEnv();
+	let teardownRegistryPromise:
+		| Promise<(name?: string) => Promise<void>>
+		| undefined;
+
+	let unregisterHotKeys: (() => void) | undefined;
 	try {
 		if (args.logLevel) {
 			logger.loggerLevel = args.logLevel;
@@ -588,8 +598,6 @@ export async function startDev(args: StartDevOptions) {
 			args.config ||
 			(args.script && findWranglerToml(path.dirname(args.script)));
 
-		const devEnv = new DevEnv();
-
 		if (args.experimentalDevEnv) {
 			// The ProxyWorker will have a stable host and port, so only listen for the first update
 			void devEnv.proxy.ready.promise.then(({ url }) => {
@@ -605,13 +613,10 @@ export async function startDev(args: StartDevOptions) {
 			});
 
 			if (!args.disableDevRegistry) {
-				const teardownRegistryPromise = devRegistry((registry) =>
+				teardownRegistryPromise = devRegistry((registry) =>
 					updateDevEnvRegistry(devEnv, registry)
 				);
-				devEnv.once("teardown", async () => {
-					const teardownRegistry = await teardownRegistryPromise;
-					await teardownRegistry(devEnv.config.latestConfig?.name);
-				});
+
 				devEnv.runtimes.forEach((runtime) => {
 					runtime.on(
 						"reloadComplete",
@@ -631,7 +636,6 @@ export async function startDev(args: StartDevOptions) {
 				});
 			}
 
-			let unregisterHotKeys: () => void;
 			if (isInteractive() && args.showInteractiveDevSession !== false) {
 				unregisterHotKeys = registerDevHotKeys(devEnv, args);
 			}
@@ -784,7 +788,7 @@ export async function startDev(args: StartDevOptions) {
 				}
 			);
 
-			return devEnv;
+			return { devEnv, unregisterHotKeys, teardownRegistryPromise };
 		} else {
 			const projectRoot = configPath && path.dirname(configPath);
 			let config = readConfig(configPath, args);
@@ -1042,6 +1046,14 @@ export async function startDev(args: StartDevOptions) {
 		await Promise.allSettled([
 			configFileWatcher?.close(),
 			assetsWatcher?.close(),
+			devEnv.teardown(),
+			(async () => {
+				if (teardownRegistryPromise) {
+					const teardownRegistry = await teardownRegistryPromise;
+					await teardownRegistry(devEnv.config.latestConfig?.name);
+				}
+				unregisterHotKeys?.();
+			})(),
 		]);
 		throw e;
 	}

packages/wrangler/src/dev/hotkeys.ts

@@ -55,7 +55,6 @@ export default function registerDevHotKeys(
 			keys: ["x", "q", "ctrl+c"],
 			label: "to exit",
 			handler: async () => {
-				unregisterHotKeys();
 				await devEnv.teardown();
 			},
 		},

packages/wrangler/src/logger.ts

@@ -181,7 +181,7 @@ export const logger = new Logger();
 export function logBuildWarnings(warnings: Message[]) {
 	const logs = formatMessagesSync(warnings, { kind: "warning", color: true });
 	for (const log of logs) {
-		console.warn(log);
+		logger.console("warn", log);
 	}
 }
 
@@ -192,7 +192,7 @@ export function logBuildWarnings(warnings: Message[]) {
 export function logBuildFailure(errors: Message[], warnings: Message[]) {
 	const logs = formatMessagesSync(errors, { kind: "error", color: true });
 	for (const log of logs) {
-		console.error(log);
+		logger.console("error", log);
 	}
 	logBuildWarnings(warnings);
 }

packages/wrangler/src/utils/log-file.ts

@@ -63,8 +63,11 @@ ${message}
 			// TODO(consider): recommend opening an issue with the contents of this file?
 			if (hasSeenErrorMessage) {
 				// use console.*warn* here so not to pollute stdout -- some commands print json to stdout
-				// use *console*.warn here so not to have include the *very* visible bright-yellow [WARNING] indicator
-				console.warn(`🪵  Logs were written to "${debugLogFilepath}"`);
+				// use logger.*console*("warn", ...) here so not to have include the *very* visible bright-yellow [WARNING] indicator
+				logger.console(
+					"warn",
+					`🪵  Logs were written to "${debugLogFilepath}"`
+				);
 			}
 		});
 	}