15

I get below output from node.js when --trace-gc option is used

[24851]      852 ms: Scavenge 26.8 (57.2) -> 20.8 (58.2) MB, 3.1 ms [allocation failure].
[24851]      927 ms: Scavenge 28.7 (58.2) -> 22.4 (59.2) MB, 2.0 ms [allocation failure].
[24851]     1013 ms: Scavenge 30.4 (61.2) -> 24.1 (61.2) MB, 2.3 ms [allocation failure].
[24851]     1067 ms: Scavenge 31.6 (62.2) -> 24.8 (62.2) MB, 2.1 ms [allocation failure].
[24851] Speed up marking because marker was not keeping up
[24851] Postponing speeding up marking until marking starts
[24851] Speed up marking because marker was not keeping up
[24851] Postponing speeding up marking until marking starts
[24851] Speed up marking because marker was not keeping up
[24851] Postponing speeding up marking until marking starts
[24851]     1359 ms: Mark-sweep 90.9 (115.1) -> 53.6 (113.7) MB, 9.0 ms (+ 19.3 ms in 105 steps since start of marking, biggest step 1.7 ms) [GC interrupt] [GC in old space requested].
[24851]     1578 ms: Scavenge 69.6 (113.7) -> 62.4 (115.7) MB, 6.0 ms [allocation failure].
[24851]     1676 ms: Scavenge 73.1 (117.7) -> 64.1 (121.7) MB, 5.9 ms [allocation failure].

Can someone please explain meaning of each item in above output?

LionHeart
  • 781
  • 1
  • 7
  • 24
  • The closest response that I got on internet is https://groups.google.com/forum/#!topic/nodejs/gITsLR7Zkew . But this seems not to cover all fields. – LionHeart Nov 16 '15 at 22:59
  • https://strongloop.com/strongblog/node-js-performance-garbage-collection/ – vinayr Nov 17 '15 at 05:42

2 Answers2

8

I haven't seen any documentation on this either, but looking at the result of process.memoryusage() along with using the --trace_gc option suggests:

Scavenge <heapUsed before> (<heapTotal before>) -> <heapUsed after> (<heapTotal after>) MB, <how long the GC pause was>

Where heapUsed and heapTotal are kinda-documented by process.memoryusage(), but better explained by this answer.

Mike Fogel
  • 3,127
  • 28
  • 22
3

When you monitoring the memory allocation and CPU utilization using a garbage collector at that time you need to start your server with node --trace_gc server.js, You need to go on Activity Monitor => Memory => Search node, You can see the how much memory is actually using by the node processing, Now when you fire above command then You can see many of logs in the console. There are mainly 2 factors to notice from those logs which are Scavenge & Mark-sweep. If it's deal with Scavenge only in logs it means it's normal memory usage...But when Mark-sweep appears means some CPU intensive task is running over there which leads to high CPU utilization and Memory allocation. Basically, This happened when you execute some code which blocking the current stack which will pop from the stack after a synchronize process done. To avoid Mark-sweep you need to make your functions asynchronous. I hope you will get my point!

Neel Rathod
  • 2,013
  • 12
  • 28