Jest is using stderr as output

[easingthemes]

Do you want to request a feature or report a bug?

bug

What is the current behavior?

jest output is using stderr.

If the current behavior is a bug, please provide the steps to reproduce and
either a repl.it demo through https://repl.it/languages/jest or a minimal
repository on GitHub that we can yarn install and yarn test.

This repo (https://github.com/easingthemes/jest-output) has task.js file which uses nodejs spawn to run npm test (jest) and print output by type.

command:

node ./task.js

Output:

> jest

stderr: PASS ./add.test.js
stderr:   add
stderr:     ✓ should add two numbers (3ms)
stderr:

stderr: Test Suites: 1 passed, 1 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        0.582s, estimated 1s
Ran all test suites.

What is the expected behavior?

Not using stderr for output, use stdout instead.

Please provide your exact Jest configuration and mention your Jest, node,
yarn/npm version and operating system.

node: v8.1.2
npm: 5.0.3
jest: ^21.2.1
MacOS 10.12.6

Related:
#4384

Right output type is important when using some other tools, eg. Jenkins / Maven. Because process is marked as failed due this error.

[milesj]

Running into this as well. Am not using the --useStderr option.

[benhysell]

I'm running into this issue using Visual Studio Online Build using a Windows host. If I switch to use a Linux host everything works as expected.

Example Scripts and output below from both hosts:

From the Windows host, using PowerShell:
Script:
($env:CI = $true) -and (npm test)

Output:

---

Starting: PowerShell Script

---

Task : PowerShell
Description : Run a PowerShell script
Version : 1.2.3
Author : Microsoft Corporation
Help : More Information
. 'C:\agent_work\32\s\visualStudioOnlineBuildTestPowerShell.ps1'
PASS src_tests_\releaseTools\user\userListStore.reducer.spec.ts
True
Process completed with exit code 0 and had 1 error(s) written to the error stream.

---

Finishing: PowerShell Script

---

From the Linux host using bash:
Script:
CI=true npm test

Output:

---

Starting: Shell Script visualStudioOnlineBuildTest.sh

---

Task : Shell Script
Description : Run a shell script using bash
Version : 2.1.3
Author : Microsoft Corporation
Help : More Information
/bin/bash /opt/vsts/work/1/s/visualStudioOnlineBuildTest.sh

react-scripts-ts test --env=jsdom
PASS src/tests/releaseTools/user/userListStore.reducer.spec.ts
PASS src/tests/releaseTools/user/userList.spec.tsx
PASS src/tests/releaseTools/user/userListStore.actions.spec.ts
Test Suites: 3 passed, 3 total
Tests: 11 passed, 11 total
Snapshots: 1 passed, 1 total
Time: 5.298s
Ran all test suites.

---

Finishing: Shell Script visualStudioOnlineBuildTest.sh

---

[benhysell]

In case anyone else runs into this...the problem is with Microsoft and how they implement the PowerShell task for Visual Studio Online Build.

See - https://developercommunity.visualstudio.com/content/problem/84878/vsts-build-fails-with-process-completed-with-exit.html

Solution for me, change my PowerShell script to:
($env:CI = $true) -and (npm test 2>&1 | Write-Host )

[milesj]

I've also noticed that NODE_ENV is not "test" when running through a child process. Not sure if related or not.

[stormherz]

Having the same issue - I'm wrapping Jest invokation in PHP Symfony process, no additional flags for jest is used - output is in stderr

[acommend]

Experiencing the same issue using frontend-maven-plugin when executing npm run unit. Not using --useStderr option. Maven output is

[INFO] --- frontend-maven-plugin:1.6:npm (npm run unit) @ frontend ---
[INFO] Running 'npm run unit' in C:\eclipse_workspace\web\frontend
[INFO]
[INFO] > frontend@1.0.0 unit C:\eclipse_workspace\web\frontend
[INFO] > jest --config test/unit/jest.conf.js --coverage
[INFO]
[ERROR] PASS test\unit\specs\System.spec.js
[ERROR]   System
[ERROR]     â?? test1 (14ms)
[ERROR]     â?? test2 (15ms)
[ERROR]     â?? test3 (32ms)
[ERROR]     â?? test4 (31ms)
[ERROR]     â?? test5 (31ms)
[ERROR]
[ERROR] Test Suites: 1 passed, 1 total
[ERROR] Tests:       5 passed, 5 total
[ERROR] Snapshots:   0 total
[ERROR] Time:        1.774s, estimated 2s
[ERROR] Ran all test suites.

"frontend-maven-plugin takes all output from stderr and forwards it as ERROR logs, and all output from stdout forwarded as INFO logs." - eirslett/frontend-maven-plugin#584.

Maven pom snippet:

<build>
    <plugins>
      <plugin>
        <groupId>com.github.eirslett</groupId>
        <artifactId>frontend-maven-plugin</artifactId>
        <version>1.6</version>
        <executions>
          <!-- Run unit tests -->
          <execution>
            <phase>test</phase>
            <id>npm run unit</id>
            <goals>
              <goal>npm</goal>
            </goals>
            <configuration>
              <skip>${maven.test.skip}</skip>
              <arguments>run unit</arguments>
              <environmentVariables>
      	        <CI>true</CI>
    	      </environmentVariables>
            </configuration>
          </execution>
        </executions>
      </plugin>
    </plugins>
</build>

[SimenB]

PR: #6583

[leonardovilarinho]

With the same problem. Hopefully the PR will be approved soon, this will hinder some CI platforms.

[chrisgalvan]

Is there any progress on this, bumped into this issue today with our CI (teamcity) treats stderr as an error even when the tests pass.

[cedosw]

Same problem ... would be nice if PR gets approved soon

[chrisgalvan]

tried to help with the PR, but there are tons of e2e integration tests failing.

For the time being, I created a reporter that uses stdout instead and published the package in case anybody can benefit from it: https://github.com/chrisgalvan/jest-standard-reporter

[tom-mckinney]

Have there been any updates on this? Jest is currently very noisy in our CI pipeline because of this bug.

[ByronBecker]

It seems someone has made a package to address this issue => https://github.com/chrisgalvan/jest-standard-reporter

[waldyrious]

It seems someone has made a package to address this issue => chrisgalvan/jest-standard-reporter

Yes, the author of that package himself announced it on this thread already (literally two comments above yours! 😄)

[lucasfcosta]

@SimenB I was working on this and managed to get it working as per our discussion on #6583.

However, there's one major issue preventing me from completing this piece of work. I'd like to ask you and the team for guidance on what's the desired behaviour for coverage reports so that I know how to proceed.

Currently, in the tests for coverage reports, the snapshots contain only the coverage reports themselves since they are written to stdout.

Now, with reporters writing to stdout, we will have entries for the passing tests mixed with the coverage reports themselves. Having these entries make tests non-deterministic, because, even if I sort them using extractSortedSummary, the coverage report will be written to stdout as soon as it is generated and therefore test entries may appear either after or before, depending on when they're complete, as you can see here, for example:

This prevents me from generating any meaningful snapshots since it's not possible to determine the order in which they are going to finish.

I have a few ideas on how to proceed, but I'd like to ask the maintainers what they think would be the most viable solution:

1. Strip all of the PASS/FAIL/RUNS entries and check coverage reports only
   The problem with this is now that we don't know whether the actual output is correct because I don't know if it's desirable to get the coverage report mixed with the test result entries. This may annoy users since currently only the coverage itself gets printed to stdout.
2. Make sure that the coverage is always reported at the end of the run so that we can extract a sorted summary and compare all of it.

I'd go for the first option since currently we already output the test result entries anyway (but on different streams). This may annoy users who rely on it being output to stdout in order to pipe it somewhere, but I don't think this is the actual correct behaviour.

Do you agree?

[jeysal]

@lucasfcosta Do I understand correctly that at the moment coverage output on stdout and reporter output on stderr can already be interleaved? If so, I agree that 1 would only make it slightly worse (unless you redirect one of the streams like a typical console run it doesn't change anything, but ofc 2 would still be the proper fix if you wanna invest the time). But I must say that I've never seen PASS/FAIL appearing below coverage so I'm wondering why it happened in your test...

[lucasfcosta]

Hi @jeysal,

Sorry, I should've been clearer in my explanation. I was also a bit confused before actually digging deeper into the issue. I'm sorry about that. Let me explain in more detail:

Currently, the reason why the coverage doesn't get mixed up with the entries is that we do print to separate streams which have separate flushing behaviour in different reporters. Since the VerboseReporter gets written to stdout and since it inherits from DefaultReporter, its flushing will be debounced rather than happening instantly. If we make all the output be flushed instantly (as it currently happens since this issue makes everything be written to stderr) or if we use --useStderr, everything works fine.

This appears to have been a "lucky"/"useful" bug, thus why we never caught the coverage being interleaved into the tests.

Once you have all the output being instantly flushed (as would happen before due to jest using stderr anyway), the problem vanishes and we don't get reports interleaved with the coverage summary anymore. If you use useStderr the problem also vanishes because that makes the output be instantly flushed too.

I still have to dig deeper into this to find the proper fix and investigate the differences between the two reporters.

Even though the debouncing is not being used at all I'd rather fix it (even if it's a separate preliminary PR) than remove it altogether as just seems incorrect to me.

For the moment I'll focus on fixing the debouncedFlush just so that I can proceed with the PR. I might open a preliminary PR with this fix, even though it's not visible. Thank you very much for making it clear that it's not acceptable to have the coverage interleaved with tests.

I'll keep you up to date, sorry for the hassle (I tend to be long-winded as you might have noticed 😅 )

[Hurtak]

Sorry for stupid question, but how can I tell programmatically that tests failed, when I run them from CLI, if stderr is always nonempty and return code is always 0, no matter if tests fail or pass?

Edit:
Ok, so combination of jest --watchAll=false --ci --testFailureExitCode=1 does not work but
CI=true jest does and returns 1 error code. Is this intended behavior?

[vejandla]

I'm running into the same problem.

none of the following things worked for me.

cross-env CI=true npm run test

tried running tests with --coverage option,
tried running tests with --ci option (for jest-cli)

all tests are passing, but when running the task through PowerShell in Azure DevOps, it is always treating it as an error.

appreciate any help !!

[lucasfcosta]

Hello everyone, this is a very long piece of work. I have started working on it and put some considerable effort in. However, I don't think I'll manage to get back to it as I've got a few conferences scheduled until the end of the year.

I'd be happy to walk someone through what needs to be done though.

It's a small change to the main code-base, but one which requires many tests to be updated, including tooling around them.

I think I'd only be able to get this done by next year. I'll hopefully try to make some room for fixing my other PRs before that, but for this specific one I'm afraid will have to wait. I'm sorry for that.

[chrisgalvan]

Hey @vejandla please use jest-standard-reporter as a workaround
#5064 (comment)

[ylacaute]

npm run test > out 2>error # jest

• out file: contains info, warn and an error stack-trace
• error file: contains all passed test logs (100%)

Facebook. This... is huge 😂

[aesyondu]

My naive guess is this is where it needs to be changed
https://github.com/facebook/jest/blob/5d1e98beda19dcfff3f10557396098524efbb639/packages/jest-reporters/src/summary_reporter.ts#L70

However, when I think about it, when should it be output to stdout and stderr?

If all tests passed, I think we can all agree the summary should be outputted to stdout. However, if at least one, or all tests failed, should it still be output to stdout, or to stderr? Or should it be split between the two?

EDIT: Nvm, found it, it's here:
https://github.com/facebook/jest/blob/5d1e98beda19dcfff3f10557396098524efbb639/packages/jest-reporters/src/base_reporter.ts#L18

[chrisgalvan]

IMO should be split, only errors should be output to stderr, most CI and other tools use it to print differently (red console for example). If you are trying to see what tests failed, should be able to point to the one that failed not the entire suite.

[lukaw3d]

Here's how to simply customize this for yourself https://github.com/lukaw3d/jest-fixed-default-reporter#implementation

[MetaMmodern]

Hi there. Exeperiencing the same behaviour when running jest from nodejs exec tool and handling outputs with a callback.
Kinda sad that this issue is open since 2017((

P.S. (I know that I could just react to first comment in issue, I'e already done that).

[chrisgalvan]

Here's how to simply customize this for yourself https://github.com/lukaw3d/jest-fixed-default-reporter#implementation

that's clever @lukaw3d do you mind if I move your approach to jest-standard-reporter?

[lukaw3d]

that's clever @lukaw3d do you mind if I move your approach to jest-standard-reporter?

Sure!

[rodrigogs]

My ci pipeline is failing because of it :(

[keverw]

Pretty strange if no errors, it's using stderr.

I was writing a little script to automate multiple tests in my mono repo, and wanted an option that would repeat the jest output. My code wasn't checking stderr since was relying on the exitCode for the execa library. So puzzled, ended up trying stderr and it worked!

[Zaggermeister]

Running into the same issue on my end. Not blocking, but bad reporting since we created a hook to grab and appropriately log stderr output in our system.

This results in the below:

[github-actions]

This issue is stale because it has been open for 1 year with no activity. Remove stale label or comment or this will be closed in 30 days.

[kachkaev]

not stale

[Douglas0n]

Same problem in our ci pipeline when we started monitoring stderr: :

[taoliujun]

Luckily, I ran the jest command using nodejs and collected the reporter information in stderr and treated it as stdout.

[m4rc77]

Here a workaround (tested with node v20 and jest v29). This workaround is inspired by https://github.com/lukaw3d/jest-fixed-default-reporter#implementation but updated in order to use import instead of require.

File: StdoutSummaryReporter.js

import { SummaryReporter } from '@jest/reporters'

class FixedSummary extends SummaryReporter {

  _hasFailures = false;

  _write(string) {
    super._write(string)

    // little hack in order to detect if there was a failure
    // the _write method will only be called if there was a failure ... see line 183 in
    // ./node_modules/@jest/reporters/build/SummaryReporter.js
    this._hasFailures = true;
  }

  log (message) {
    if (this._hasFailures) {
      process.stderr.write(`${message}\n`)
    } else {
      process.stdout.write(`${message}\n`)
    }
  }

}
export default FixedSummary

File: StdoutReporter.js

import { DefaultReporter } from '@jest/reporters'

class Fixed extends DefaultReporter {

  log (message) {
    if (message.startsWith('FAIL ')) {
      process.stderr.write(`${message}\n`)
    } else {
      process.stdout.write(`${message}\n`)
    }
  }

}
export default Fixed

File: jest.conf.js

const jestConfig = {
  ...
  reporters: [
    './test/unit/StdoutReporter.js',
    ['./test/unit/StdoutSummaryReporter.js', {summaryThreshold: 1} ]
  ],
  ...
}