Jest: Image comparison is extremely slow when running in a Jest environment

[theblang]

I'm using Jest with jest-image-snapshot to create and diff image screenshots taken with puppeteer. When running a simple test the image comparison causes the test to take close to thirty seconds. I also wrote a Jest test without jest-image-snapshot that instead uses Resemble for the image comparison and it takes about ten seconds; running the same screenshot and comparison outside of Jest in a script only takes 3-4 seconds. Something seems to be causing a heavily degraded performance for at least the task of comparing image data in Jest. I initially created this issue on the jest-image-snapshot repo, but after realizing that the same degradation occurs when using a different image comparison library a suggestion was made to create a ticket here.

OS: macOS High Sierra 10.13.1
Jest: 21.2.1
Node: 8.9.1
NPM: 5.5.1

Here is a repo to reproduce the issue.

[SimenB]

If I remove the assertion, your repro passes in 3-5 seconds for me. I don't think this is jest's fault

[thymikee]

Have you tried to profile this and identify where it gets slow?

[theblang]

@SimenB @thymikee I've made some tweaks to my test repo that illustrate something weird is going on with Jest. I took the jest-image-snapshot matcher out of the equation entirely. I have a Jest test that does the screenshot comparison only and takes around six seconds. In that same test I have a block of code that can be uncommented to write the diff of the screenshot comparison to a file, and that is where it gets really slow. The exact code that seems to be the culprit is:

const PNG = require('pngjs').PNG;
const diff = new PNG({width: 1100,height: 2400});
// ... do comparison
diff.pack().pipe(fs.createWriteStream("__pixelmatch__/diff.png"))

For good measure I also wrote a script using only Node that does the screenshot comparison and writes the diff to a file; it only takes about four seconds. So the slowdown seems to be writing a file within the Jest context.

[theblang]

Interesting! It seems as though pngjs is the culprit, though only in the Jest context (since the same code in a node script runs in about four seconds). That paethPredictor function and all the filter functions are from pngjs.

[cpojer]

I'll close this because it is unlikely that there is a bug in Jest based on the conversation but please keep discussing here to resolve your issue if you like.

[theblang]

@cpojer I know that I mentioned pngjs seems to be the culprit of the slowdown when looking at the CPU profile that I linked earlier, but the slowdown only happens when running in Jest. The exact same code runs in a regular node script in about four seconds, while taking about twenty-five seconds to run in a Jest test. This makes me think the issue should not necessarily be closed?

[theblang]

@cpojer I feel like I have some further evidence that Jest is doing something weird here and that maybe the ticket should not be closed. If you see the console timings after the Jest test runs they are about the same as when running the exact same code in just a Node script. But it seems as though Jest is just not finishing the test for another twenty seconds.

[cpojer]

I'm happy to reopen and appreciate your investigation. It would be awesome if you could find the root cause and propose a PR to fix it for everyone :)

[theblang]

@cpojer If you get a moment could you take a peak at the for loop here that is wrapped inside of two debugger statements. You'll see that the code calls those filter* functions at the top of the file a bunch of times (for each line of the PNG I believe). The filter functions seem to be doing a lot of math operations. Each iteration of that for loop is taking ~7 - 8ms when run in Jest, as apposed to ~0.2ms when run in a vanilla Node script. That is definitely the source of the slowdown and I'm hoping that maybe someone more knowledgable about Jest might help give me a clue as to what might be going on. (cc: @anescobar1991 )

[cpojer]

Fascinating. This might be a case of the vm module deopting code. Could you possibly make a repro without Jest, of running this code in a vm context (see https://nodejs.org/api/vm.html ) and outside and displaying the performance difference? We can then ask the node.js folks to take a look.

Meanwhile, I encourage you to build a custom test environment in Jest that pulls in this module in the parent context, which will probably be faster (assuming my intuition is correct that the code is deoptimized because of the vm module).

[theblang]

@cpojer So something like this? It takes about the same amount of time as the Node script, so assuming I did it correctly I think we can rule out vm.

[cpojer]

Ok, that's really odd then :( I'm not sure right now what is causing the issue.

[theblang]

I made a new issue after isolating the slowdown to just a call to Math. You can follow the new list of instructions here to reproduce the issue. Calling Math.abs ten million times takes about 2000ms in Jest, compared to about 10ms in Node or Jasmine.

I'm going to close this ticket in favor of the aforementioned new one.