Skip to content

Commit 6275654

Browse files
Copilothi-ogawasheremet-va
authored
fix: fix mixed stdout/stderr log timestamps in onUserConsoleLog (#10308)
Co-authored-by: copilot-swe-agent[bot] <[email protected]> Co-authored-by: hi-ogawa <[email protected]> Co-authored-by: Hiroshi Ogawa <[email protected]> Co-authored-by: Vladimir <[email protected]>
1 parent fe5ed6b commit 6275654

3 files changed

Lines changed: 78 additions & 16 deletions

File tree

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

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -139,7 +139,7 @@ export function createCustomConsole(defaultState?: WorkerGlobalState): Console {
139139
else {
140140
timer = {
141141
stdoutTime: RealDate.now(),
142-
stderrTime: RealDate.now(),
142+
stderrTime: 0,
143143
}
144144
timers.set(id, timer)
145145
}
@@ -178,7 +178,7 @@ export function createCustomConsole(defaultState?: WorkerGlobalState): Console {
178178
else {
179179
timer = {
180180
stderrTime: RealDate.now(),
181-
stdoutTime: RealDate.now(),
181+
stdoutTime: 0,
182182
}
183183
timers.set(id, timer)
184184
}

‎test/e2e/fixtures/reporters/console-batch/basic.test.ts‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
import { it } from 'vitest'
2+
3+
it('batch microtask', async () => {
4+
console.log('1')
5+
await new Promise(resolve => setTimeout(resolve, 100))
6+
console.log('2')
7+
const now = Date.now()
8+
while (Date.now() < now + 50) {}
9+
console.error('3') // this gets own entry with timestamp after `2`
10+
console.log('4') // this is batched to the same stdout log as `2`
11+
})

‎test/e2e/test/reporters/console.test.ts‎

Lines changed: 65 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -77,18 +77,69 @@ test.for(['forks', 'threads'])('interleave (pool = %s)', async (pool) => {
7777
],
7878
}, [resolve('./fixtures/reporters/console-interleave.test.ts')])
7979
expect(stderr).toBe('')
80-
expect(logs).toMatchObject([
81-
{
82-
type: 'stdout',
83-
content: expect.stringContaining('1'),
84-
},
85-
{
86-
type: 'stderr',
87-
content: expect.stringContaining('2'),
88-
},
89-
{
90-
type: 'stdout',
91-
content: expect.stringContaining('3'),
92-
},
93-
])
80+
const formatted = logs.map((log, i) =>
81+
({
82+
type: log.type,
83+
content: log.content.trim(),
84+
timeSign: i > 0 ? Math.sign(log.time - logs[i - 1].time) : undefined,
85+
}))
86+
expect(formatted).toMatchInlineSnapshot(`
87+
[
88+
{
89+
"content": "1",
90+
"timeSign": undefined,
91+
"type": "stdout",
92+
},
93+
{
94+
"content": "2",
95+
"timeSign": 1,
96+
"type": "stderr",
97+
},
98+
{
99+
"content": "3",
100+
"timeSign": 1,
101+
"type": "stdout",
102+
},
103+
]
104+
`)
105+
})
106+
107+
test('console batching', async () => {
108+
const logs: UserConsoleLog[] = []
109+
const { stderr } = await runVitest({
110+
root: './fixtures/reporters/console-batch',
111+
reporters: [
112+
{
113+
onUserConsoleLog(log) {
114+
logs.push(log)
115+
},
116+
} satisfies Reporter,
117+
],
118+
})
119+
expect(stderr).toBe('')
120+
const formatted = logs.map((log, i) =>
121+
({
122+
type: log.type,
123+
content: log.content.replace(/\n/g, '_'),
124+
timeSign: i > 0 ? Math.sign(log.time - logs[i - 1].time) : undefined,
125+
}))
126+
expect(formatted).toMatchInlineSnapshot(`
127+
[
128+
{
129+
"content": "1_",
130+
"timeSign": undefined,
131+
"type": "stdout",
132+
},
133+
{
134+
"content": "2_4_",
135+
"timeSign": 1,
136+
"type": "stdout",
137+
},
138+
{
139+
"content": "3_",
140+
"timeSign": 1,
141+
"type": "stderr",
142+
},
143+
]
144+
`)
94145
})

0 commit comments

Comments
 (0)