jest 25 performance

[benmonro]

💥 Regression Report

we upgraded jest from 24 to 25 and saw our unit tests go from taking 5min 23sec in jenkins to now over 11 minutes. only a few snapshot tests broke in the upgrade, we -u'd them, but this is a severe regression imo. please help me understand how we can fix this. We clear cache in CI to ensure we always run the latest.

A clear and concise description of what the regression is.
run time went from 5:23, to 11:00

Last working version

24.8.0
Worked up to version:
24.8.0
Stopped working in version:
25.1.0

To Reproduce

sorry can't share our codebase
Steps to reproduce the behavior:

Expected behavior

A clear and concise description of what you expected to happen.

Link to repl or repo (highly encouraged)

Please provide either a repl.it demo or a minimal repository on GitHub.

Issues without a reproduction link are likely to stall.

Run npx envinfo --preset jest

Paste the results here:

  System:
    OS: macOS Mojave 10.14.6
    CPU: (12) x64 Intel(R) Core(TM) i9-8950HK CPU @ 2.90GHz
  Binaries:
    Node: 10.16.0 - ~/.nvm/versions/node/v10.16.0/bin/node
    Yarn: 1.19.0 - ~/.nvm/versions/node/v10.16.0/bin/yarn
    npm: 6.13.6 - ~/.nvm/versions/node/v10.16.0/bin/npm

[SimenB]

Sorry about the regression but

sorry can't share our codebase

means we can do absolutely nothing. This is the first I've heard of performance regressing, everywhere else I've heard from 10-40% improvement in performance going from 24 to 25. You need to provide some sort of reproduction, otherwise we'll have to close this issue as it's not actionable at all as it stands.

If you want to see this adressed, you'll need to spend some time putting together a reproduction case, or hope somebody else does so.

[benmonro]

ok i will see if i can pull our 10 slowest tests maybe, then try to run them in 24 vs 25. in the meantime, what do you recommend with regards to clearing cache before running tests in CI? do it? don't do it?

[SimenB]

Your configuration, especially transforms and setup files are probably relevant as well

what do you recommend with regards to clearing cache before running tests in CI

I personally think it's a good idea just to be sure there's nothing stale laying around giving false negative or positives. Does it make a huge difference to the runtime of your tests to not clear the cache?

[benmonro]

it appears to be quite a bit slower when run after clearing cache. thanks for the tips i'll look into it and see if i can attempt a repro

[milesj]

FWIW, I've also noticed that v25 is either slightly slower or right on par with v24. Have not seen anywhere near 10-40% improvement.

[csvan]

I saw a significant speedup over jest 24 as noted here: #7811 (comment)

The above was tested on osx.

However, the exact same setup runs much, much slower on our CI which runs CentOS.

Linux specific issue? I/O related issues when writing cache files? Is it possible to turn off cache generation altogether to rule this out?

[csvan]

I think I found the culprit in our case, it's the --collectCoverage flag. When it is removed for both Jest 24 and 25, our tests run roughly twice as fast under 25. When it is enabled, our tests under 25 are almost 4 times as slow as the same ones under 24.

This is reproducible both on OSX and CentOS, so contrary to my previous comment the issue does not appear Linux-specific.

[SimenB]

Interesting! We've updated Istanbul to v3, maybe something in there has regressed. We've added support for v8 code coverage, so I might also have messed up the refactoring when doing so

[benmonro]

Yes! That's consistent with what I'm seeing as well. We are running with coverage in CI where it's 2x slower. And when I run locally without covg is quite fast. @SimenB is there any config option to use the older Istanbul? :)

[benmonro]

Echoing what @csvan said it would be nice to turn off cache generation in CI if that is in fact a culprit since we delete it prior to building anyway

[SimenB]

I'm unable to reproduce this - the repos I test have about the same performance with --coverage between v24 and v25. Would somebody be able to put together a repository with jest 24 and jest 25 where switching between them shows a difference?

[benmonro]

just ran our CI build w/ coverage disabled, I think @csvan is on to something. The tests run in 4:00 w/ coverage turned off vs 11 min w/ coverage turned on. I will try to see if i can create repro this weekend at some point.

our exinfo from the build agent:

00:03:31.992   System:
00:03:31.992     OS: Linux 3.10 CentOS Linux 7 (Core)
00:03:31.992     CPU: (8) x64 Intel Core Processor (Skylake, IBRS)
00:03:31.992   Binaries:
00:03:31.992     Node: 10.16.0 - ~/workspace/grocery-electrode/tools/nix_64/nodejs-10.16.0/bin/node
00:03:31.992     npm: 6.9.0 - ~/workspace/grocery-electrode/tools/nix_64/npm-6.9.0/node_modules/.bin/npm
00:03:31.993   npmPackages:
00:03:31.993     jest: 25.1.0 => 25.1.0 

[EvHaus]

We're seeing a similar issue. Upgrading Jest 25 made our tests slower when using coverage (166s with Jest 24 vs. 381s with Jest 25). With Jest 25 displaying many of these errors while running the checks:

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0x10003d041 node::Abort() [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 2: 0x10003d24b node::OnFatalError(char const*, char const*) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 3: 0x1001b8e25 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 4: 0x100586d82 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 5: 0x100589855 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 6: 0x1005856ff v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 7: 0x1005838d4 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 8: 0x10059016c v8::internal::Heap::AllocateRawWithLigthRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
 9: 0x1005901ef v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
10: 0x10055fb34 v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
11: 0x1007e7e14 v8::internal::Runtime_AllocateInNewSpace(int, v8::internal::Object**, v8::internal::Isolate*) [/Users/evhaus/.nvm/versions/node/v10.17.0/bin/node]
12: 0xb9c575dbe3d 
13: 0xb9c57ab091a 
14: 0xb9c579e7d65 
15: 0xb9c579ebaf3 

<--- Last few GCs --->

[733:0x102804000]    84639 ms: Mark-sweep 1335.2 (1449.6) -> 1325.4 (1452.1) MB, 1443.2 / 0.0 ms  (average mu = 0.135, current mu = 0.076) allocation failure scavenge might not succeed
[733:0x102804000]    85872 ms: Mark-sweep 1338.3 (1452.1) -> 1327.8 (1455.1) MB, 1159.4 / 0.0 ms  (average mu = 0.101, current mu = 0.059) allocation failure scavenge might not succeed


<--- JS stacktrace --->

Downgrading to Jest 24 makes those errors go away.

I also noticed Jest 25 handles the collectCoverageFrom differently as it seems to collect coverage from files we have explicitly disabled in that configuration. Did support for the glob syntax change there?