Snapshot comparison failing but results look identical

[robross0606]

🐛 Bug Report

A unit test is failing in one environment but not others. The output is very unhelpful because the serialized results look identical.

To Reproduce

Created a unit tests against captured console output using toMatchSnapshot().

    expect(getLog().log).toMatchSnapshot()

The results of running this test look like this:

[2020-04-22T17:27:08.927Z] FAIL src/__tests__/logger.test.js
[2020-04-22T17:27:08.927Z]   ● Console logging › Logs error level and above.
[2020-04-22T17:27:08.927Z]
[2020-04-22T17:27:08.927Z]     expect(received).toMatchSnapshot()
[2020-04-22T17:27:08.927Z]
[2020-04-22T17:27:08.927Z]     Snapshot name: `Console logging Logs error level and above. 1`
[2020-04-22T17:27:08.927Z]
[2020-04-22T17:27:08.927Z]     Snapshot: "[error]: Testing simple message at error level... "
[2020-04-22T17:27:08.927Z]     Received: "[error]: Testing simple message at error level... "

From this result I cannot fathom what is wrong with the matcher. As far as I know, this is not a custom matcher. .log is declared as a TS string type.

As of right now I have no idea how to reproduce since the error has given me no indication of what is not matching.

Expected behavior

Output either matches and succeeds or provides a clear indication of how the matcher failed.

Link to repl or repo (highly encouraged)

No way to reproduce outside environment at the moment. No idea what is wrong because the error message is completely opaque.

envinfo

[2020-04-22T18:10:43.171Z] + npx envinfo --preset jest
[2020-04-22T18:10:44.515Z] npx: installed 1 in 1.119s
[2020-04-22T18:10:44.765Z] 
[2020-04-22T18:10:44.765Z]   System:
[2020-04-22T18:10:44.765Z]     OS: Linux 4.14 Alpine Linux
[2020-04-22T18:10:44.765Z]     CPU: (2) x64 Intel(R) Xeon(R) CPU E5-2676 v3 @ 2.40GHz
[2020-04-22T18:10:44.765Z]   Binaries:
[2020-04-22T18:10:44.765Z]     Node: 12.16.2 - /usr/local/bin/node
[2020-04-22T18:10:44.765Z]     Yarn: 1.22.4 - /usr/local/bin/yarn
[2020-04-22T18:10:44.765Z]     npm: 6.14.4 - /usr/local/bin/npm
[2020-04-22T18:10:44.765Z]   npmPackages:
[2020-04-22T18:10:44.765Z]     jest: ^25.4.0 => 25.4.0 
[2020-04-22T18:10:44.765Z]

[SimenB]

Related to #9863?

[robross0606]

Related to #9863?

Possibly. It is very hard for me to tell because this is only failing on our Jenkins server. Running locally does not cause the problem. This could be because the code generating the console output is different on different OS and my local environment is different than the deployed environment.

[SimenB]

You can try running with NO_COLOR=1 or CI=true or some such

[robross0606]

Already doing that. There is no color in the output. Color is disabled on all tests.

[robross0606]

I finally just created a separate entire test environment on Linux to match the Jenkins as best I could and was able to reproduce the problem.

For some reason, on Windows my generated snapshot looks like this:

// Jest Snapshot v1, https://goo.gl/fbAQLP

exports[`Health Check API Returns not healthy from when ArangoDB is down 1`] = `
"[error]: Health check failed: Expected mock failure. "
`;

but on Linux it looks like this:

// Jest Snapshot v1, https://goo.gl/fbAQLP

exports[`Health Check API Returns not healthy from when ArangoDB is down 1`] = `"[error]: Health check failed: Expected mock failure. "`;

Why is Jest adding extra carriage returns outside the string value on Windows? And why should that matter at all for the snapshot comparison?

[robross0606]

This turned out to be caused by Winston logger using os.EOL as the default for newlines. In this case, capturing and comparing snapshots on console output was failing due to an extra \r in the output that doesn't show up on the error diff coming from Jest. Recommend an option to allow those diff messages to show escape codes. This was VERY hard to track down due to Jest output hiding control characters.

[SimenB]

We discussed this some in #6881, but no obvious solution was found at the time. Seeing as that issue is closed, do you wanna open up a feature request with it?

[robross0606]

I dunno how to approach this really. I was simply pointing out that this does have real-world consequences because I just spent 3 days debugging to find this as the root cause.

I'm actually a fan on unifying on \n across the board. Windows drives me nuts with stuff like this. But then os.EOL was introduced which looks like Node.js is waffling on approach. So then you get very popular libraries like Winston using it as the default for console output.

One possibility would be to create a console.EOL constant to be more explicit that console output should always use \n.

[SimenB]

I don't think Jest should normalize this into lf, But I'd definitely merge a PR copying concordance in swapping them for specific crlf, cr and lf characters in the visualization during diffing 🙂 You wouldn't be interested in working on this?

https://github.com/concordancejs/concordance/blob/1638c0915d5df9595be533cd7d060f96727245c5/lib/primitiveValues/string.js#L30-L41

Place in Jest would be somewhere inside jest-diff, I guess, although I haven't dug into it

[robross0606]

Agreed I don't think Jest should address this at all except for potentially offering a more revealing result from a diff:

  ● EOL handling

    expect(received).toEqual(expected) // deep equality

    Expected: "This is a logging entry with EOL.\r\n"
    Received: "This is a logging entry with EOL.\n"

[SimenB]

Yeah exactly, that's what concordance does