Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug]: Jest leaks memory in ESM mode #14605

Open
Havunen opened this issue Oct 5, 2023 · 14 comments
Open

[Bug]: Jest leaks memory in ESM mode #14605

Havunen opened this issue Oct 5, 2023 · 14 comments

Comments

@Havunen
Copy link

Havunen commented Oct 5, 2023

Version

29.7.0

Steps to reproduce

clone the repository at: https://github.com/Havunen/jest-memory-leak
run npm install
run npm test

You should see the heap memory increasing over time until the nodejs process crashes.

Expected behavior

The nodejs process should be able to clean the memory and preferably allocate as little as possible

Actual behavior

The node js process crashes

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
 1: 00007FF7018A3CEF node::SetCppgcReference+15695
 2: 00007FF70181E606 EVP_MD_meth_get_input_blocksize+78566
 3: 00007FF7018203F1 EVP_MD_meth_get_input_blocksize+86225
 4: 00007FF70228A191 v8::Isolate::ReportExternalAllocationLimitReached+65
 5: 00007FF702273928 v8::Function::Experimental_IsNopFunction+1336
 6: 00007FF7020D5190 v8::Platform::SystemClockTimeMillis+659552
 7: 00007FF7020D2218 v8::Platform::SystemClockTimeMillis+647400
 8: 00007FF7020E752A v8::Platform::SystemClockTimeMillis+734202
 9: 00007FF7020E7DA7 v8::Platform::SystemClockTimeMillis+736375
10: 00007FF7020F09DE v8::Platform::SystemClockTimeMillis+772270
11: 00007FF702101356 v8::Platform::SystemClockTimeMillis+840230
12: 00007FF702105F28 v8::Platform::SystemClockTimeMillis+859640
13: 00007FF701E7D67A v8::base::Thread::StartSynchronously+372122
14: 00007FF701FC15B0 v8::ObjectTemplate::IsImmutableProto+13152
15: 00007FF7021EA0C9 v8::SharedValueConveyor::SharedValueConveyor+62825
16: 00007FF7021EA3C8 v8::SharedValueConveyor::SharedValueConveyor+63592
17: 00007FF7021E4624 v8::SharedValueConveyor::SharedValueConveyor+39620
18: 00007FF7021E455A v8::SharedValueConveyor::SharedValueConveyor+39418
19: 00007FF70226E84D v8::ScriptCompiler::CompileUnboundInternal+1069
20: 00007FF70226EB21 v8::ScriptCompiler::CompileUnboundScript+161
21: 00007FF70182E54B node::OnFatalError+57675
22: 00007FF70224056E v8::SharedValueConveyor::SharedValueConveyor+416270
23: 00007FF70223FE17 v8::SharedValueConveyor::SharedValueConveyor+414391
24: 00007FF702240444 v8::SharedValueConveyor::SharedValueConveyor+415972
25: 00007FF7022402A0 v8::SharedValueConveyor::SharedValueConveyor+415552
26: 00007FF70233AC3E v8::PropertyDescriptor::writable+674286
27: 00007FF7022A99B3 v8::PropertyDescriptor::writable+79715
28: 00007FF682572942

Additional context

This is continuation from here: #12205 (comment)

Environment

node v20.8.0
windows 11 ver. 2261
npm 9.6.4
Jest 29.7
@Havunen
Copy link
Author

Havunen commented Oct 5, 2023

Here is a log:

> jest-memory-leak@1.0.0 test
> cross-env NODE_OPTIONS=--max-old-space-size=128 node --experimental-vm-modules ./node_modules/jest/bin/jest.js --config=jest.config.js --runInBand --logHeapUsage --no-watchman --ci

