fix: ensure console.log()s during startup are displayed

As of #4072, whenever Wrangler connected to the V8 inspector, it would
clear V8's internal buffer of log messages. This ensured only messages
logged while the inspector was connected would be displayed.
Unfortunately, we only connect to the inspector once the Worker has
reported it's ready to receive connections. This meant any
`console.log()`s during Worker startup wouldn't be displayed. This
change switches to clearing V8's buffer whenever we _disconnect_
from the inspector instead, ensuring startup logs are shown.

Author: mrbbot

.changeset/serious-beans-trade.md

@@ -0,0 +1,16 @@
+---
+"wrangler": patch
+---
+
+fix: ensure `console.log()`s during startup are displayed
+
+Previously, whenever Wrangler connected to the V8 inspector, it would clear V8's
+internal buffer of log messages. This ensured only messages logged while the
+inspector was connected would be displayed. Unfortunately, we only connect to
+the inspector once the Worker has reported it's ready to receive connections.
+This meant any `console.log()`s during Worker startup wouldn't be displayed.
+
+This change switches to clearing V8's buffer whenever we _disconnect_ from the
+inspector instead, ensuring startup logs are shown. In particular, this should
+[fix Remix's HMR](https://github.com/remix-run/remix/issues/7616), which relies
+on startup logs to know when the Worker is ready.

fixtures/shared/src/run-wrangler-long-lived.ts

@@ -57,6 +57,7 @@ async function runLongLivedWrangler(command: string[], cwd: string) {
 	const chunks: Buffer[] = [];
 	wranglerProcess.stdout?.on("data", (chunk) => chunks.push(chunk));
 	wranglerProcess.stderr?.on("data", (chunk) => chunks.push(chunk));
+	const getOutput = () => Buffer.concat(chunks).toString();
 
 	const timeoutHandle = setTimeout(() => {
 		if (settledReadyPromise) return;
@@ -65,7 +66,7 @@ async function runLongLivedWrangler(command: string[], cwd: string) {
 		const message = [
 			"Timed out starting long-lived Wrangler:",
 			separator,
-			Buffer.concat(chunks).toString(),
+			getOutput(),
 			separator,
 		].join("\n");
 		rejectReadyPromise(new Error(message));
@@ -85,5 +86,5 @@ async function runLongLivedWrangler(command: string[], cwd: string) {
 	}
 
 	const { ip, port } = await ready;
-	return { ip, port, stop };
+	return { ip, port, stop, getOutput };
 }

fixtures/worker-app/src/index.js

@@ -1,6 +1,8 @@
 import { now } from "./dep";
 import { randomBytes } from "isomorphic-random-example";
 
+console.log("startup log");
+
 /** @param {Uint8Array} array */
 function hexEncode(array) {
 	return Array.from(array)
@@ -10,6 +12,8 @@ function hexEncode(array) {
 
 export default {
 	async fetch(request) {
+		console.log("request log");
+
 		const { pathname } = new URL(request.url);
 		if (pathname === "/random") return new Response(hexEncode(randomBytes(8)));
 

fixtures/worker-app/tests/index.test.ts

@@ -4,13 +4,16 @@ import { describe, it, beforeAll, afterAll } from "vitest";
 import { runWranglerDev } from "../../shared/src/run-wrangler-long-lived";
 
 describe("'wrangler dev' correctly renders pages", () => {
-	let ip: string, port: number, stop: (() => Promise<unknown>) | undefined;
+	let ip: string,
+		port: number,
+		stop: (() => Promise<unknown>) | undefined,
+		getOutput: () => string;
 
 	beforeAll(async () => {
-		({ ip, port, stop } = await runWranglerDev(resolve(__dirname, ".."), [
-			"--local",
-			"--port=0",
-		]));
+		({ ip, port, stop, getOutput } = await runWranglerDev(
+			resolve(__dirname, ".."),
+			["--local", "--port=0"]
+		));
 	});
 
 	afterAll(async () => {
@@ -21,6 +24,11 @@ describe("'wrangler dev' correctly renders pages", () => {
 		const response = await fetch(`http://${ip}:${port}/`);
 		const text = await response.text();
 		expect(text).toContain(`http://${ip}:${port}/`);
+
+		// Ensure `console.log()`s from startup and requests are shown
+		const output = getOutput();
+		expect(output).toContain("startup log");
+		expect(output).toContain("request log");
 	});
 
 	it("uses `workerd` condition when bundling", async ({ expect }) => {

packages/wrangler/src/dev/inspect.ts

@@ -342,6 +342,10 @@ export default function useInspector(props: InspectorProps) {
 		 */
 		function close(): void {
 			if (!isClosed()) {
+				send({
+					method: "Runtime.discardConsoleEntries",
+					id: messageCounterRef.current++,
+				});
 				try {
 					ws.close();
 				} catch (err) {
@@ -378,10 +382,6 @@ export default function useInspector(props: InspectorProps) {
 		}
 
 		ws.addEventListener("open", () => {
-			send({
-				method: "Runtime.discardConsoleEntries",
-				id: messageCounterRef.current++,
-			});
 			send({ method: "Runtime.enable", id: messageCounterRef.current++ });
 			// TODO: This doesn't actually work. Must fix.
 			send({ method: "Network.enable", id: messageCounterRef.current++ });