jestjs / jest

Delightful JavaScript Testing.
https://jestjs.io
MIT License
44.23k stars 6.46k forks source link

Jest is using `stderr` as output #5064

Open easingthemes opened 6 years ago

easingthemes commented 6 years ago

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: https://github.com/facebook/jest/issues/4384

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

milesj commented 6 years ago

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

benhysell commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

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

stormherz commented 6 years ago

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 commented 6 years ago

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." - https://github.com/eirslett/frontend-maven-plugin/issues/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 commented 6 years ago

PR: #6583

leonardovilarinho commented 6 years ago

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

chrisgalvan commented 5 years ago

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 commented 5 years ago

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

chrisgalvan commented 5 years ago

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 commented 5 years ago

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

ByronBecker commented 5 years ago

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

waldyrious commented 5 years ago

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 commented 5 years ago

@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:

Screen Shot 2019-08-10 at 19 59 49

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 commented 5 years ago

@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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

Hey @vejandla please use jest-standard-reporter as a workaround https://github.com/facebook/jest/issues/5064#issuecomment-462817327

ylacaute commented 4 years ago
npm run test > out 2>error # jest

Facebook. This... is huge :joy:

aesyondu commented 4 years ago

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 commented 4 years ago

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 commented 3 years ago

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

MetaMmodern commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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

Sure!

rodrigogs commented 2 years ago

My ci pipeline is failing because of it :(

keverw commented 2 years ago

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 commented 2 years ago

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:

image
github-actions[bot] commented 1 year ago

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 commented 1 year ago

not stale

Douglas0n commented 1 year ago

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

image

taoliujun commented 10 months ago

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

m4rc77 commented 8 months ago

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} ]
  ],
  ...
}