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

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,11 @@
+---
+"wrangler": patch
+---
+
+fix: ensure `console.log()`s during startup are displayed
+
+Previously, `console.log()` calls before the Workers runtime was ready to
+receive requests wouldn't be shown. This meant any logs in the global scope
+likely weren't visible. This change ensures 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++ });