From 306b54503af332a70d5918b39ee60c5944212bcc Mon Sep 17 00:00:00 2001 From: Vladimir Date: Thu, 28 Apr 2022 13:03:34 +0300 Subject: [PATCH] feat: error log improvements (#1202) * feat: improve error logging * feat: more friendly error message for "Vitest initialized with Native Node" * chore: don't exit the process on inhandled rejections * feat: show "cause" error * refactor: pass options object to printError * chore: get only own proprty names for error object * fix: show that tests are failed if there are unhandled errors * chore: ignore constructor, toString on error --- packages/vitest/src/integrations/vi.ts | 11 ++- packages/vitest/src/node/cli-api.ts | 5 +- packages/vitest/src/node/core.ts | 17 ++++- packages/vitest/src/node/error.ts | 74 ++++++++++++++++--- packages/vitest/src/node/pool.ts | 5 +- packages/vitest/src/node/reporters/base.ts | 22 +++++- packages/vitest/src/node/reporters/default.ts | 4 +- packages/vitest/src/node/reporters/dot.ts | 4 +- packages/vitest/src/node/state.ts | 16 +++- packages/vitest/src/runtime/worker.ts | 4 + packages/vitest/src/types/general.ts | 1 + packages/vitest/src/types/reporter.ts | 2 +- packages/vitest/src/types/worker.ts | 3 +- packages/vitest/src/utils/source-map.ts | 2 + 14 files changed, 139 insertions(+), 31 deletions(-) diff --git a/packages/vitest/src/integrations/vi.ts b/packages/vitest/src/integrations/vi.ts index 3eac9c9dd713..66b113d10d79 100644 --- a/packages/vitest/src/integrations/vi.ts +++ b/packages/vitest/src/integrations/vi.ts @@ -21,8 +21,15 @@ class VitestUtils { this._mocker = typeof __vitest_mocker__ !== 'undefined' ? __vitest_mocker__ : null this._mockedDate = null - if (!this._mocker) - throw new Error('Vitest was initialized with native Node instead of Vite Node') + if (!this._mocker) { + const errorMsg = 'Vitest was initialized with native Node instead of Vite Node.' + + '\n\nOne of the following is possible:' + + '\n- "vitest" is imported outside of your tests (in that case, use "vitest/node" or import.meta.vitest)' + + '\n- "vitest" is imported inside "globalSetup" (use "setupFiles", because "globalSetup" runs in a different context)' + + '\n- Your dependency inside "node_modules" imports "vitest" directly (in that case, inline that dependency, using "deps.inline" config)' + + '\n- Otherwise, it might be a Vitest bug. Please report it to https://github.com/vitest-dev/vitest/issues\n' + throw new Error(errorMsg) + } } // timers diff --git a/packages/vitest/src/node/cli-api.ts b/packages/vitest/src/node/cli-api.ts index 4216f1d08ff1..16bc1a6945a6 100644 --- a/packages/vitest/src/node/cli-api.ts +++ b/packages/vitest/src/node/cli-api.ts @@ -1,11 +1,9 @@ import { execa } from 'execa' import type { UserConfig as ViteUserConfig } from 'vite' -import c from 'picocolors' import type { UserConfig } from '../types' import { ensurePackageInstalled } from '../utils' import { createVitest } from './create' import { registerConsoleShortcuts } from './stdin' -import { divider } from './reporters/renderers/utils' export interface CliOptions extends UserConfig { /** @@ -75,8 +73,7 @@ export async function startVitest(cliFilters: string[], options: CliOptions, vit } catch (e) { process.exitCode = 1 - ctx.error(`\n${c.red(divider(c.bold(c.inverse(' Unhandled Error '))))}`) - await ctx.printError(e) + await ctx.printError(e, true, 'Unhandled Error') ctx.error('\n\n') return false } diff --git a/packages/vitest/src/node/core.ts b/packages/vitest/src/node/core.ts index 4cdaf0227411..96463c7455fe 100644 --- a/packages/vitest/src/node/core.ts +++ b/packages/vitest/src/node/core.ts @@ -226,12 +226,17 @@ export class Vitest { const invalidates = Array.from(this.invalidates) this.invalidates.clear() this.snapshot.clear() - await this.pool.runTests(files, invalidates) + try { + await this.pool.runTests(files, invalidates) + } + catch (err) { + this.state.catchError(err, 'Unhandled Error') + } if (hasFailed(this.state.getFiles())) process.exitCode = 1 - await this.report('onFinished', this.state.getFiles()) + await this.report('onFinished', this.state.getFiles(), this.state.getUnhandledErrors()) })() .finally(() => { this.runningPromise = undefined @@ -493,8 +498,12 @@ export class Vitest { return code.includes('import.meta.vitest') } - printError(err: unknown) { - return printError(err, this) + printError(err: unknown, fullStack = false, type?: string) { + return printError(err, this, { + fullStack, + type, + showCodeFrame: true, + }) } onServerRestarted(fn: () => void) { diff --git a/packages/vitest/src/node/error.ts b/packages/vitest/src/node/error.ts index c973e1b22132..a3f12ef63a76 100644 --- a/packages/vitest/src/node/error.ts +++ b/packages/vitest/src/node/error.ts @@ -1,6 +1,6 @@ /* eslint-disable prefer-template */ /* eslint-disable no-template-curly-in-string */ -import { existsSync, promises as fs } from 'fs' +import { existsSync, readFileSync } from 'fs' import { join, relative } from 'pathe' import c from 'picocolors' import cliTruncate from 'cli-truncate' @@ -10,6 +10,7 @@ import { F_POINTER } from '../utils/figures' import { stringify } from '../integrations/chai/jest-matcher-utils' import type { Vitest } from './core' import { unifiedDiff } from './diff' +import { divider } from './reporters/renderers/utils' export function fileFromParsedStack(stack: ParsedStack) { if (stack?.sourcePos?.source?.startsWith('..')) @@ -17,7 +18,14 @@ export function fileFromParsedStack(stack: ParsedStack) { return stack.file } -export async function printError(error: unknown, ctx: Vitest) { +interface PrintErrorOptions { + type?: string + fullStack?: boolean + showCodeFrame?: boolean +} + +export async function printError(error: unknown, ctx: Vitest, options: PrintErrorOptions = {}) { + const { showCodeFrame = true, fullStack = false, type } = options let e = error as ErrorWithDiff if (typeof error === 'string') { @@ -27,7 +35,7 @@ export async function printError(error: unknown, ctx: Vitest) { } as any } - const stacks = parseStacktrace(e) + const stacks = parseStacktrace(e, fullStack) await interpretSourcePos(stacks, ctx) @@ -36,20 +44,61 @@ export async function printError(error: unknown, ctx: Vitest) { && existsSync(stack.file), ) + const errorProperties = getErrorProperties(e) + + if (type) + printErrorType(type, ctx) printErrorMessage(e, ctx.console) - await printStack(ctx, stacks, nearest, async (s, pos) => { - if (s === nearest && nearest) { - const sourceCode = await fs.readFile(fileFromParsedStack(nearest), 'utf-8') + printStack(ctx, stacks, nearest, errorProperties, (s, pos) => { + if (showCodeFrame && s === nearest && nearest) { + const sourceCode = readFileSync(fileFromParsedStack(nearest), 'utf-8') ctx.log(c.yellow(generateCodeFrame(sourceCode, 4, pos))) } }) + if (e.cause) { + e.cause.name = `Caused by: ${e.cause.name}` + await printError(e.cause, ctx, { fullStack, showCodeFrame: false }) + } + handleImportOutsideModuleError(e.stack || e.stackStr || '', ctx) if (e.showDiff) displayDiff(stringify(e.actual), stringify(e.expected), ctx.console, ctx.config.outputTruncateLength) } +function printErrorType(type: string, ctx: Vitest) { + ctx.error(`\n${c.red(divider(c.bold(c.inverse(` ${type} `))))}`) +} + +function getErrorProperties(e: ErrorWithDiff) { + const errorObject = Object.create(null) + if (e.name === 'AssertionError') + return errorObject + + const skip = [ + 'message', + 'name', + 'nameStr', + 'stack', + 'cause', + 'stacks', + 'stackStr', + 'type', + 'showDiff', + 'actual', + 'expected', + 'constructor', + 'toString', + ] + for (const key of Object.getOwnPropertyNames(e)) { + if (!skip.includes(key)) + errorObject[key] = e[key as keyof ErrorWithDiff] + } + + return errorObject +} + const esmErrors = [ 'Cannot use import statement outside a module', 'Unexpected token \'export\'', @@ -95,10 +144,11 @@ function printErrorMessage(error: ErrorWithDiff, console: Console) { console.error(c.red(`${c.bold(errorName)}: ${error.message}`)) } -async function printStack( +function printStack( ctx: Vitest, stack: ParsedStack[], - highlight?: ParsedStack, + highlight: ParsedStack | undefined, + errorProperties: Record, onStack?: ((stack: ParsedStack, pos: Position) => void), ) { if (!stack.length) @@ -111,13 +161,19 @@ async function printStack( const path = relative(ctx.config.root, file) ctx.log(color(` ${c.dim(F_POINTER)} ${[frame.method, c.dim(`${path}:${pos.line}:${pos.column}`)].filter(Boolean).join(' ')}`)) - await onStack?.(frame, pos) + onStack?.(frame, pos) // reached at test file, skip the follow stack if (frame.file in ctx.state.filesMap) break } ctx.log() + const hasProperties = Object.keys(errorProperties).length > 0 + if (hasProperties) { + ctx.log(c.red(c.dim(divider()))) + const propertiesString = stringify(errorProperties, 10, { printBasicPrototype: false }) + ctx.log(c.red(c.bold('Serialized Error:')), c.gray(propertiesString)) + } } export function generateCodeFrame( diff --git a/packages/vitest/src/node/pool.ts b/packages/vitest/src/node/pool.ts index 191b4f753556..b4f4ea59aa79 100644 --- a/packages/vitest/src/node/pool.ts +++ b/packages/vitest/src/node/pool.ts @@ -148,8 +148,11 @@ function createChannel(ctx: Vitest) { ctx.state.updateUserLog(log) ctx.report('onUserConsoleLog', log) }, + onUnhandledRejection(err) { + ctx.state.catchError(err, 'Unhandled Rejection') + }, onFinished(files) { - ctx.report('onFinished', files) + ctx.report('onFinished', files, ctx.state.getUnhandledErrors()) }, }, { diff --git a/packages/vitest/src/node/reporters/base.ts b/packages/vitest/src/node/reporters/base.ts index a522333777ff..0560c907e1da 100644 --- a/packages/vitest/src/node/reporters/base.ts +++ b/packages/vitest/src/node/reporters/base.ts @@ -53,9 +53,22 @@ export abstract class BaseReporter implements Reporter { return relative(this.ctx.config.root, path) } - async onFinished(files = this.ctx.state.getFiles()) { + async onFinished(files = this.ctx.state.getFiles(), errors = this.ctx.state.getUnhandledErrors()) { this.end = performance.now() await this.reportSummary(files) + if (errors.length) { + process.exitCode = 1 + const errorMessage = c.red(c.bold( + `\nVitest catched ${errors.length} unhandled error${errors.length > 1 ? 's' : ''} during the test run. This might cause false positive tests.` + + '\nPlease, resolve all the errors to make sure your tests are not affected.', + )) + this.ctx.log(c.red(divider(c.bold(c.inverse(' Unhandled Errors '))))) + this.ctx.log(errorMessage) + await Promise.all(errors.map(async (err) => { + await this.ctx.printError(err, true, (err as ErrorWithDiff).type || 'Unhandled Error') + })) + this.ctx.log(c.red(divider())) + } } onTaskUpdate(packs: TaskResultPack[]) { @@ -89,7 +102,8 @@ export abstract class BaseReporter implements Reporter { async onWatcherStart() { const files = this.ctx.state.getFiles() - const failed = hasFailed(files) + const errors = this.ctx.state.getUnhandledErrors() + const failed = errors.length > 0 || hasFailed(files) const failedSnap = hasFailedSnapshot(files) if (failed) this.ctx.log(WAIT_FOR_CHANGE_FAIL) @@ -108,6 +122,7 @@ export abstract class BaseReporter implements Reporter { async onWatcherRerun(files: string[], trigger?: string) { this.watchFilters = files + this.ctx.state.clearErrors() this.ctx.clearScreen() this.ctx.log(`\n${c.inverse(c.bold(c.blue(' RERUN ')))}${trigger ? c.dim(` ${this.relative(trigger)}\n`) : ''}`) this.start = performance.now() @@ -209,8 +224,7 @@ export abstract class BaseReporter implements Reporter { registerUnhandledRejection() { process.on('unhandledRejection', async (err) => { process.exitCode = 1 - this.ctx.error(`\n${c.red(divider(c.bold(c.inverse(' Unhandled Rejection '))))}`) - await this.ctx.printError(err) + await this.ctx.printError(err, true, 'Unhandled Rejection') this.ctx.error('\n\n') process.exit(1) }) diff --git a/packages/vitest/src/node/reporters/default.ts b/packages/vitest/src/node/reporters/default.ts index 3d067b4405d6..c26e00e9721c 100644 --- a/packages/vitest/src/node/reporters/default.ts +++ b/packages/vitest/src/node/reporters/default.ts @@ -30,10 +30,10 @@ export class DefaultReporter extends BaseReporter { } } - async onFinished(files = this.ctx.state.getFiles()) { + async onFinished(files = this.ctx.state.getFiles(), errors = this.ctx.state.getUnhandledErrors()) { await this.stopListRender() this.ctx.log() - await super.onFinished(files) + await super.onFinished(files, errors) } async onWatcherStart() { diff --git a/packages/vitest/src/node/reporters/dot.ts b/packages/vitest/src/node/reporters/dot.ts index 55bf2ef9f499..3bc3e820fcd7 100644 --- a/packages/vitest/src/node/reporters/dot.ts +++ b/packages/vitest/src/node/reporters/dot.ts @@ -17,10 +17,10 @@ export class DotReporter extends BaseReporter { } } - async onFinished(files = this.ctx.state.getFiles()) { + async onFinished(files = this.ctx.state.getFiles(), errors = this.ctx.state.getUnhandledErrors()) { await this.stopListRender() this.ctx.log() - await super.onFinished(files) + await super.onFinished(files, errors) } async onWatcherStart() { diff --git a/packages/vitest/src/node/state.ts b/packages/vitest/src/node/state.ts index 91d0785736ca..2db75565ebbe 100644 --- a/packages/vitest/src/node/state.ts +++ b/packages/vitest/src/node/state.ts @@ -1,9 +1,23 @@ -import type { File, Task, TaskResultPack, UserConsoleLog } from '../types' +import type { ErrorWithDiff, File, Task, TaskResultPack, UserConsoleLog } from '../types' export class StateManager { filesMap = new Map() idMap = new Map() taskFileMap = new WeakMap() + errorsSet = new Set() + + catchError(err: unknown, type: string) { + (err as ErrorWithDiff).type = type + this.errorsSet.add(err) + } + + clearErrors() { + this.errorsSet.clear() + } + + getUnhandledErrors() { + return Array.from(this.errorsSet.values()) + } getFiles(keys?: string[]): File[] { if (keys) diff --git a/packages/vitest/src/runtime/worker.ts b/packages/vitest/src/runtime/worker.ts index 31703979a804..fe827f25c852 100644 --- a/packages/vitest/src/runtime/worker.ts +++ b/packages/vitest/src/runtime/worker.ts @@ -31,6 +31,10 @@ async function startViteNode(ctx: WorkerContext) { return processExit(code) } + process.on('unhandledRejection', (err) => { + rpc().onUnhandledRejection(err) + }) + const { config } = ctx const { run, collect } = (await executeInViteNode({ diff --git a/packages/vitest/src/types/general.ts b/packages/vitest/src/types/general.ts index 7005ed271b98..8b621e0716c7 100644 --- a/packages/vitest/src/types/general.ts +++ b/packages/vitest/src/types/general.ts @@ -71,6 +71,7 @@ export interface ErrorWithDiff extends Error { actual?: any expected?: any operator?: string + type?: string } export interface ModuleGraphData { diff --git a/packages/vitest/src/types/reporter.ts b/packages/vitest/src/types/reporter.ts index 0f79bd53249e..c971c7ed18cb 100644 --- a/packages/vitest/src/types/reporter.ts +++ b/packages/vitest/src/types/reporter.ts @@ -5,7 +5,7 @@ import type { File, TaskResultPack } from './tasks' export interface Reporter { onInit?(ctx: Vitest): void onCollected?: (files?: File[]) => Awaitable - onFinished?: (files?: File[]) => Awaitable + onFinished?: (files?: File[], errors?: unknown[]) => Awaitable onTaskUpdate?: (packs: TaskResultPack[]) => Awaitable onTestRemoved?: (trigger?: string) => Awaitable diff --git a/packages/vitest/src/types/worker.ts b/packages/vitest/src/types/worker.ts index bb2717620750..e48b05a59c25 100644 --- a/packages/vitest/src/types/worker.ts +++ b/packages/vitest/src/types/worker.ts @@ -22,9 +22,10 @@ export interface WorkerRPC { resolveId: ResolveIdFunction getSourceMap: (id: string, force?: boolean) => Promise - onFinished: (files: File[]) => void + onFinished: (files: File[], errors?: unknown[]) => void onWorkerExit: (code?: number) => void onUserConsoleLog: (log: UserConsoleLog) => void + onUnhandledRejection: (err: unknown) => void onCollected: (files: File[]) => void onTaskUpdate: (pack: TaskResultPack[]) => void diff --git a/packages/vitest/src/utils/source-map.ts b/packages/vitest/src/utils/source-map.ts index aa776cbeed16..197be8649694 100644 --- a/packages/vitest/src/utils/source-map.ts +++ b/packages/vitest/src/utils/source-map.ts @@ -26,6 +26,8 @@ const stackBarePathRE = /at ?(.*) (.+):(\d+):(\d+)$/ export async function interpretSourcePos(stackFrames: ParsedStack[], ctx: Vitest): Promise { for (const frame of stackFrames) { + if ('sourcePos' in frame) + continue const transformResult = ctx.server.moduleGraph.getModuleById(frame.file)?.ssrTransformResult if (!transformResult) continue