Log messages from pino logger not showing in test results

[djstrong]

Describe the bug

The same as #585
When using the vitest vscode extension, log messages from pino logger show up in outputs but not in specific test results.

Reproduction

https://github.com/anthonyma94/vitest-vscode-repro

Output

[INFO 1:59:09 PM] [v1.14.3] Vitest extension is activated because Vitest is installed or there is a Vite/Vitest config file in the workspace.
[INFO 1:59:09 PM] [API] Resolving configs: vitest.config.js
[INFO 1:59:09 PM] [API] Running Vitest v3.0.5 (vitest-vscode-repro/vitest.config.js) with "node /home/kwrobel/.cursor/extensions/vitest.explorer-1.14.3/dist/worker.js"
[INFO 1:59:10 PM] [Worker] �[33mThe CJS build of Vite's Node API is deprecated. See https://vite.dev/guide/troubleshooting.html#vite-cjs-node-api-deprecated for more details.�[39m
[INFO 1:59:10 PM] [API] Watching vitest.config.js
[INFO 1:59:10 PM] [VSCODE] Watching vitest-vscode-repro with pattern **/*
[INFO 1:59:10 PM] [API] Collecting tests: test.spec.js
[1:59:10 PM] Not starting the runner because tests are being collected for test.spec.js
[1:59:11 PM] There is no test run for "test.spec.js"
[1:59:11 PM] No test run to finish for test.spec.js
[1:59:12 PM] [VSCODE] Ignoring file: node_modules/.vite
[1:59:12 PM] [VSCODE] Ignoring file: node_modules/.vite/results.json
[INFO 1:59:26 PM] Running 1 file(s): test.spec.js
[1:59:26 PM] Starting a test run because test.spec.js triggered a watch rerun event
[1:59:26 PM] Enqueuing "testing console"
[1:59:26 PM] No task result for "test.spec.js", ignoring
[1:59:26 PM] No task result for "test", ignoring
[1:59:26 PM] Enqueuing "testing console" because it was just collected
[INFO 1:59:26 PM] [Worker] {"level":30,"time":1740056366885,"pid":91613,"hostname":"kwrobel-Lenovo-Y520-15IKBN","msg":"hello world pino"}
[1:59:26 PM] No errors found for "test.spec.js"
[1:59:26 PM] No errors found for "test"
[1:59:26 PM] Marking "testing console" as passed
[1:59:26 PM] Ending test run test.spec.js
[1:59:26 PM] Test run promise is finished, the queue is 0
[1:59:27 PM] [VSCODE] Ignoring file: node_modules/.vite/results.json
[1:59:55 PM] [VSCODE] File changed: package.json
[1:59:55 PM] [VSCODE] File changed: package.json
[1:59:55 PM] [VSCODE] File changed: vitest.config.js
[1:59:55 PM] Disposing test runner
[1:59:55 PM] Ending test run <none>
[INFO 1:59:55 PM] [API] Vitest process 91556 closed successfully
[INFO 1:59:55 PM] [API] Resolving configs: vitest.config.js
[INFO 1:59:55 PM] [API] Running Vitest v3.0.5 (vitest-vscode-repro/vitest.config.js) with "node /home/kwrobel/.cursor/extensions/vitest.explorer-1.14.3/dist/worker.js"
[1:59:55 PM] [API] Vitest WebSocket connection closed, cannot call RPC anymore.
[INFO 1:59:56 PM] [API] Watching vitest.config.js
[INFO 1:59:56 PM] [VSCODE] Watching vitest-vscode-repro with pattern **/*
[INFO 1:59:56 PM] [API] Collecting tests: test.spec.js
[1:59:56 PM] Not starting the runner because tests are being collected for test.spec.js
[1:59:56 PM] There is no test run for "test.spec.js"
[1:59:56 PM] No test run to finish for test.spec.js
[1:59:56 PM] [VSCODE] Ignoring file: node_modules/.vite/results.json
[INFO 2:00:00 PM] Running 1 file(s): test.spec.js
[2:00:00 PM] Starting a test run because test.spec.js triggered a watch rerun event
[2:00:00 PM] Enqueuing "testing console"
[2:00:00 PM] No task result for "test.spec.js", ignoring
[2:00:00 PM] No task result for "test", ignoring
[2:00:00 PM] Enqueuing "testing console" because it was just collected
[INFO 2:00:00 PM] [Worker] {"level":30,"time":1740056400285,"pid":92026,"hostname":"kwrobel-Lenovo-Y520-15IKBN","msg":"hello world pino"}
[2:00:00 PM] No errors found for "test.spec.js"
[2:00:00 PM] No errors found for "test"
[2:00:00 PM] Marking "testing console" as passed
[2:00:00 PM] Ending test run test.spec.js
[2:00:00 PM] Test run promise is finished, the queue is 0
[2:00:00 PM] [VSCODE] Ignoring file: node_modules/.vite/results.json
[INFO 2:00:32 PM] Running 1 file(s): test.spec.js
[2:00:32 PM] Starting a test run because test.spec.js triggered a watch rerun event
[2:00:32 PM] Enqueuing "testing console"
[2:00:32 PM] No task result for "test.spec.js", ignoring
[2:00:32 PM] No task result for "test", ignoring
[2:00:32 PM] Enqueuing "testing console" because it was just collected
[INFO 2:00:32 PM] [Worker] {"level":30,"time":1740056432177,"pid":92032,"hostname":"kwrobel-Lenovo-Y520-15IKBN","msg":"hello world pino"}
[2:00:32 PM] No errors found for "test.spec.js"
[2:00:32 PM] No errors found for "test"
[2:00:32 PM] Marking "testing console" as passed
[2:00:32 PM] Ending test run test.spec.js
[2:00:32 PM] Test run promise is finished, the queue is 0
[2:00:32 PM] [VSCODE] Ignoring file: node_modules/.vite/results.json
[2:03:59 PM] [VSCODE] Ignoring file: .git/FETCH_HEAD
[2:03:59 PM] [VSCODE] Ignoring file: .git/FETCH_HEAD
[2:04:00 PM] [VSCODE] Ignoring file: test.spec.js.git
[2:04:00 PM] [VSCODE] Ignoring file: index.js.git
[2:04:00 PM] [VSCODE] Ignoring file: pnpm-lock.yaml.git
[2:04:00 PM] [VSCODE] Ignoring file: package.json.git
[2:04:00 PM] [VSCODE] Ignoring file: package-lock.json.git
[INFO 2:04:16 PM] Running 1 file(s): test.spec.js
[2:04:16 PM] Starting a test run because test.spec.js triggered a watch rerun event
[2:04:16 PM] Enqueuing "testing console"
[2:04:16 PM] No task result for "test.spec.js", ignoring
[2:04:16 PM] No task result for "test", ignoring
[2:04:16 PM] Enqueuing "testing console" because it was just collected
[INFO 2:04:16 PM] [Worker] {"level":30,"time":1740056656802,"pid":92033,"hostname":"kwrobel-Lenovo-Y520-15IKBN","msg":"hello world pino"}
[2:04:16 PM] No errors found for "test.spec.js"
[2:04:16 PM] No errors found for "test"
[2:04:16 PM] Marking "testing console" as passed
[2:04:16 PM] Ending test run test.spec.js
[2:04:16 PM] Test run promise is finished, the queue is 0
[2:04:16 PM] [VSCODE] Ignoring file: node_modules/.vite/results.json

Extension Version

1.14.3

Vitest Version

3.0.5

Validations

• Check that you are using the latest version of the extension
• Check that there isn't already an issue that reports the same bug to avoid creating a duplicate.
• Check that this is a concrete bug. For Q&A open a GitHub Discussion or join our Discord Chat Server.
• The provided reproduction is a minimal reproducible example of the bug.

[sheremet-va]

Works fine for me:

The log cannot be attributed to a test, obviously. So it is printed as part of the test run. Everything works as intended.

[sheremet-va]

The log cannot be attributed to a test, obviously

To clarify - pino prints to stdout directly, so Vitest cannot intercept it to attribute to a specific test. This is expected behavour.