Memory Leak on ridiculously simple repo

[javinor]

You guys do an awesome job and we all appreciate it! 🎉

🐛 Bug Report

On a work project we discovered a memory leak choking our CI machines. Going down the rabbit hole, I was able to recreate the memory leak using Jest alone.

Running many test files causes a memory leak. I created a stupid simple repo with only Jest installed and 40 tautological test files.

I tried a number of solutions from #7311 but to no avail. I couldn't find any solutions in the other memory related issues, and this seems like the most trivial repro I could find.

Workaround :'(

We run tests with --expose-gc flag and adding this to each test file:

afterAll(() => {
  global.gc && global.gc()
})

To Reproduce

Steps to reproduce the behavior:

git clone git@github.com:javinor/jest-memory-leak.git
cd jest-memory-leak
npm i
npm t

Expected behavior

Each test file should take the same amount of memory (give or take)

Link to repl or repo (highly encouraged)

https://github.com/javinor/jest-memory-leak

Run npx envinfo --preset jest

Paste the results here:

System:
    OS: macOS High Sierra 10.13.6
    CPU: (4) x64 Intel(R) Core(TM) i7-5557U CPU @ 3.10GHz
  Binaries:
    Node: 10.15.0 - ~/.nvm/versions/node/v10.15.0/bin/node
    Yarn: 1.12.3 - /usr/local/bin/yarn
    npm: 6.4.1 - ~/.nvm/versions/node/v10.15.0/bin/npm
  npmPackages:
    jest: ^24.1.0 => 24.1.0

[milesj]

I found this out recently but you can use the Chrome console to debug Node scripts! You can try using the Chrome console to profile Jest while it's running to try and dig into the issue.

I believe the command is: node --inspect ./node_modules/.bin/jest --watch -i. When running, open Chrome and go to about:inspect. You should then see the running Node script.

[jeysal]

Do I understand correctly that using the workaround to force GC runs makes the heap size remain constant? In that case it's not really a memory leak, just v8 deciding not to run the GC because there is enough memory available. If I try running the repro with 50MB heap size

node --max_old_space_size=50 node_modules/.bin/jest --logHeapUsage --runInBand --config=jest.config.js

the tests still complete successfully, supporting this assumption.

[javinor]

@milesj I ran through some memory dumps, but couldn't make much sense of them, I'm not too experienced with pursuing leaks and I didn't want to point in the wrong direction without something solid to count on.

@jeysal you are right of course! The thing is our tests freeze in the middle of running since (I assume and could be wrong) we run out of memory. After spending a lot of time trying to figure this out, I found #7274. It seemed to me from the discussion that the behaviour I encountered here is not intended. wdyt @SimenB ?

[javinor]

Bueller?

[alfaproject]

My tests are also leaking massively on CI but the exact same setup locally doesn't really leak (much at least).

It's so bad, I'm considering disabling tests on CI until I can make sense of what the difference is beside the OS. ):

[javinor]

Hey guys!

I simplified the memory leak case to a single file which runs tautological tests and eventually throws an exception due to a memory leak.

I'm not sure how to move forward with this... help? @SimenB @jeysal @milesj

jest_leak@1.0.0 test /Users/javinor/workspace/jest-memory-leak
> jest --logHeapUsage --runInBand --config=jest.config.js


 RUNS  __test__/repeat100.test.js

<--- Last few GCs --->

[82597:0x103800000]    79124 ms: Mark-sweep 1259.1 (1442.2) -> 1240.0 (1436.2) MB, 438.3 / 0.0 ms  (average mu = 0.310, current mu = 0.304) allocation failure scavenge might not succeed
[82597:0x103800000]    79197 ms: Scavenge 1255.7 (1436.2) -> 1242.6 (1438.2) MB, 15.9 / 0.0 ms  (average mu = 0.310, current mu = 0.304) allocation failure
[82597:0x103800000]    79256 ms: Scavenge 1256.5 (1438.2) -> 1244.7 (1441.7) MB, 11.0 / 0.0 ms  (average mu = 0.310, current mu = 0.304) allocation failure


