Is your Node.js application experiencing unresponsiveness or performance bottlenecks? The problem could have originated because of long running Garbage Collection pauses or memory leaks. In such circumstances you might want to study your Node.js application’s Garbage Collection performance. In this post, we’ll walk you through the process of enabling GC traces, interpreting the trace data, and the right tools and knowledge needed to study the Garbage Collection behavior.
How to enable Node.js Garbage Collection traces?
There are few approaches to enable the Node.js Garbage Collection traces. Easiest and most straightforward approach is to pass the ‘–trace-gc’ flag along with your usual invocation command. Example:
node --trace-gc my-script.mjs
Once the ‘–trace-gc’ flag is enabled, your Node.js application will start generating garbage collection traces in the console output. These traces provide valuable insights into memory usage, GC events, and potential performance bottlenecks. Garbage Collection traces would look something like this:
[721159:0x61f0210] 1201125 ms: Scavenge 27.7 (28.8) -> 26.8 (29.8) MB, 0.5 / 0.2 ms (average mu = 0.999, current mu = 0.970) allocation failure
[721166:0x5889210] 1201338 ms: Scavenge 30.7 (32.1) -> 29.7 (33.1) MB, 0.6 / 0.3 ms (average mu = 0.998, current mu = 0.972) allocation failure
[721173:0x54fc210] 1202608 ms: Scavenge 26.8 (28.3) -> 25.8 (29.3) MB, 0.7 / 0.4 ms (average mu = 0.999, current mu = 0.972) allocation failure
[721152:0x54ca210] 1202879 ms: Scavenge 30.5 (31.8) -> 29.6 (32.8) MB, 0.6 / 0.2 ms (average mu = 0.999, current mu = 0.978) allocation failure
[721166:0x5889210] 1202925 ms: Scavenge 30.6 (32.1) -> 29.7 (33.1) MB, 0.7 / 0.3 ms (average mu = 0.998, current mu = 0.972) task
[721159:0x61f0210] 1203105 ms: Scavenge 27.7 (28.8) -> 26.7 (29.8) MB, 0.4 / 0.2 ms (average mu = 0.999, current mu = 0.970) allocation failure
[721173:0x54fc210] 1204660 ms: Scavenge 26.8 (28.3) -> 25.8 (29.3) MB, 0.5 / 0.2 ms (average mu = 0.999, current mu = 0.972) allocation failure
How to analyze Node.js GC log?
Garbage Collection traces contain a rich set of information such as how many objects created, how many objects got garbage collected, how long each Garbage Collection event took to complete, how much memory got reclaimed after every GC event, whether there are any memory leaks… You may refer to this post to see how to interpret and read the GC trace. However, it’s quite a tedious and time-consuming process to interpret the GC traces manually. Thus, you may consider using the GCeasy online tool to analyze the Node.js GC traces.
You can go to the GCeasy tool and sign-up for a free account and upload the GC trace. The tool will instantly parse the GC traces and generate a report that contains vital Garbage Collection analysis metrics and graphs. For your reference, here is the live report generated by the tool.
Node.js GC trace analysis report
GCeasy report provides a rich set of graphs, metrics and statistics around Garbage Collection overhead added to the Node.js application. Below are some of the excerpts from the GCeasy report.
Fig: Heap usage graph
‘Heap usage’ graph, reports the memory trend after every GC event. You can notice that after GC events, memory usage drops.
Fig: GC Duration Time Graph
‘GC Duration Time’ Graph indicates the time taken by each GC event to run. The red triangle indicates it’s a Full GC event and green square icon indicates it’s a Young (or minor) GC event. You can notice that in general Full GC events (i.e. red triangle) are running less frequently, but taking more time, on the other hand Young GC events (i.e. green square) are running more often but taking less time. Because Full GC runs on all the regions in the Node.js memory, whereas minor GC runs only on the young region of the memory.
Fig: Reclaimed Bytes Graph
‘Reclaimed Bytes’ graph shows the amount of memory reclaimed after each GC event. You can notice that Full GC events are reclaiming more memory than Young GC events.
Fig: GC Statistics section
Besides giving graphical visualization of the Garbage Collection behavior, the tool also gives a lot of statistical metrics. The ‘GC statistics’ section above reports the total number GC events, their average time, min/max time, standard deviation… These metrics are vital to study the overhead added by the automatic garbage collection to the Node.js application.
Fig: GC Causes section
Another interesting section in the report is the ‘GC Causes’ section. This section reveals the reasons why Garbage Collection got triggered in the application. For example, in this application 50,965 GC events got triggered because of ‘Allocation Failure’. This happens when there is a lack of memory in the young generation.
Conclusion
Node.js garbage collection analysis provides insights into your application’s memory management, performance, and stability. By understanding and interpreting GC traces, you can uncover hidden performance bottlenecks, identify memory leaks, and optimize memory usage for optimal application performance. Armed with this knowledge, you can make informed decisions to optimize your code, fine-tune garbage collection parameters, and address any underlying issues affecting performance.
Top comments (0)