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

@@ -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

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
   }

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) {

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,14 +10,22 @@ 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('..'))
     return join(stack.file, '../', stack.sourcePos.source)
   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<string, unknown>,
   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(

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())
       },
     },
     {

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)
     })

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() {

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() {

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<string, File>()
   idMap = new Map<string, Task>()
   taskFileMap = new WeakMap<Task, File>()
+  errorsSet = new Set<unknown>()
+
+  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)

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({

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 {

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<void>
-  onFinished?: (files?: File[]) => Awaitable<void>
+  onFinished?: (files?: File[], errors?: unknown[]) => Awaitable<void>
   onTaskUpdate?: (packs: TaskResultPack[]) => Awaitable<void>
 
   onTestRemoved?: (trigger?: string) => Awaitable<void>

packages/vitest/src/types/worker.ts

@@ -22,9 +22,10 @@ export interface WorkerRPC {
   resolveId: ResolveIdFunction
   getSourceMap: (id: string, force?: boolean) => Promise<RawSourceMap | undefined>
 
-  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
 

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<ParsedStack[]> {
   for (const frame of stackFrames) {
+    if ('sourcePos' in frame)
+      continue
     const transformResult = ctx.server.moduleGraph.getModuleById(frame.file)?.ssrTransformResult
     if (!transformResult)
       continue