(node:28376) ExperimentalWarning: VM Modules is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
 PASS  tests/test (9).spec.spec.js (37 MB heap size)
 PASS  tests/test (80).spec.spec.js (42 MB heap size)
 PASS  tests/test (8).spec.spec.js (35 MB heap size)
 PASS  tests/test (79).spec.spec.js (45 MB heap size)
 PASS  tests/test (78).spec.spec.js (44 MB heap size)
 PASS  tests/test (77).spec.spec.js (46 MB heap size)
 PASS  tests/test (76).spec.spec.js (46 MB heap size)
 PASS  tests/test (75).spec.spec.js (55 MB heap size)
 PASS  tests/test (74).spec.spec.js (55 MB heap size)
 PASS  tests/test (73).spec.spec.js (59 MB heap size)
 PASS  tests/test (72).spec.spec.js (56 MB heap size)
 PASS  tests/test (71).spec.spec.js (65 MB heap size)
 PASS  tests/test (70).spec.spec.js (65 MB heap size)
 PASS  tests/test (7).spec.spec.js (69 MB heap size)
 PASS  tests/test (69).spec.spec.js (70 MB heap size)
 PASS  tests/test (68).spec.spec.js (68 MB heap size)
 PASS  tests/test (66).spec.spec.js (77 MB heap size)
 PASS  tests/test (67).spec.spec.js (77 MB heap size)
 PASS  tests/test (65).spec.spec.js (80 MB heap size)
 PASS  tests/test (64).spec.spec.js (81 MB heap size)
 PASS  tests/test (63).spec.spec.js (90 MB heap size)
 PASS  tests/test (43).spec.spec.js (82 MB heap size)
 PASS  tests/test (61).spec.spec.js (91 MB heap size)
 PASS  tests/test (62).spec.spec.js (91 MB heap size)
 PASS  tests/test (60).spec.spec.js (95 MB heap size)
 PASS  tests/test (6).spec.spec.js (91 MB heap size)
 PASS  tests/test (59).spec.spec.js (100 MB heap size)
 PASS  tests/test (58).spec.spec.js (101 MB heap size)
 PASS  tests/test (57).spec.spec.js (104 MB heap size)
 PASS  tests/test (56).spec.spec.js (99 MB heap size)
 PASS  tests/test (55).spec.spec.js (100 MB heap size)
 PASS  tests/test (54).spec.spec.js (95 MB heap size)
 PASS  tests/test (53).spec.spec.js (102 MB heap size)
 PASS  tests/test (52).spec.spec.js (99 MB heap size)
 PASS  tests/test (50).spec.spec.js (103 MB heap size)
 PASS  tests/test (51).spec.spec.js (101 MB heap size)
 PASS  tests/test (5).spec.spec.js (107 MB heap size)
 PASS  tests/test (49).spec.spec.js (106 MB heap size)
 PASS  tests/test (48).spec.spec.js (111 MB heap size)
 PASS  tests/test (47).spec.spec.js (111 MB heap size)
 PASS  tests/test (45).spec.spec.js (113 MB heap size)
 PASS  tests/test (46).spec.spec.js (118 MB heap size)
 PASS  tests/test (44).spec.spec.js (116 MB heap size)
 PASS  tests/test (42).spec.spec.js (117 MB heap size)

 RUNS  tests/test (41).spec.spec.js

<--- Last few GCs --->

[28376:000001E017CEF240]     6150 ms: Mark-Compact (reduce) 117.4 (130.8) -> 116.8 (131.3) MB, 25.51 / 0.00 ms  (average mu = 0.609, current mu = 0.567) allocation failure; scavenge might not succeed
[28376:000001E017CEF240]     6189 ms: Mark-Compact (reduce) 118.0 (131.3) -> 116.8 (131.8) MB, 24.29 / 0.01 ms  (average mu = 0.526, current mu = 0.375) allocation failure; scavenge might not succeed

@Havunen
Copy link
Author

Havunen commented Oct 6, 2023

tested with nodejs v21.0.0-nightly202310041a839f388e (06-Oct-2023 11:00) and it is still an issue.

@SimenB
Copy link
Member

SimenB commented Oct 9, 2023

You mentioned JSON files in the other PR. This is how we construct them in ESM mode:

module = new SyntheticModule(
['default'],
function () {
const obj = JSON.parse(transformedCode);
// @ts-expect-error: TS doesn't know what `this` is
this.setExport('default', obj);
},
{context, identifier: modulePath},
);