<--- JS stacktrace --->

==== JS stack trace =========================================

    0: ExitFrame [pc: 0x2440d84dbe3d]
Security context: 0x30802859e6e9 <JSObject>
    1: prepareStackTrace [0x3080c9459f79] [/Users/javinor/workspace/garbage/jest_leak/node_modules/source-map-support/source-map-support.js:~388] [pc=0x2440d854b545](this=0x308094d07b59 <JSFunction Error (sfi = 0x308018616e01)>,error=0x3080e18623f9 <Error map = 0x3080f3c619f9>,stack=0x3080e1862e91 <JSArray[23]>)
    2: InternalFrame [pc: 0x2440d848ee75]
    ...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0x10003c597 node::Abort() [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 2: 0x10003c7a1 node::OnFatalError(char const*, char const*) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 3: 0x1001ad575 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 4: 0x100579242 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 5: 0x10057bd15 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 6: 0x100577bbf v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 7: 0x100575d94 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 8: 0x10058262c v8::internal::Heap::AllocateRawWithLigthRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
 9: 0x1005826af v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
10: 0x100551ff4 v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
11: 0x1007da044 v8::internal::Runtime_AllocateInNewSpace(int, v8::internal::Object**, v8::internal::Isolate*) [/Users/javinor/.nvm/versions/node/v10.15.3/bin/node]
12: 0x2440d84dbe3d
Abort trap: 6

[fyodorvi]

Similar here, jest + ts-jest, simple tests get over 1GB of memory and eventually crash.

[kirillgroshkov]

crashes for us too

[jeysal]

@javinor For a test file containing a ridiculous number of tests, I'm not sure there's much we can do, we have to keep the test objects around until the test file is finished - this is the heap while the tests are running:

Hundreds of MBs of test objects, so for the case shown in this repro we can't really help either :/

[thymikee]

FYI @scotthovestadt is currently working on holistically improving memory efficiency of Jest, so improvements are coming (some of them in the next minor version).

[kirillgroshkov]

I wonder, why isn't it possible for Jest to spawn a process for each test file, which will guarantee that memory will be freed? Ok, it can be slower, of course, but in my case - it's much better to be slower rather than get a crash from out-of-memory and be blocked to use Jest alltogether...

Maybe an option? Or a separate "runner" (not sure if I understand architecture and terminology right)?

Is it architecturally possible?

Or, will Node-experimental-workers solve it?..

[scotthovestadt]

I've made a few improvements to memory in the next release:
#8234
#8233

I have a future plan to improve memory in a couple of ways:

• by not holding onto test results at all, which are currently held until the end. related: Support JSON line output. #8242
• limiting number of modules that can exist in the require cache

The problem with your suggestion of just spawning a new worker for each test is that it would be very slow. A better suggestion along the same lines would be to monitor the memory usage of the processes and auto-restart them at some threshold. I have some concerns about that in general, I'd rather always fix memory leaks than paper them over, but if a PR did that I would accept it.

Let me know if the release next week helps with the problems you've been experiencing.

[kirillgroshkov]

@scotthovestadt thanks for the info! I'll definitely check with the next release.

My actual issue is reported here: #8247
And there I'm dealing with much bigger leaks, +30Mb per each test file (~150 files in my project).

[javinor]

Thanks for the responses guys!

I think I can break this down to different two problems:

1. Memory consumption grows the more test files I have
2. Memory consumption grows the more tests I have per file

We're running thousands of tests, each creating a relatively big setup so we get bitten twice.

The original screenshot showing the consumption growing from test file to test file, hinting to a leak between tests - I have a few guesses as to why this happens, but nothing solid yet.

The exception I referred to later, as far as I can tell, really has to do with what @jeysal pointed out - having a large number of tests in the file. In our case, we have only hundreds of tests but with a very large setup. I'll try to provide a better reproduction of this.

I'll update after the next release, when I get to poke around a bit more and see the additional fixes in action. Thanks guys!