Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rework Vite and Astro logger for HMR messages #9139

Merged
merged 10 commits into from
Dec 1, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions .changeset/gold-grapes-jump.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,5 @@
---
'astro': minor
---

Reworks Vite's logger to use Astro's logger to correctly log HMR messages
5 changes: 1 addition & 4 deletions packages/astro/src/core/build/static-build.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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,
Expand Down
16 changes: 2 additions & 14 deletions packages/astro/src/core/create-vite.ts
Original file line number Diff line number Diff line change
@@ -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';
Expand Down Expand Up @@ -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';

Expand Down Expand Up @@ -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),
};
bluwy marked this conversation as resolved.
Show resolved Hide resolved

// 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/**/*'],
Expand Down
6 changes: 5 additions & 1 deletion packages/astro/src/core/logger/core.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down
97 changes: 97 additions & 0 deletions packages/astro/src/core/logger/vite.ts
Original file line number Diff line number Diff line change
@@ -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))) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The fact that some files are logged by Vite with a leading / and some are not is pretty odd and would confuse me as a user (especially on windows where I imagine one would have / and the other would have \). Does Vite consider this a bug?

I also don't love matching strings like this with regex, since these error messages aren't usually covered by semver and can change unexpectedly across different versions.

I think I prefer the solution that keeps handling this ourselves in handleHotUpdate where we can control things ourselves, for those reasons. But I also could be missing some benefits!

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've left a note in the description about the slash issue:

NOTE: there's a leading slash inconcistency for [watch] messages, seems to be intended in Vite. Leading slash is the URL, non-leading slash is for local files.

I investigated that yesterday and it seems safer this way since you may sometime get /@fs/some/fs/path and it would not be safe to remove the initial slash.

If we put back in handleHotUpdate, we won't be able to fix #8224 though. Since an update that calls handleHotUpdate doesn't always trigger HMR, e.g. if you're editing files that are not part of your app.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I also didn't find a cleaner way besides the regex, though Vite hasn't changed those HMR messages across many majors now. It seems to be the easiest way to get the exact paths that would trigger HMR + whether the HMR will trigger a page reload or HMR update, which our logs don't differentiate now but we could.

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]);
}
bluwy marked this conversation as resolved.
Show resolved Hide resolved
// 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;
}
18 changes: 3 additions & 15 deletions packages/astro/src/vite-plugin-astro/hmr.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,3 @@
import { fileURLToPath } from 'node:url';
import type { HmrContext, ModuleNode } from 'vite';
import type { AstroConfig } from '../@types/astro.js';
import {
Expand All @@ -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;
Expand Down Expand Up @@ -45,7 +39,7 @@ export async function handleHotUpdate(
}

// Skip monorepo files to avoid console spam
if (isPkgFile(ctx.file)) {
if (isAstroSrcFile(ctx.file)) {
return;
}

Expand All @@ -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;
}
Expand Down Expand Up @@ -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');
}
bluwy marked this conversation as resolved.
Show resolved Hide resolved

return mods;
}

Expand Down
30 changes: 0 additions & 30 deletions packages/astro/src/vite-plugin-astro/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand All @@ -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;
Expand Down Expand Up @@ -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, '/'));
}
Comment on lines -200 to -206
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This part can be removed as Vite now logs the actual changed files instead. The dedupe should also not be needed now as we log things through the Vite logger.

const source = await context.read();
const compile = () =>
cachedCompilation({
Expand Down