Heap space explaination on old and new(young) space thresholds, interesting behavior observed

[abregar]

Hi,
seeing some interesting behavior on some of apps I have based on node.js v14.15.1.
I am observing
MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory which I need to dig deeper to reveal the root cause. But what is interesting is - my experience with 'heap out of memory' was similar to 'near heap exhaustion' where it is clear that configured heap is near limit. But in my case - with following v8 options enabled:
/usr/bin/node --max-old-space-size=6144--optimize_for_size --always_compact --heapsnapshot-signal=SIGUSR2

process dies ~55% of configured old space, i.e.:

May 19 17:25:04 node[25195]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory
May 19 17:25:04 node[25195]: <--- JS stacktrace --->
May 19 17:25:04 node[25195]: [23321:0x7f99848e8000] 101763240 ms: Scavenge (reduce) 3376.7 (3382.6) -> 3376.5 (3384.1) MB, 40.9 / 0.0 ms  (average mu
May 19 17:25:04 node[25195]: [23321:0x7f99848e8000] 101763194 ms: Scavenge (reduce) 3376.3 (3382.4) -> 3376.1 (3383.6) MB, 17.9 / 0.0 ms  (average mu
May 19 17:25:04 node[25195]: [23321:0x7f99848e8000] 101763135 ms: Scavenge (reduce) 3375.8 (3381.6) -> 3375.8 (3383.4) MB, 20.7 / 0.0 ms  (average mu
May 19 17:25:04 node[25195]: <--- Last few GCs --->

Tried with max-old-space-size=8192, and this time again process dies ~55%, i.e.

May 20 10:24:09 node[971]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory
May 20 10:24:09 node[971]: <--- JS stacktrace --->
May 20 10:24:09 node[971]: [16806:0x7f4ee4ce8000]  4015463 ms: Scavenge (reduce) 4524.2 (4530.6) -> 4523.8 (4531.8) MB, 34.8 / 0.0 ms  (average mu = 0.615, current mu = 0.613) allocation failure
May 20 10:24:09 node[971]: [16806:0x7f4ee4ce8000]  4015413 ms: Scavenge (reduce) 4523.8 (4530.1) -> 4523.5 (4531.6) MB, 39.0 / 0.0 ms  (average mu = 0.615, current mu = 0.613) allocation failure
May 20 10:24:09 node[971]: [16806:0x7f4ee4ce8000]  4015341 ms: Scavenge (reduce) 4523.5 (4529.6) -> 4523.2 (4531.1) MB, 49.8 / 0.0 ms  (average mu = 0.615, current mu = 0.613) allocation failure
May 20 10:24:09 node[971]: <--- Last few GCs --->

All I would like to clarify is - if there are any default thresholds or relation between old, new, semi spaces, particularly this observed 55% and how this is made visible with inspector or some other tool?

[bnoordhuis]

any default thresholds or relation between old, new, semi spaces

Not exactly but a good rule of thumb is that compaction needs 2x the size of the live objects. That 55% you observed is therefore very plausible.

[abregar]

Thank you for the hint, did some further research in this context, mainly staring from issue nodejs/node#40014 .
To explain why adding v8 params anyway - they were introduced to the application with node.js v10.x where application suffered from RSS memory fragmentation and those parameters mitigated the issue. They were automatically inherited when node.js was upgraded.

Have tried few combinations of test script (progressively filling the heap at slow pace - in order gc to follow nicely) with different set of named parameters and node.js version. Starting like in node --expose-gc --trace_gc --max-old-space-size=100 test.js

Results are kind a interesting.
node.js version: v10.15.0 v8 param used: --optimize-for-size --always-compact gc activity: ... [1656230:0x40afc60] 26465 ms: Mark-sweep 5.0 (9.7) -> 4.2 (9.2) MB, 9.4 / 0.0 ms (average mu = 0.652, current mu = 0.655) testing GC in old space requested ^C Result: runs without visible flaw

node.js version: v14.15.1 v8 param used: --always-compact gc activity: ... <--- Last few GCs ---> [1591813:0x5640bb0] 4550 ms: Mark-sweep 39.8 (50.8) -> 39.3 (51.0) MB, 15.5 / 0.0 ms (average mu = 0.485, current mu = 0.480) testing GC in old space requested [1591813:0x5640bb0] 4580 ms: Mark-sweep 40.0 (51.0) -> 39.5 (51.3) MB, 16.1 / 0.0 ms (average mu = 0.478, current mu = 0.470) testing GC in old space requested [1591813:0x5640bb0] 4610 ms: Mark-sweep 40.2 (51.3) -> 39.7 (51.5) MB, 15.8 / 0.0 ms (average mu = 0.476, current mu = 0.475) testing GC in old space requested <--- JS stacktrace ---> FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory Result: breaks fatal @half heap configured

node.js version: v14.15.1 v8 param used: --optimize-for-size gc activity: ... <--- Last few GCs ---> [1695715:0x556abc0] 8752 ms: Mark-sweep 74.2 (94.8) -> 73.7 (95.0) MB, 5.3 / 0.0 ms (average mu = 0.739, current mu = 0.757) testing GC in old space requested [1695715:0x556abc0] 8773 ms: Mark-sweep 74.4 (95.0) -> 73.9 (95.3) MB, 6.9 / 0.0 ms (average mu = 0.709, current mu = 0.679) testing GC in old space requested [1695715:0x556abc0] 8793 ms: Mark-sweep 74.6 (95.3) -> 74.1 (95.3) MB, 5.1 / 0.0 ms (average mu = 0.724, current mu = 0.741) testing GC in old space requested <--- JS stacktrace --->FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory Result: breaks fatal @near full heap configured

node.js version: v14.15.1 v8 param used: none gc activity: ... [1702856:0x53afaf0] 134813 ms: Mark-sweep 26.3 (65.3) -> 25.8 (65.6) MB, 1.8 / 0.0 ms (average mu = 0.874, current mu = 0.876) testing GC in old space requested [1702856:0x53afaf0] 134828 ms: Mark-sweep 26.5 (65.8) -> 26.0 (65.8) MB, 1.9 / 0.0 ms (average mu = 0.874, current mu = 0.875) testing GC in old space requested ^C Result: sawtoothing mem, cpu seems stable, but does not break, rss fragmentation not determined

node.js version: v16.15.0 v8 param used: --optimize-for-size gc activity: ... <--- Last few GCs ---> [1721533:0x59909c0] 13445 ms: Mark-sweep 80.8 (101.2) -> 80.1 (101.2) MB, 66.4 / 0.0 ms (average mu = 0.273, current mu = 0.264) testing GC in old space requested [1721533:0x59909c0] 13533 ms: Mark-sweep 81.0 (101.4) -> 80.3 (101.4) MB, 67.3 / 0.0 ms (average mu = 0.253, current mu = 0.234) testing GC in old space requested [1721533:0x59909c0] 13620 ms: Mark-sweep 81.2 (101.7) -> 80.5 (101.7) MB, 66.9 / 0.0 ms (average mu = 0.244, current mu = 0.235) testing GC in old space requested <--- JS stacktrace ---> FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory Result: a bit better than v14, still breaks fatal

node.js version: v16.15.0 v8 param used: --always-compact gc activity: ... [1752299:0x659e8a0] 64050 ms: Mark-sweep 29.4 (66.7) -> 28.8 (66.7) MB, 14.1 / 0.0 ms (average mu = 0.532, current mu = 0.550) testing GC in old space requested [1752299:0x659e8a0] 64079 ms: Mark-sweep 29.6 (66.9) -> 29.0 (66.9) MB, 13.0 / 0.0 ms (average mu = 0.542, current mu = 0.555) testing GC in old space requested ^C progressive increasing cpu impact detected with heap filling up, but does not break

Would appreciate any further hint what to debug deeper and which direction to determine the root cause. Thank you in advance.

[bnoordhuis]

Is your question why --optimize-for-size makes it run out of memory? It by default limits --max-semi-space-size to 1 MB, that's probably why.

[abregar]

Thank you for sharing this piece of information. May I ask for a v8 documentation reference where this setting(s) behavior is described in more detail?

[bnoordhuis]

I'm afraid the words "V8" and "documentation" are rarely seen together unless it's in a sentence with words like "missing" or "lack thereof". You end up either reading the source code or asking people who have.