Essentially copied straight from the docs (which use a JSON example): https://nodejs.org/api/vm.html#class-vmsyntheticmodule

So there's no code cache here. I'd assume JSON.parse wouldn't cause an issue as long as the synthetic module is collected.

But yeah, maybe the flags suggested in #12205 (comment) can help in narrowing down what's not freed?

@SimenB
Copy link
Member

SimenB commented Oct 9, 2023

@Havunen this does not reproduce if I remove the importModuleDynamically option from createScriptFromCode in jest-runtime. So I'm guessing it's still related to the broken code caching (i.e. nr 4 here #12205 (comment))

@Havunen
Copy link
Author

Havunen commented Oct 9, 2023

I commented out all importModuleDynamically callbacks it still does not work using node v21.0.0-nightly20231008fce8fbadcd.
I added more tests and bigger JSON to the example so its more obvious now

@Havunen
Copy link
Author

Havunen commented Oct 9, 2023

log:

cross-env NODE_OPTIONS=--max-old-space-size=128 node --experimental-vm-modules ./node_modules/jest/bin/jest.js --config=jest.config.js --runInBand --logHeapUsage --no-watchman --ci

(node:17340) ExperimentalWarning: VM Modules is an experimental feature and might change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
 PASS  tests/test (94).spec.js (34 MB heap size)
 PASS  tests/test (90).spec.js (50 MB heap size)
 PASS  tests/test (234).spec.js (53 MB heap size)
 PASS  tests/test (89).spec.js (61 MB heap size)
 PASS  tests/test (9).spec.js (61 MB heap size)
 PASS  tests/test (92).spec.js (69 MB heap size)
 PASS  tests/test (91).spec.js (78 MB heap size)
 PASS  tests/test (87).spec.js (74 MB heap size)
 PASS  tests/test (98).spec.js (82 MB heap size)
 PASS  tests/test (97).spec.js (91 MB heap size)
 PASS  tests/test (50).spec.js (87 MB heap size)
 PASS  tests/test (93).spec.js (95 MB heap size)
 PASS  tests/test (192).spec.js (95 MB heap size)
 PASS  tests/test (96).spec.js (103 MB heap size)
 PASS  tests/test (86).spec.js (100 MB heap size)
 PASS  tests/test (129).spec.js (107 MB heap size)
 PASS  tests/test (21).spec.js (111 MB heap size)
 PASS  tests/test (77).spec.js (116 MB heap size)
 PASS  tests/test (186).spec.js (116 MB heap size)
 PASS  tests/test (209).spec.js (121 MB heap size)
 PASS  tests/test (57).spec.js (125 MB heap size)

 RUNS  tests/test (56).spec.js

<--- Last few GCs --->

[17340:0000022DDED70080]     2645 ms: Mark-Compact (reduce) 126.9 (130.3) -> 126.9 (131.1) MB, 52.91 / 0.00 ms  (average mu = 0.347, current mu = 0.071) allocation failure; scavenge might not succeed
[17340:0000022DDED70080]     2694 ms: Mark-Compact (reduce) 127.9 (131.1) -> 127.9 (132.1) MB, 44.15 / 0.00 ms  (average mu = 0.235, current mu = 0.088) allocation failure; scavenge might not succeed


<--- JS stacktrace --->

FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory
 1: 00007FF61DFA9A7F node::SetCppgcReference+13775
 2: 00007FF61DF23B06 DSA_meth_get_flags+76070
 3: 00007FF61DF25941 DSA_meth_get_flags+83809
 4: 00007FF61E984111 v8::Isolate::ReportExternalAllocationLimitReached+65
 5: 00007FF61E96D9B8 v8::Function::Experimental_IsNopFunction+1336
 6: 00007FF61E7D5F90 v8::StackTrace::GetFrameCount+74720
 7: 00007FF61E7D2D8D v8::StackTrace::GetFrameCount+61917
 8: 00007FF61E7E800D v8::StackTrace::GetFrameCount+148573
 9: 00007FF61E7E8892 v8::StackTrace::GetFrameCount+150754
10: 00007FF61E7F166E v8::StackTrace::GetFrameCount+187070
11: 00007FF61E7F976A v8::StackTrace::GetFrameCount+220090
12: 00007FF61E700A5A v8::base::time_internal::TimeBase<v8::base::ThreadTicks>::operator!=+53770
13: 00007FF61E6FD5AD v8::base::time_internal::TimeBase<v8::base::ThreadTicks>::operator!=+40285
14: 00007FF61E702C0F v8::base::time_internal::TimeBase<v8::base::ThreadTicks>::operator!=+62399
15: 00007FF61E913AD8 v8::SharedValueConveyor::SharedValueConveyor+256680
16: 00007FF61E913CF0 v8::SharedValueConveyor::SharedValueConveyor+257216
17: 00007FF61EA355BE v8::PropertyDescriptor::writable+676814
18: 0000022DDF0633E5

All importModuleDynamically removed from the whole code base

image

@Havunen
Copy link
Author

Havunen commented Oct 9, 2023

I also removed all initializeImportMeta callbacks and it still reproduces

@Havunen
Copy link
Author

Havunen commented Oct 9, 2023

I have reproduced the issue using nodejs and javascript only, and also found a work around.

Having a shared context between the modules seems to leak the memory. However setting the shared context null manually after function execution it fixes the memory leak. Setting the variable null in JS is non-sense (ref: https://github.com/Havunen/nodejs-memory-leak/blob/main/test.js#L45-L46 ) because it goes out of scope and should be GC'd but it does not seem to happen. So its definetly a nodejs / v8 bug

https://github.com/Havunen/nodejs-memory-leak

@SimenB
Copy link
Member

SimenB commented Oct 10, 2023

We do set it to null manually in the node environment, FWIW.

Not so in the JSDOM env, but the reproduction in this issue uses the Node env.

Might be we keep a reference without meaning to within the runtime of course

@Havunen
Copy link
Author

Havunen commented Oct 10, 2023

yeah but it is not set null in the call site not sure if it needs to be nulled everywhere or how it works in low level

@Havunen
Copy link
Author

Havunen commented Oct 10, 2023

After testing a bit more it seems setting the context to null does not really fix the issue :/

@FrederickEngelhardt
Copy link

FrederickEngelhardt commented Jun 21, 2024

Edit: same issue with or without cross-env. 😢


Just curious, but does removing cross-env and using node directly resolve the leak? Also does cross-env inject variables/flags into node?

Noticed it's in maintenance only mode so I'm curious if nodejs 20 is supported. https://www.npmjs.com/package/cross-env. 4 years ago was last publish...so it would have only supported maybe up to Node12

@FrederickEngelhardt
Copy link

FrederickEngelhardt commented Jun 21, 2024

Workaround for this is to do the following. Whatever your --max-old-space-size=128 value is...add the same value following to jest.config.js or as a flag --workerIdleMemoryLimit=128MB.

You can pass it around as a process.env variable too...or read the docs further there might be a spot to access this heapsize within the nodejs process (see my bullet).

  • Within node you could run v8.getHeapStatistics().total_heap_size and use the byte count to send to jest or write to the config file.

jest.config.js that works with your repo

diff --git a/jest.config.js b/jest.config.js
index 99cbe34..6f28936 100644
--- a/jest.config.js
+++ b/jest.config.js
@@ -10,6 +10,7 @@ export default {
   transformIgnorePatterns: [
     '/node_modules/',
   ],
+  workerIdleMemoryLimit: '128MB',
   collectCoverage: false,
   coverageReporters: [],
   moduleDirectories: ['node_modules']

@FrederickEngelhardt
Copy link

Regarding workerIdleMemoryLimit, I'm curious if jest should be capping itself directly with that workerIdleMemoryLimit so it can never exceed v8 heap size. Is there a reason to let it exceed the max-old-space-size provided to nodejs?

CC: @SimenB thoughts?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants