nodejs garbage collection output

Question

Anyone knows where I can read about the output of the --trace-gc option in nodejs?

I am not asking for an explanation on how the gc works, as there is plenty of information about it, just for the output of the --trace-gc.

I can guess what is the meaning of some of the fields but I have no idea of some others.

For instance :

• what is the meaning of the number in parenthesis,
• "steps" meaining (it may be related to the incremental mark & lazy sweep)
• the size of the heap that is written is the total heap ? (adding young and old areas)
• ...

An example :

[12994]    77042 ms: Scavenge 260.7 (298.1) -> 247.7 (298.1) MB, 9.4 ms [allocation failure].
[12994]    77188 ms: Scavenge 261.7 (298.1) -> 249.0 (300.1) MB, 7.4 ms [allocation failure].
[12994]    77391 ms: Scavenge 263.8 (301.1) -> 250.6 (302.1) MB, 8.1 ms [allocation failure].
[12994]    77511 ms: Scavenge 264.8 (302.1) -> 251.8 (304.1) MB, 7.4 ms [allocation failure].
[12994]    77839 ms: Scavenge 273.4 (304.1) -> 260.7 (305.1) MB, 8.3 ms (+ 55.7 ms in 201 steps since last GC) [allocation failure].
[12994]    78052 ms: Scavenge 274.3 (305.1) -> 261.9 (307.1) MB, 8.2 ms (+ 54.4 ms in 192 steps since last GC) [allocation failure].
[12994]    78907 ms: Scavenge 277.3 (308.1) -> 264.2 (309.1) MB, 10.1 ms (+ 51.5 ms in 196 steps since last GC) [allocation failure].
[12994]    80246 ms: Mark-sweep 272.2 (310.1) -> 82.9 (310.1) MB, 45.2 ms (+ 195.4 ms in 690 steps since start of marking, biggest step 1.2 ms) [GC interrupt] [GC in old space requested].
[12994]    80868 ms: Scavenge 99.3 (310.1) -> 85.5 (310.1) MB, 6.5 ms [allocation failure].
[12994]    81039 ms: Scavenge 100.2 (310.1) -> 86.8 (310.1) MB, 6.9 ms [allocation failure].
[12994]    81455 ms: Scavenge 102.2 (310.1) -> 88.8 (310.1) MB, 5.5 ms [allocation failure].

UPDATE

Looking at the file that creates the output (as suggesteed by mtth), I am adding an explanation of all the fields in case anyone is interested :

[12994]    77042 ms: Scavenge 260.7 (298.1) -> 247.7 (298.1) MB, 9.4 ms [allocation failure].
[pid] <time_since_start> : 
      <Phase> <heap_used_before (old+young)> (<allocated_heap_before>) ->
              <heap_used_after (old+young)> (<allocated_heap_after>) MB, 
              <time_spent_gc> [<reason_of_gc>]

Additionally when there has been any incremental marking between old space gcs (full), it appears in the scavenging trace, like this :

(+ <incremental_time_duration> ms in <incremental_marking_steps> steps since last GC)

When the trace corresponds to an old space gcs (full), it also shows the biggest step duration.

This traces correspond to nodejs 0.12.9, and they look alike at least in nodejs 4.2.2

Answer 1

The closest to documentation I could find is the source of the function that generates the output. Using the comments in gc-tracer.h, we can figure out what each entry means. For example:

• what is the meaning of the number in parenthesis

The number inside the parens represents the total memory allocated from the OS (and the one before is the total memory used for objects in the heap).