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

feat: error log improvements #1202

Merged
merged 8 commits into from Apr 28, 2022
11 changes: 9 additions & 2 deletions packages/vitest/src/integrations/vi.ts
Expand Up @@ -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
Expand Down
5 changes: 1 addition & 4 deletions 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 {
/**
Expand Down Expand Up @@ -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
}
Expand Down
17 changes: 13 additions & 4 deletions packages/vitest/src/node/core.ts
Expand Up @@ -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
Expand Down Expand Up @@ -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) {
Expand Down
74 changes: 65 additions & 9 deletions 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'
Expand All @@ -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') {
Expand All @@ -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)

Expand All @@ -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')
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 found a bug where fs.readFile stalls the terminal, and breaks for of loop - because of that some stack trace might be missing.

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\'',
Expand Down Expand Up @@ -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)
Expand All @@ -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(
Expand Down
5 changes: 4 additions & 1 deletion packages/vitest/src/node/pool.ts
Expand Up @@ -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())
},
},
{
Expand Down
22 changes: 18 additions & 4 deletions packages/vitest/src/node/reporters/base.ts
Expand Up @@ -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[]) {
Expand Down Expand Up @@ -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)
Expand All @@ -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()
Expand Down Expand Up @@ -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)
})
Expand Down
4 changes: 2 additions & 2 deletions packages/vitest/src/node/reporters/default.ts
Expand Up @@ -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() {
Expand Down
4 changes: 2 additions & 2 deletions packages/vitest/src/node/reporters/dot.ts
Expand Up @@ -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() {
Expand Down
16 changes: 15 additions & 1 deletion 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)
Expand Down
4 changes: 4 additions & 0 deletions packages/vitest/src/runtime/worker.ts
Expand Up @@ -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({
Expand Down
1 change: 1 addition & 0 deletions packages/vitest/src/types/general.ts
Expand Up @@ -71,6 +71,7 @@ export interface ErrorWithDiff extends Error {
actual?: any
expected?: any
operator?: string
type?: string
}

export interface ModuleGraphData {
Expand Down
2 changes: 1 addition & 1 deletion packages/vitest/src/types/reporter.ts
Expand Up @@ -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>
Expand Down
3 changes: 2 additions & 1 deletion packages/vitest/src/types/worker.ts
Expand Up @@ -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

Expand Down
2 changes: 2 additions & 0 deletions packages/vitest/src/utils/source-map.ts
Expand Up @@ -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
Expand Down