Rework Vite and Astro logger for HMR messages (withastro#9139)

.changeset/gold-grapes-jump.md

@@ -0,0 +1,5 @@
+---
+'astro': minor
+---
+
+Reworks Vite's logger to use Astro's logger to correctly log HMR messages

packages/astro/src/core/build/static-build.ts

@@ -155,8 +155,7 @@ async function ssrBuild(
 	const viteBuildConfig: vite.InlineConfig = {
 		...viteConfig,
 		mode: viteConfig.mode || 'production',
-		// Check using `settings...` as `viteConfig` always defaults to `warn` by Astro
-		logLevel: settings.config.vite.logLevel ?? 'error',
+		logLevel: viteConfig.logLevel ?? 'error',
 		build: {
 			target: 'esnext',
 			// Vite defaults cssMinify to false in SSR by default, but we want to minify it
@@ -288,8 +287,6 @@ async function clientBuild(
 	const viteBuildConfig: vite.InlineConfig = {
 		...viteConfig,
 		mode: viteConfig.mode || 'production',
-		// Check using `settings...` as `viteConfig` always defaults to `warn` by Astro
-		logLevel: settings.config.vite.logLevel ?? 'info',
 		build: {
 			target: 'esnext',
 			...viteConfig.build,

packages/astro/src/core/create-vite.ts

@@ -1,6 +1,5 @@
 import nodeFs from 'node:fs';
 import { fileURLToPath } from 'node:url';
-import type { Logger as ViteLogger } from 'vite';
 import * as vite from 'vite';
 import { crawlFrameworkPkgs } from 'vitefu';
 import type { AstroSettings } from '../@types/astro.js';
@@ -31,6 +30,7 @@ import astroScriptsPlugin from '../vite-plugin-scripts/index.js';
 import astroScriptsPageSSRPlugin from '../vite-plugin-scripts/page-ssr.js';
 import { vitePluginSSRManifest } from '../vite-plugin-ssr-manifest/index.js';
 import type { Logger } from './logger/core.js';
+import { createViteLogger } from './logger/vite.js';
 import { vitePluginMiddleware } from './middleware/vite-plugin.js';
 import { joinPaths } from './path.js';
 
@@ -102,25 +102,13 @@ export async function createVite(
 		},
 	});
 
-	const viteCustomLogger: ViteLogger = {
-		...vite.createLogger('warn'),
-		// All error log messages are also thrown as real errors,
-		// so we can safely ignore them here and let the error handler
-		// log them for the user instead.
-		error: (msg) => logger.debug('vite', 'ERROR ' + msg),
-		// Warnings are usually otherwise ignored by Vite, so it's
-		// important that we catch and log them here.
-		warn: (msg) => logger.warn('vite', msg),
-	};
-
 	// Start with the Vite configuration that Astro core needs
 	const commonConfig: vite.InlineConfig = {
 		// Tell Vite not to combine config from vite.config.js with our provided inline config
 		configFile: false,
 		cacheDir: fileURLToPath(new URL('./node_modules/.vite/', settings.config.root)), // using local caches allows Astro to be used in monorepos, etc.
 		clearScreen: false, // we want to control the output, not Vite
-		logLevel: 'warn', // log warnings and errors only
-		customLogger: viteCustomLogger,
+		customLogger: createViteLogger(logger, settings.config.vite.logLevel),
 		appType: 'custom',
 		optimizeDeps: {
 			entries: ['src/**/*'],

packages/astro/src/core/logger/core.ts

@@ -76,13 +76,17 @@ export function log(opts: LogOptions, level: LoggerLevel, label: string | null,
 	};
 
 	// test if this level is enabled or not
-	if (levels[logLevel] > levels[level]) {
+	if (!isLogLevelEnabled(logLevel, level)) {
 		return; // do nothing
 	}
 
 	dest.write(event);
 }
 
+export function isLogLevelEnabled(configuredLogLevel: LoggerLevel, level: LoggerLevel) {
+	return levels[configuredLogLevel] <= levels[level];
+}
+
 /** Emit a user-facing message. Useful for UI and other console messages. */
 export function info(opts: LogOptions, label: string | null, message: string) {
 	return log(opts, 'info', label, message);

packages/astro/src/core/logger/vite.ts

@@ -0,0 +1,97 @@
+import { fileURLToPath } from 'url';
+import stripAnsi from 'strip-ansi';
+import type { Logger as ViteLogger, Rollup, LogLevel } from 'vite';
+import { isAstroError } from '../errors/errors.js';
+import { isLogLevelEnabled, type Logger as AstroLogger } from './core.js';
+
+const PKG_PREFIX = fileURLToPath(new URL('../../../', import.meta.url));
+const E2E_PREFIX = fileURLToPath(new URL('../../../e2e', import.meta.url));
+export function isAstroSrcFile(id: string | null) {
+	return id?.startsWith(PKG_PREFIX) && !id.startsWith(E2E_PREFIX);
+}
+
+// capture "page reload some/Component.vue (additional info)" messages
+const vitePageReloadMsg = /page reload (.*)( \(.*\))?/;
+// capture "hmr update some/Component.vue" messages
+const viteHmrUpdateMsg = /hmr update (.*)/;
+// capture "vite v5.0.0 building SSR bundle for production..." and "vite v5.0.0 building for production..." messages
+const viteBuildMsg = /vite.*building.*for production/;
+
+export function createViteLogger(
+	astroLogger: AstroLogger,
+	viteLogLevel: LogLevel = 'info'
+): ViteLogger {
+	const warnedMessages = new Set<string>();
+	const loggedErrors = new WeakSet<Error | Rollup.RollupError>();
+
+	const logger: ViteLogger = {
+		hasWarned: false,
+		info(msg) {
+			if (!isLogLevelEnabled(viteLogLevel, 'info')) return;
+
+			const stripped = stripAnsi(msg);
+			let m;
+			// Rewrite HMR page reload message
+			if ((m = vitePageReloadMsg.exec(stripped))) {
+				if (isAstroSrcFile(m[1])) return;
+				const extra = m[2] ?? '';
+				astroLogger.info('watch', m[1] + extra);
+			}
+			// Rewrite HMR update message
+			else if ((m = viteHmrUpdateMsg.exec(stripped))) {
+				if (isAstroSrcFile(m[1])) return;
+				astroLogger.info('watch', m[1]);
+			}
+			// Don't log Vite build messages
+			else if (viteBuildMsg.test(stripped)) {
+				// noop
+			}
+			// Fallback
+			else {
+				astroLogger.info('vite', msg);
+			}
+		},
+		warn(msg) {
+			if (!isLogLevelEnabled(viteLogLevel, 'warn')) return;
+
+			logger.hasWarned = true;
+			astroLogger.warn('vite', msg);
+		},
+		warnOnce(msg) {
+			if (!isLogLevelEnabled(viteLogLevel, 'warn')) return;
+
+			if (warnedMessages.has(msg)) return;
+			logger.hasWarned = true;
+			astroLogger.warn('vite', msg);
+			warnedMessages.add(msg);
+		},
+		error(msg, opts) {
+			if (!isLogLevelEnabled(viteLogLevel, 'error')) return;
+
+			logger.hasWarned = true;
+
+			const err = opts?.error;
+			if (err) loggedErrors.add(err);
+			// Astro errors are already logged by us, skip logging
+			if (err && isAstroError(err)) return;
+			// SSR module and pre-transform errors are always handled by us,
+			// send to debug logs
+			if (
+				msg.includes('Error when evaluating SSR module') ||
+				msg.includes('Pre-transform error:')
+			) {
+				astroLogger.debug('vite', msg);
+				return;
+			}
+
+			astroLogger.error('vite', msg);
+		},
+		// Don't allow clear screen
+		clearScreen: () => {},
+		hasErrorLogged(error) {
+			return loggedErrors.has(error);
+		},
+	};
+
+	return logger;
+}

packages/astro/src/vite-plugin-astro/hmr.ts

@@ -1,4 +1,3 @@
-import { fileURLToPath } from 'node:url';
 import type { HmrContext, ModuleNode } from 'vite';
 import type { AstroConfig } from '../@types/astro.js';
 import {
@@ -8,14 +7,9 @@ import {
 	type CompileResult,
 } from '../core/compile/index.js';
 import type { Logger } from '../core/logger/core.js';
+import { isAstroSrcFile } from '../core/logger/vite.js';
 import { isAstroScript } from './query.js';
 
-const PKG_PREFIX = fileURLToPath(new URL('../../', import.meta.url));
-const E2E_PREFIX = fileURLToPath(new URL('../../e2e', import.meta.url));
-const isPkgFile = (id: string | null) => {
-	return id?.startsWith(PKG_PREFIX) && !id.startsWith(E2E_PREFIX);
-};
-
 export interface HandleHotUpdateOptions {
 	config: AstroConfig;
 	logger: Logger;
@@ -45,7 +39,7 @@ export async function handleHotUpdate(
 	}
 
 	// Skip monorepo files to avoid console spam
-	if (isPkgFile(ctx.file)) {
+	if (isAstroSrcFile(ctx.file)) {
 		return;
 	}
 
@@ -55,7 +49,7 @@ export async function handleHotUpdate(
 	const files = new Set<string>();
 	for (const mod of ctx.modules) {
 		// Skip monorepo files to avoid console spam
-		if (isPkgFile(mod.id ?? mod.file)) {
+		if (isAstroSrcFile(mod.id ?? mod.file)) {
 			filtered.delete(mod);
 			continue;
 		}
@@ -107,12 +101,6 @@ export async function handleHotUpdate(
 		}
 	}
 
-	// TODO: Svelte files should be marked as `isSelfAccepting` but they don't appear to be
-	const isSelfAccepting = mods.every((m) => m.isSelfAccepting || m.url.endsWith('.svelte'));
-	if (!isSelfAccepting) {
-		logger.debug('watch', 'full page reload triggered');
-	}
-
 	return mods;
 }
 

packages/astro/src/vite-plugin-astro/index.ts

@@ -4,7 +4,6 @@ import type { AstroSettings } from '../@types/astro.js';
 import type { Logger } from '../core/logger/core.js';
 import type { PluginMetadata as AstroPluginMetadata } from './types.js';
 
-import { fileURLToPath } from 'url';
 import { normalizePath } from 'vite';
 import {
 	cachedCompilation,
@@ -24,28 +23,6 @@ interface AstroPluginOptions {
 	logger: Logger;
 }
 
-const PKG_PREFIX = fileURLToPath(new URL('../../', import.meta.url));
-const E2E_PREFIX = fileURLToPath(new URL('../../e2e', import.meta.url));
-const isPkgFile = (id: string | null) => {
-	return id?.startsWith(PKG_PREFIX) && !id.startsWith(E2E_PREFIX);
-};
-
-const dedupeHotUpdateLogsCache = new Map<string, NodeJS.Timeout>();
-
-// TODO(fks): For some reason, we're seeing duplicate handleHotUpdate() calls
-// when hitting save multiple times in a row. This is a temporary workaround
-// to prevent duplicate logging until the (vite?) issue is fixed.
-function dedupeHotUpdateLogs(filename: string) {
-	if (dedupeHotUpdateLogsCache.has(filename)) {
-		return false;
-	}
-	dedupeHotUpdateLogsCache.set(
-		filename,
-		setTimeout(() => dedupeHotUpdateLogsCache.delete(filename), 150)
-	);
-	return true;
-}
-
 /** Transform .astro files for Vite */
 export default function astro({ settings, logger }: AstroPluginOptions): vite.Plugin[] {
 	const { config } = settings;
@@ -197,13 +174,6 @@ export default function astro({ settings, logger }: AstroPluginOptions): vite.Pl
 		async handleHotUpdate(context) {
 			if (context.server.config.isProduction) return;
 			const filename = context.file;
-			const isSkipLog =
-				/astro\.config\.[cm][jt]s$/.test(filename) ||
-				/(\/|\\)\.astro(\/|\\)/.test(filename) ||
-				isPkgFile(filename);
-			if (!isSkipLog && dedupeHotUpdateLogs(filename)) {
-				logger.info('watch', filename.replace(config.root.pathname, '/'));
-			}
 			const source = await context.read();
 			const compile = () =>
 				cachedCompilation({