How to understands logs when nodejs process crashes out of memory

Question

My node server crashes with the following logs.

<--- Last few GCs --->

  504158 ms: Mark-sweep 1379.9 (1434.3) -> 1379.0 (1434.3) MB, 1486.7 / 0.0 ms [allocation failure] [GC in old space requested].
  505610 ms: Mark-sweep 1379.0 (1434.3) -> 1379.0 (1434.3) MB, 1452.0 / 0.0 ms [allocation failure] [GC in old space requested].
  507067 ms: Mark-sweep 1379.0 (1434.3) -> 1379.0 (1406.3) MB, 1456.1 / 0.0 ms [last resort gc].
  508505 ms: Mark-sweep 1379.0 (1406.3) -> 1379.0 (1406.3) MB, 1438.3 / 0.0 ms [last resort gc].

I understand Mark-sweep is a GC algorithm. How do we interpret these numbers "1379.9 (1434.3) -> 1379.0 (1434.3) MB, 1486.7 / 0.0 ms" after that?

Answer 1

These are reported metrics at the end of a GC mark-sweep (go through, mark for removal, then sweep the marked items). The two numbers are start and end of the total object size and total memory size.

So at the beginning your total object size is 1379.9 and your total memory size is 1434.4 MB. At the end your total object size is 1379.0 and your total memory size is 1434.3 MB. So 0.9 MB was freed.

I'm not 100% certain about the timings, but I believe the first is the total external time spent (which seems to be total time spent in certain "scopes")

Here's the source code you want: https://github.com/nodejs/node/blob/de732725d8ae232d7b6d56927ea8bef471d5bf1d/deps/v8/src/heap/gc-tracer.cc#L481

Regarding external time spent: https://github.com/nodejs/node/blob/de732725d8ae232d7b6d56927ea8bef471d5bf1d/deps/v8/src/heap/gc-tracer.h#L368