when using debug to print to console, output is missing on reruns

[panick-carousel]

Describe the bug

I am using the debug tool with vitest and cannot reliably get output from this tool. It appears as tho when in watch mode, vitest clears the console and wipes any debug output under some circumstances.

the debug library writes to stderr rather than stdout, so perhaps the clearing code in vite should account for lines due to stderr somehow ?

Thank you kindly for vitest - it makes life so much better.

Reproduction

https://stackblitz.com/edit/vitest-dev-vitest-qiyvqq?file=test%2Fsuite.test.ts,package.json&initialPath=__vitest__

In terminal, press enter to trigger test reruns and observe the output to console from the debug() library.

Then start editing any file to trigger a test rerun, and observe the output to console from debug() is removed.

System Info

System:
    OS: Linux 5.17 Fedora Linux 36 (Server Edition)
    CPU: (16) x64 Intel(R) Xeon(R) E-2286M  CPU @ 2.40GHz
    Memory: 14.55 GB / 19.53 GB
    Container: Yes
    Shell: 5.1.16 - /bin/bash
  Binaries:
    Node: 18.6.0 - /run/user/1001/fnm_multishells/788267_1659397396823/bin/node
    Yarn: 1.22.19 - /run/user/1001/fnm_multishells/788267_1659397396823/bin/yarn
    npm: 8.13.2 - /run/user/1001/fnm_multishells/788267_1659397396823/bin/npm

Used Package Manager

yarn

Validations

• Follow our Code of Conduct
• Read the Contributing Guidelines.
• Read the docs.
• 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.

[panick-carousel]

I managed to make the logging from debug be more usable by writing to stdout instead of stderr: debug.log = console.log.bind(console) but even that still fails to display the output roughly 1 in 20 runs.

[jcalfee]

It may be related to length. By trading streams perhaps it is just giving it a little more time before it fills up again. #2671 (comment)

[inverted-capital]

Turns out, the issue is to do with the spinner used by the default test reporter. If the default test reporter is changed to 'dot' or any other one that doesn't have a spinner in it, the output is preserved with no issue.

https://vitest.dev/config/#reporters

[inverted-capital]

actually even 'dot' does some clearing of the terminal, so for #2671 when only a single character is being printed to stderr, it is only visible using a reporter than does not change any existing output on the terminal. Currently the 'tap' reporter is working for even a single character output.

[aleclarson]

Here's the workaround I'm using.

import createDebug from 'debug'

export let debug = createDebug('foo')

if (process.env.TEST && debug.enabled) {
  debug = console.log.bind(console) as any
  debug.enabled = true
}

[hi-ogawa]

This is because debug package directly writes to process.stderr by default https://github.com/debug-js/debug/blob/bc60914816e5e45a5fff1cd638410438fc317521/src/node.js#L194 while Vitest only captures global console logging.

I think this is working intended and it's necessary to override debug.log like suggested above for this case. Thanks people for sharing workaround 🙏

Just one more idea is that it looks like it's possible to overriding the default export directly from setup files. I'll leave a latest repro here https://stackblitz.com/edit/vitest-dev-vitest-mjacyu?file=test%2Fsetup.ts and let me close the issue as it's working intended.

import createDebug from 'debug';
createDebug.log = console.error.bind(console);

 DEV  v2.1.4 /home/projects/vitest-dev-vitest-mjacyu

stderr | test/basic.test.ts > foo
  repro meow1 +0ms
  repro meow2 +1ms

stderr | test/basic.test.ts > bar
  repro xxx +0ms

 ✓ test/basic.test.ts (2)
   ✓ foo
   ✓ bar

[AriPerkkio]

I see couple of issues here:

1. The forks pool is currently unable to pass direct process.stdout to Vitest. This will be fixed by fix(child_process): pipe stdout and stderr to main thread tinylibs/tinypool#104
2. Vitest's reporters using log-update are currently erasing all process.stdout writes. To users this makes the output flicker as it's conflicting with our "internal write buffer". There's on-going work on rewriting Vitest's test reporters that will solve this. We need to intercept global process.stdout and handle that properly in CLI output.

Using the createDebug.log = console.error.bind(console); work-around mentioned above looks like good solution for now.