Very poor performance on basic tests

[cozmy]

🐛 Bug Report

I've created a simple test with no configuration. You can find it here. It takes 7.6 seconds just to start jest, and then, on file change, it takes 5 seconds to re-run.
There's clearly something wrong here.

Mocha and Chai, for example, start in around 4 seconds, but afterward, the re-run is almost instant.

It's weird that Jest reports that the test takes 14ms but shows me the result in 5 seconds.

On top of this, if you add more basic tests, the time just seems to go up.

To Reproduce

Clone my minimal repository, yarn install and yarn test.

Expected behavior

It should be faster than this.

Link to repl or repo (highly encouraged)

https://github.com/cozmy/jest-performance

Run npx envinfo --preset jest

Paste the results here:

  System:
    OS: Windows 10
    CPU: (8) x64 Intel(R) Core(TM) i7-4700MQ CPU @ 2.40GHz
  Binaries:
    Node: 8.12.0 - C:\Program Files\nodejs\node.EXE
    Yarn: 1.13.0 - C:\Users\CosminCristian\AppData\Roaming\npm\yarn.CMD
    npm: 6.8.0 - C:\Program Files\nodejs\npm.CMD

[jeysal]

Your repo takes way less time for me:
4ms test case
0.7s according to jest
1.4s according to time
Reruns are pretty much instant.

On Windows, startup performance (of any Node process and especially if you do a lot of IO) will always be noticeably slower. You can try upgrading the Node version to 10 or 11 (8 is quite old), I'd expect a 10-20% speedup coming from that.
I'd try to profile the performance issue a bit, but I can't reproduce the terrible performance on my systems :/

[gsteacy]

Test: 8-10ms
Total: 2.4-2.8s

Reruns are very erratic if the rerun was triggered by a file change:

Test: 2-14ms
Total: 0.8-3.3s (typically on the upper end though, <2.5s is uncommon).

If it was triggered manually then it is pretty consistent with the first run. Interestingly, if I run with --no-cache then the first run is similar, but reruns on file changes are 0.8-0.9s and manual reruns are <0.2s. I think this might be because it throws away the timings of each run and causes Jest to run in-band (no extra workers). I usually run in-band on Windows because it's nearly always the fastest option, at least in watch mode. In WSL the performance is not quite as bad (though well short of native Linux) so I typically let Jest do whatever it wants.

As a side note, my runs seems to have been quite a bit faster than yours despite this machine having pretty dated hardware. That's pretty strange in itself.

  System:
    OS: Windows 8.1
    CPU: x64 Intel(R) Core(TM) i7 CPU         920  @ 2.67GHz
  Binaries:
    Node: 8.11.3
    Yarn: 1.7.0
    npm: 5.6.0
  npmPackages:
    jest:
      wanted: ^24.1.0
      installed: 24.1.0

[cozmy]

To give you a bit of background, I was trying to set up the test environment on my work laptop and I noticed that my React tests were way to slow. That's when I've discovered the poor performance. I've also tested this on Linux and it's 2x as fast, but still, 3seconds on re-run for some basic tests it's too much.

It's weird that Jest reports that a test runs in 10ms but the reported time is 5seconds.

Even on my work laptop, running the tests on create-react-app are slow, on re-run:

I guess this issue is a duplicate of #7619 and #6694 so most likely it can be closed.

[fabiosantoscode]

Mocha doesn't take 4 seconds to initialise in this case. I changed your test to do require('assert').equal(1, 112) and it took less than 200ms:

fabio@fabio-thinkpad ♥  time mocha index.spec.js 


  jest performance
    1) should be fast


  0 passing (6ms)
  1 failing

  1) jest performance
       should be fast:

      AssertionError [ERR_ASSERTION]: 1 == 112
      + expected - actual

      -1
      +112
      
      at Context.<anonymous> (index.spec.js:3:23)




real    0m0.173s
user    0m0.153s
sys     0m0.024s

Which by the way, if you add another test it doesn't take 173ms * 2 to run.

I've never seen a testing framework that takes more than 500ms to perform a single equality check. There must be some configuration option we can set here, and if there is, I would like to make the case for it to be in the defaults.

[fabiosantoscode]

Just copied the original test 50 times to make sure. Results:

real    0m0.193s
user    0m0.157s
sys     0m0.040s

[natealcedo]

Tests run fine for me.

[jeysal]

I tried this out on my Mac and got run times of 3-4s, so a bit closer to what you are describing. There is nothing that takes way longer than expected in the profile though, as I said it's just that IO performance is very OS-dependent, most of this is require loading modules:

One thing caught my eye in the flame chart though

Setting up a JSDOM environment is very expensive (the middle part of the chart). Setting testEnvironment to node if the tests don't need it cut the test time in half for me. I find it a bit unfortunate that the default is jsdom. @SimenB has there been any discussion on the default testEnvironment?

[jeysal]

Also, I noticed that watch mode is not running inBand, which I think it should in this case. After setting the test environment to node and passing --watchAll --runInBand reruns are pretty much instant. I'll try to find out by Jest doesn't decide to runInBand automatically in this case.

[SimenB]

@SimenB has there been any discussion on the default testEnvironment?

Yes, #5815. If you use jest --init, it defaults to node as well. I'd forgotten #5815 was accepted, would be nice to get done for 25.

[jeysal]

After some investigation, the reason why Jest does not run the test inBand is the following:

• On the first run, we do not know whether the one test will be fast, so we decide not to runInBand in order to keep the main thread unblocked and make sure the TTY remains responsive
• Because this first run is not inBand, the overhead causes it to take about 2.2s on my device (even without JSDOM)
• On rerun, Jest sees that the test took longer than 1s (the current SLOW_TEST_TIME threshold), so it again decides not to runInBand
• You will never get out of this until you force runInBand once (and do one rerun, because the first runInBand execution also has to load everything which is slow), which causes the test time to go down to <100ms

I don't have a good solution to this other than making the threshold more generous right now

[SimenB]

Because this first run is not inBand, the overhead causes it to take about 2.2s on my device (even without JSDOM)

Can you test with node worker threads? Still some overhead, but maybe not so much

[jeysal]

@SimenB no noticeable change. jasmine2() has 1.5s total time when it initially requires all the modules, it's not really the worker overhead itself. In band the modules will be loaded after the first run so subsequent runs are almost instant.

[jeysal]

(jest-circus is not significantly faster to load either)

[jeysal]

There's no mechanism in place to reuse workers across watch runs, is there? Would it be unsafe to do so in case there is some kind of leftover state in the worker?