Skip to content

Commit e4fe6f5

Browse files
sheremet-vasheremet-va
authored
feat: add an option to print console stack trace (#5720)
1 parent fc53f56 commit e4fe6f5

File tree

17 files changed

+267
-38
lines changed

17 files changed

+267
-38
lines changed

‎docs/config/index.md

+7
Original file line numberDiff line numberDiff line change
@@ -2322,3 +2322,10 @@ Polling interval in milliseconds
23222322
- **Default:** `1000`
23232323

23242324
Polling timeout in milliseconds
2325+
2326+
### printConsoleTrace
2327+
2328+
- **Type:** `boolean`
2329+
- **Default:** `false`
2330+
2331+
Always print console traces when calling any `console` method. This is useful for debugging.

‎packages/browser/src/client/logger.ts

+8-3
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import { rpc } from './rpc'
2-
import { importId } from './utils'
2+
import { getConfig, importId } from './utils'
33

44
const { Date, console } = globalThis
55

@@ -12,14 +12,19 @@ export async function setupConsoleLogSpy() {
1212
return format(input)
1313
}
1414
const processLog = (args: unknown[]) => args.map(formatInput).join(' ')
15-
const sendLog = (type: 'stdout' | 'stderr', content: string) => {
15+
const sendLog = (type: 'stdout' | 'stderr', content: string, disableStack?: boolean) => {
1616
if (content.startsWith('[vite]'))
1717
return
1818
const unknownTestId = '__vitest__unknown_test__'
1919
// @ts-expect-error untyped global
2020
const taskId = globalThis.__vitest_worker__?.current?.id ?? unknownTestId
21+
const origin = getConfig().printConsoleTrace && !disableStack
22+
? new Error('STACK_TRACE').stack?.split('\n').slice(1).join('\n')
23+
: undefined
2124
rpc().sendLog({
25+
origin,
2226
content,
27+
browser: true,
2328
time: Date.now(),
2429
taskId,
2530
type,
@@ -58,7 +63,7 @@ export async function setupConsoleLogSpy() {
5863
.split('\n')
5964
.slice(error.stack?.includes('$$Trace') ? 2 : 1)
6065
.join('\n')
61-
sendLog('stdout', `${content}\n${stack}`)
66+
sendLog('stderr', `${content}\n${stack}`, true)
6267
return trace(...args)
6368
}
6469

‎packages/vitest/src/node/cli/cli-config.ts

+3
Original file line numberDiff line numberDiff line change
@@ -618,6 +618,9 @@ export const cliOptionsConfig: VitestCLIOptions = {
618618
return value
619619
},
620620
},
621+
printConsoleTrace: {
622+
description: 'Always print console stack traces',
623+
},
621624

622625
// CLI only options
623626
run: {

‎packages/vitest/src/node/core.ts

+1
Original file line numberDiff line numberDiff line change
@@ -315,6 +315,7 @@ export class Vitest {
315315
'passWithNoTests',
316316
'bail',
317317
'isolate',
318+
'printConsoleTrace',
318319
] as const
319320

320321
const cliOverrides = overridesOptions.reduce((acc, name) => {

‎packages/vitest/src/node/error.ts

+1-1
Original file line numberDiff line numberDiff line change
@@ -260,7 +260,7 @@ function printErrorMessage(error: ErrorWithDiff, logger: Logger) {
260260
}
261261
}
262262

263-
function printStack(
263+
export function printStack(
264264
logger: Logger,
265265
project: WorkspaceProject,
266266
stack: ParsedStack[],

‎packages/vitest/src/node/reporters/base.ts

+27-3
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,11 @@
11
import { performance } from 'node:perf_hooks'
22
import c from 'picocolors'
3+
import { parseStacktrace } from '@vitest/utils/source-map'
4+
import { relative } from 'pathe'
35
import type { ErrorWithDiff, File, Reporter, Task, TaskResultPack, UserConsoleLog } from '../../types'
46
import { getFullName, getSafeTimers, getSuites, getTests, hasFailed, hasFailedSnapshot, isCI, isNode, relativePath, toArray } from '../../utils'
57
import type { Vitest } from '../../node'
6-
import { F_RIGHT } from '../../utils/figures'
8+
import { F_POINTER, F_RIGHT } from '../../utils/figures'
79
import { UNKNOWN_TEST_ID } from '../../runtime/console'
810
import { countTestErrors, divider, formatProjectName, formatTimeString, getStateString, getStateSymbol, pointer, renderSnapshotSummary } from './renderers/utils'
911

@@ -198,9 +200,31 @@ export abstract class BaseReporter implements Reporter {
198200
const header = c.gray(log.type + c.dim(` | ${task ? getFullName(task, c.dim(' > ')) : log.taskId !== UNKNOWN_TEST_ID ? log.taskId : 'unknown test'}`))
199201

200202
const output = log.type === 'stdout' ? this.ctx.logger.outputStream : this.ctx.logger.errorStream
203+
const write = (msg: string) => (output as any).write(msg)
204+
205+
write(`${header}\n${log.content}`)
206+
207+
if (log.origin) {
208+
// browser logs don't have an extra end of line at the end like Node.js does
209+
if (log.browser)
210+
write('\n')
211+
const project = log.taskId
212+
? this.ctx.getProjectByTaskId(log.taskId)
213+
: this.ctx.getCoreWorkspaceProject()
214+
const stack = parseStacktrace(log.origin, {
215+
getSourceMap: file => project.getBrowserSourceMapModuleById(file),
216+
frameFilter: project.config.onStackTrace,
217+
})
218+
const highlight = task ? stack.find(i => i.file === task.file.filepath) : null
219+
for (const frame of stack) {
220+
const color = frame === highlight ? c.cyan : c.gray
221+
const path = relative(project.config.root, frame.file)
222+
223+
write(color(` ${c.dim(F_POINTER)} ${[frame.method, `${path}:${c.dim(`${frame.line}:${frame.column}`)}`].filter(Boolean).join(' ')}\n`))
224+
}
225+
}
201226

202-
// @ts-expect-error -- write() method has different signature on the union type
203-
output.write(`${header}\n${log.content}\n`)
227+
write('\n')
204228
}
205229

206230
shouldLog(log: UserConsoleLog) {

‎packages/vitest/src/node/workspace.ts

+1
Original file line numberDiff line numberDiff line change
@@ -397,6 +397,7 @@ export class WorkspaceProject {
397397
testerScripts: [],
398398
commands: {},
399399
},
400+
printConsoleTrace: this.config.printConsoleTrace ?? this.ctx.config.printConsoleTrace,
400401
}, this.ctx.configOverride || {} as any) as ResolvedConfig
401402
}
402403

‎packages/vitest/src/runtime/console.ts

+66-23
Original file line numberDiff line numberDiff line change
@@ -54,36 +54,52 @@ export function createCustomConsole(defaultState?: WorkerGlobalState) {
5454
})
5555
}
5656
function sendStdout(taskId: string) {
57-
const buffer = stdoutBuffer.get(taskId)
58-
if (!buffer)
59-
return
60-
const content = buffer.map(i => String(i)).join('')
61-
const timer = timers.get(taskId)!
62-
state().rpc.onUserConsoleLog({
63-
type: 'stdout',
64-
content: content || '<empty line>',
65-
taskId,
66-
time: timer.stdoutTime || RealDate.now(),
67-
size: buffer.length,
68-
})
69-
stdoutBuffer.set(taskId, [])
70-
timer.stdoutTime = 0
57+
sendBuffer('stdout', taskId)
7158
}
59+
7260
function sendStderr(taskId: string) {
73-
const buffer = stderrBuffer.get(taskId)
61+
sendBuffer('stderr', taskId)
62+
}
63+
64+
function sendBuffer(type: 'stdout' | 'stderr', taskId: string) {
65+
const buffers = type === 'stdout' ? stdoutBuffer : stderrBuffer
66+
const buffer = buffers.get(taskId)
7467
if (!buffer)
7568
return
76-
const content = buffer.map(i => String(i)).join('')
69+
if (state().config.printConsoleTrace) {
70+
buffer.forEach(([buffer, origin]) => {
71+
sendLog(type, taskId, String(buffer), buffer.length, origin)
72+
})
73+
}
74+
else {
75+
const content = buffer.map(i => String(i[0])).join('')
76+
sendLog(type, taskId, content, buffer.length)
77+
}
7778
const timer = timers.get(taskId)!
79+
buffers.set(taskId, [])
80+
if (type === 'stderr')
81+
timer.stderrTime = 0
82+
else
83+
timer.stdoutTime = 0
84+
}
85+
86+
function sendLog(
87+
type: 'stderr' | 'stdout',
88+
taskId: string,
89+
content: string,
90+
size: number,
91+
origin?: string,
92+
) {
93+
const timer = timers.get(taskId)!
94+
const time = type === 'stderr' ? timer.stderrTime : timer.stdoutTime
7895
state().rpc.onUserConsoleLog({
79-
type: 'stderr',
96+
type,
8097
content: content || '<empty line>',
8198
taskId,
82-
time: timer.stderrTime || RealDate.now(),
83-
size: buffer.length,
99+
time: time || RealDate.now(),
100+
size,
101+
origin,
84102
})
85-
stderrBuffer.set(taskId, [])
86-
timer.stderrTime = 0
87103
}
88104

89105
const stdout = new Writable({
@@ -103,7 +119,17 @@ export function createCustomConsole(defaultState?: WorkerGlobalState) {
103119
buffer = []
104120
stdoutBuffer.set(id, buffer)
105121
}
106-
buffer.push(data)
122+
if (state().config.printConsoleTrace) {
123+
const limit = Error.stackTraceLimit
124+
Error.stackTraceLimit = limit + 6
125+
const stack = new Error('STACK_TRACE').stack
126+
const trace = stack?.split('\n').slice(7).join('\n')
127+
Error.stackTraceLimit = limit
128+
buffer.push([data, trace])
129+
}
130+
else {
131+
buffer.push([data, undefined])
132+
}
107133
schedule(id)
108134
callback()
109135
},
@@ -125,7 +151,24 @@ export function createCustomConsole(defaultState?: WorkerGlobalState) {
125151
buffer = []
126152
stderrBuffer.set(id, buffer)
127153
}
128-
buffer.push(data)
154+
if (state().config.printConsoleTrace) {
155+
const limit = Error.stackTraceLimit
156+
Error.stackTraceLimit = limit + 6
157+
const stack = new Error('STACK_TRACE').stack?.split('\n')
158+
Error.stackTraceLimit = limit
159+
const isTrace = stack?.some(line => line.includes('at Console.trace'))
160+
if (isTrace) {
161+
buffer.push([data, undefined])
162+
}
163+
else {
164+
const trace = stack?.slice(7).join('\n')
165+
Error.stackTraceLimit = limit
166+
buffer.push([data, trace])
167+
}
168+
}
169+
else {
170+
buffer.push([data, undefined])
171+
}
129172
schedule(id)
130173
callback()
131174
},

‎packages/vitest/src/types/config.ts

+8
Original file line numberDiff line numberDiff line change
@@ -765,6 +765,13 @@ export interface InlineConfig {
765765
*/
766766
disableConsoleIntercept?: boolean
767767

768+
/**
769+
* Always print console stack traces.
770+
*
771+
* @default false
772+
*/
773+
printConsoleTrace?: boolean
774+
768775
/**
769776
* Include "location" property inside the test definition
770777
*
@@ -1000,6 +1007,7 @@ export type RuntimeConfig = Pick<
10001007
| 'fakeTimers'
10011008
| 'maxConcurrency'
10021009
| 'expect'
1010+
| 'printConsoleTrace'
10031011
> & {
10041012
sequence?: {
10051013
concurrent?: boolean

‎packages/vitest/src/types/general.ts

+2
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,8 @@ export interface Environment {
3535

3636
export interface UserConsoleLog {
3737
content: string
38+
origin?: string
39+
browser?: boolean
3840
type: 'stdout' | 'stderr'
3941
taskId?: string
4042
time: number

‎test/browser/specs/runner.test.ts

+32-5
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import { beforeAll, describe, expect, onTestFailed, test } from 'vitest'
2-
import { runBrowserTests } from './utils'
2+
import { browser, runBrowserTests } from './utils'
33

44
describe('running browser tests', async () => {
55
let stderr: string
@@ -45,8 +45,6 @@ describe('running browser tests', async () => {
4545
expect(stdout).toContain('hello from console.debug')
4646
expect(stdout).toContain('{ hello: \'from dir\' }')
4747
expect(stdout).toContain('{ hello: \'from dirxml\' }')
48-
// safari logs the stack files with @https://...
49-
expect(stdout).toMatch(/hello from console.trace\s+(\w+|@)/)
5048
expect(stdout).toContain('dom <div />')
5149
expect(stdout).toContain('default: 1')
5250
expect(stdout).toContain('default: 2')
@@ -64,10 +62,39 @@ describe('running browser tests', async () => {
6462
expect(stderr).toContain('hello from console.warn')
6563
expect(stderr).toContain('Timer "invalid timeLog" does not exist')
6664
expect(stderr).toContain('Timer "invalid timeEnd" does not exist')
65+
// safari logs the stack files with @https://...
66+
expect(stderr).toMatch(/hello from console.trace\s+(\w+|@)/)
67+
})
68+
69+
test.runIf(browser !== 'webkit')(`logs have stack traces in non-safari`, () => {
70+
expect(stdout).toMatch(`
71+
log with a stack
72+
❯ test/logs.test.ts:58:10
73+
`.trim())
74+
expect(stderr).toMatch(`
75+
error with a stack
76+
❯ test/logs.test.ts:59:10
77+
`.trim())
78+
// console.trace doens't add additional stack trace
79+
expect(stderr).not.toMatch('test/logs.test.ts:60:10')
80+
})
81+
82+
test.runIf(browser === 'webkit')(`logs have stack traces in safari`, () => {
83+
// safari print stack trace in a different place
84+
expect(stdout).toMatch(`
85+
log with a stack
86+
❯ test/logs.test.ts:58:14
87+
`.trim())
88+
expect(stderr).toMatch(`
89+
error with a stack
90+
❯ test/logs.test.ts:59:16
91+
`.trim())
92+
// console.trace doens't add additional stack trace
93+
expect(stderr).not.toMatch('test/logs.test.ts:60:16')
6794
})
6895

69-
test('stack trace points to correct file in every browser', () => {
70-
// dependeing on the browser it references either '.toBe()' or 'expect()'
96+
test(`stack trace points to correct file in every browser`, () => {
97+
// dependeing on the browser it references either `.toBe()` or `expect()`
7198
expect(stderr).toMatch(/test\/failing.test.ts:4:(12|17)/)
7299
})
73100

‎test/browser/specs/utils.ts

+2-2
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@ import { readFile } from 'node:fs/promises'
22
import type { UserConfig } from 'vitest'
33
import { runVitest } from '../../test-utils'
44

5-
const browser = process.env.BROWSER || (process.env.PROVIDER !== 'playwright' ? 'chromium' : 'chrome')
5+
export const browser = process.env.BROWSER || (process.env.PROVIDER !== 'playwright' ? 'chromium' : 'chrome')
66

77
export async function runBrowserTests(config?: Omit<UserConfig, 'browser'> & { browser?: Partial<UserConfig['browser']> }, include?: string[]) {
88
const result = await runVitest({
@@ -24,5 +24,5 @@ export async function runBrowserTests(config?: Omit<UserConfig, 'browser'> & { b
2424
const passedTests = getPassed(browserResultJson.testResults)
2525
const failedTests = getFailed(browserResultJson.testResults)
2626

27-
return { ...result, browserResultJson, passedTests, failedTests }
27+
return { ...result, browserResultJson, passedTests, failedTests, browser }
2828
}

‎test/browser/test/logs.test.ts

+8-1
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/* eslint-disable no-console */
2-
import { test } from 'vitest'
2+
import { test, vi } from 'vitest'
33

44
test('logging to stdout', () => {
55
console.log('hello from console.log')
@@ -52,3 +52,10 @@ test('logging invalid time', () => {
5252
console.timeLog('invalid timeLog')
5353
console.timeEnd('invalid timeEnd')
5454
})
55+
56+
test('logging the stack', () => {
57+
vi.setConfig({ printConsoleTrace: true })
58+
console.log('log with a stack')
59+
console.error('error with a stack')
60+
console.trace('trace with a stack')
61+
})

‎test/browser/vitest.config.mts

+3
Original file line numberDiff line numberDiff line change
@@ -86,5 +86,8 @@ export default defineConfig({
8686
onServerRestart: noop,
8787
onUserConsoleLog: noop,
8888
}, 'default'],
89+
env: {
90+
BROWSER: browser,
91+
},
8992
},
9093
})

‎test/cli/fixtures/console/trace.test.ts

+12
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,12 @@
1+
import { test } from 'vitest';
2+
3+
test('logging to stdout', () => {
4+
console.log('log with trace')
5+
console.info('info with trace')
6+
console.debug('debug with trace')
7+
console.dir({ hello: 'from dir with trace' })
8+
console.warn('warn with trace')
9+
console.assert(false, 'assert with trace')
10+
console.error('error with trace')
11+
console.trace('trace with trace')
12+
})

0 commit comments

Comments
 (0)