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?
The node:trace_events module provides a mechanism to centralize tracing information generated by V8, Node. js core, and userspace code. Tracing can be enabled with the --trace-event-categories command-line flag or by using the node:trace_events module.
Some high-level languages, such as JavaScript, utilize a form of automatic memory management known as garbage collection (GC). The purpose of a garbage collector is to monitor memory allocation and determine when a block of allocated memory is no longer needed and reclaim it.
Garbage collection is a way of managing application memory automatically. The job of the garbage collector (GC) is to reclaim memory occupied by unused objects (garbage).
This small GC is triggered by a number of things (including some heuristics) that can make it difficult to determine precisely what triggered it, but every couple seconds is nothing to be concerned about in practice since it's only blocking for 1-10ms. Under high load applications it will actually run much more often.
I haven't seen any documentation on this either, but doing 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.
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!
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With