"FATAL ERROR: NewSpace::Rebalance Allocation failed" but already allocate more space for garbage collector

Viewed 1366
<--- Last few GCs --->

[19246:0x3c0ba70] 13018753 ms: Scavenge 15929.0 (32800.1) -> 17647.7 (32800.1) MB, 236071.8 / 0.0 ms  (average mu = 0.309, current mu = 0.369) allocation failure 
[19246:0x3c0ba70] 13263082 ms: Scavenge 15929.0 (32800.1) -> 17701.0 (32800.1) MB, 238469.3 / 0.0 ms  (average mu = 0.309, current mu = 0.369) allocation failure 
[19246:0x3c0ba70] 13510095 ms: Scavenge 15929.0 (32800.1) -> 17763.1 (32800.1) MB, 240951.1 / 0.0 ms  (average mu = 0.309, current mu = 0.369) allocation failure 


<--- JS stacktrace --->
Cannot get stack trace in GC.
FATAL ERROR: NewSpace::Rebalance Allocation failed - JavaScript heap out of memory
 1: 0x8dc510 node::Abort() [node]
 2: 0x8dc55c  [node]
 3: 0xad9b5e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
 4: 0xad9d94 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
 5: 0xec7bf2  [node]
 6: 0xefaf66 v8::internal::MarkCompactCollector::Evacuate() [node]
 7: 0xefb5c2 v8::internal::MarkCompactCollector::CollectGarbage() [node]
 8: 0xed3411 v8::internal::Heap::MarkCompact() [node]
 9: 0xed3b01 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node]
10: 0xed4704 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
11: 0xed7371 v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [node]
12: 0xea0466 v8::internal::Factory::AllocateRawArray(int, v8::internal::PretenureFlag) [node]
13: 0xea0cea v8::internal::Factory::NewFixedArrayWithFiller(v8::internal::Heap::RootListIndex, int, v8::internal::Object*, v8::internal::PretenureFlag) [node]
14: 0xea12a7 v8::internal::Factory::NewUninitializedFixedArray(int, v8::internal::PretenureFlag) [node]
15: 0xe62190  [node]
16: 0xe65322  [node]
17: 0xe65682  [node]
18: 0xe665a2 v8::internal::ArrayConstructInitializeElements(v8::internal::Handle<v8::internal::JSArray>, v8::internal::Arguments*) [node]
19: 0x10fa09f v8::internal::Runtime_NewArray(int, v8::internal::Object**, v8::internal::Isolate*) [node]
20: 0x1bac6fc5be1d 
Aborted (core dumped)

The input will be a 1028673 Json objects. Each object contains an array called enrollment, and the following code will only take out and deal with that array in each object. (Here, ramda function over() is used to perform this operation). The total length of that field (the enrollment array) is 71,157,478.

Environment: 
    NAME="Ubuntu"
    VERSION="18.04.1 LTS (Bionic Beaver)"
npm version: 6.4.1
node version: 10.15.3
run command: node --max-semi-space-size=10000 --max-old-space-size=40000 xx.js
Memory: 80G
Data size: 1028673 records (1 record ~= 4kb) (so approx. 4gib in total)

The code snippet where breaks the program: Then I performed three steps on that array for each object:

  1. add empty field for each element inside the array
  2. remove duplication based on one of the properties of the elements inside the array.
  3. sort
const enrollments = compose(  //ramda functions
    sortBy(prop('date')), 
    deduplicationRecord,
    map(normalizeEnrollment)
);

I've already set both the new space size and the old space size to relatively large space (10g and 40g). Each step is just a function which will read in the array and output a new array. So I believe there's no memory leak here(not sure tho) I've already set both the new space size and the old space size to relatively large space (10g and 40g). If I only perform the above three tasks, it will throw error about garbage collector and memory issues. However, if I add another console.log() step after sort, the issue won't occure anymore.

My question:

  1. Is this because of the garbage collector doesn't have enough time to collect the garbage? (since when I add console.log() as the last step, the program needs extra time to print something in the console)
  2. Based on the info of 'Last Few GCs', it is doing Scavenge, which is the gc algorithm for new space. But inside the error stacktrace info, it said something wrong happened during markcompact, which is the old space gc algorithm. So does this error happen during new space gc or old space gc?
  3. Any potential optimization or solution on this?
1 Answers

V8 developer here. The new-space is not supposed (or designed) to be so large, so the first thing I would try is a significantly smaller new-space. Ideally, drop the --max-semi-space-size flag entirely. If you insist on setting it, choose a value like 8 or 16 or maybe 32 (probably does more harm than good). The whole idea behind a generational heap layout is that the new-space is much, much smaller than the old-space. If you want to allow a large heap, increase old-space size, and leave new-space size alone.

Regarding your questions:

  1. No, the garbage collector will take as much time as it needs. I don't know why adding a console.log statement has an effect in this case.
  2. Mark-compact includes scavenging. The failure is during scavenging, because new-space is too large.
  3. Dropping --max-semi-space-size (to stick with the default value) should help.
Related