Tracking GC Pauses with perf_hooks in Node.js

p99 latency spikes every few minutes, CPU is higher than request work explains, and you suspect garbage collection — but restarting production with --trace-gc is not an option and log lines are hard to aggregate. This guide from Production Memory Monitoring and Container Limits, part of Node.js Server-Side Memory Management, shows how to observe every GC from inside the process with perf_hooks, turn the events into metrics, and read them alongside latency and heap data.

Symptom Root Cause Immediate Action Measurable Impact
Latency spikes with no slow endpoint Long major GC pauses block the event loop Record GC entries; correlate with latency Spikes attributed (or ruled out)
High CPU with modest traffic High allocation rate → frequent scavenges Track minor GC count and time per minute Churn quantified
Memory near limit, GC time rising Old space full; major GCs frequent and ineffective Alert on GC share and reclaimed bytes Early warning before OOM
Need GC data without restart --trace-gc requires a flag Use PerformanceObserver with gc entries Metrics from running code
Hard to compare releases No stored GC history Export histograms per release Regressions visible

Root Cause: GC Work Is Invisible Unless You Ask for It

V8 runs two kinds of collections, described in scavenger vs major GC: frequent, short scavenges of the young generation, and less frequent mark-sweep-compact collections of the old generation, most of whose marking runs incrementally and concurrently as explained in incremental and concurrent marking. While the main thread performs a GC step, JavaScript does not run: requests wait, timers slip, and the event loop stalls. A service can look healthy in request timing aggregated per minute while individual requests absorb 100 ms pauses.

Node.js exposes GC events through the Performance Timeline. A PerformanceObserver subscribed to the 'gc' entry type receives one PerformanceEntry per collection with its startTime and duration, and a detail object whose kind identifies the type — NODE_PERFORMANCE_GC_MINOR (scavenge), NODE_PERFORMANCE_GC_MAJOR (mark-sweep-compact), NODE_PERFORMANCE_GC_INCREMENTAL (incremental marking step) and NODE_PERFORMANCE_GC_WEAKCB (weak callback processing) — plus flags that indicate, for example, forced collections. Observing costs little, needs no restart and works in any environment.

Durations measure main-thread time for each event. That makes them directly comparable with request latency and event-loop delay, and summing them per minute gives the GC share of wall-clock time. Combined with heap statistics before and after (sampled from v8.getHeapStatistics()), you can tell whether major GCs are reclaiming a lot (churn and promotion) or very little (retention approaching the limit). The latter is the pattern that precedes out-of-memory crashes and deserves an alert.

GC events on the main thread Along a sixty second timeline, minor GC entries appear every few hundred milliseconds with durations of 1 to 3 milliseconds. Incremental marking steps of under 1 millisecond cluster before a major GC. One major GC entry of 140 milliseconds aligns with a p99 latency spike in the request timeline below it. minor incremental major 140 ms p99 latency spike 60 s of production traffic

Step-by-Step Fix

  1. Observe GC entries. Register a PerformanceObserver for 'gc' at startup (see code). Verification: in staging, a burst of traffic produces minor and major entries with durations.
  2. Aggregate into histograms. Record durations into per-kind histograms (for example with prom-client) rather than logging each event. Verification: a metrics endpoint exposes GC duration histograms by kind.
  3. Compute GC share. Sum durations per minute and divide by 60 seconds. Verification: you have a gauge for the percentage of wall-clock time spent in GC.
  4. Add heap context. Sample heap used and limit periodically, and record heap used after each major GC. Verification: you can see whether major GCs reclaim much or little.
  5. Correlate with latency and event-loop delay. Plot p99 latency, monitorEventLoopDelay() percentiles and major GC durations on one dashboard. Verification: spikes line up — or clearly do not, pointing elsewhere.
  6. Alert on the dangerous patterns. Alert on GC share above a threshold (for example 10% for 10 minutes) and on post-GC heap rising towards the limit. Verification: a staging leak test triggers the alert before the process crashes.
The pre-OOM signature In a leaking service, heap used immediately after each major GC climbs from 40 percent to 95 percent of the heap limit over three hours while the GC share of wall-clock time rises from 2 percent to 35 percent, ending in an out-of-memory crash. In a healthy service both stay flat. 100% 0 post-GC heap % of limit (leaking) GC share of wall clock (leaking) healthy service: flat hours 0 → 3 (crash at the end)

Command and Code Reference

Use case: GC histograms and GC share with prom-client.

// gc-metrics.js
const { PerformanceObserver, constants, monitorEventLoopDelay } = require('node:perf_hooks');
const client = require('prom-client');

const KIND = {
  [constants.NODE_PERFORMANCE_GC_MINOR]: 'minor',
  [constants.NODE_PERFORMANCE_GC_MAJOR]: 'major',
  [constants.NODE_PERFORMANCE_GC_INCREMENTAL]: 'incremental',
  [constants.NODE_PERFORMANCE_GC_WEAKCB]: 'weakcb',
};

const gcDuration = new client.Histogram({
  name: 'app_gc_duration_seconds',
  help: 'Main-thread GC pause duration by kind',
  labelNames: ['kind'],
  buckets: [0.001, 0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1],
});
const gcShare = new client.Gauge({ name: 'app_gc_share_ratio', help: 'GC time / wall time, last minute' });

let windowMs = 0;
new PerformanceObserver((list) => {
  for (const e of list.getEntries()) {
    gcDuration.observe({ kind: KIND[e.detail?.kind] ?? 'other' }, e.duration / 1000);
    windowMs += e.duration;
  }
}).observe({ entryTypes: ['gc'] });

setInterval(() => { gcShare.set(windowMs / 60_000); windowMs = 0; }, 60_000).unref();

// Event-loop delay puts GC pauses in context with other blocking work
const eld = monitorEventLoopDelay({ resolution: 20 });
eld.enable();
new client.Gauge({
  name: 'app_event_loop_delay_p99_seconds',
  help: 'p99 event loop delay',
  collect() { this.set(eld.percentile(99) / 1e9); eld.reset(); },
});

Use case: log only unusually long pauses with heap context.

const v8 = require('node:v8');
new PerformanceObserver((list) => {
  for (const e of list.getEntries()) {
    if (e.duration < 50) continue;                    // only pauses that hurt latency
    const h = v8.getHeapStatistics();
    console.warn(JSON.stringify({
      gc: KIND[e.detail?.kind], ms: Math.round(e.duration),
      heapUsedMB: Math.round(h.used_heap_size / 1048576),
      limitMB: Math.round(h.heap_size_limit / 1048576),
    }));
  }
}).observe({ entryTypes: ['gc'] });

Verification and Regression Prevention

Verify the instrumentation in staging by running a deliberate allocation-heavy load (which should raise minor GC counts) and a deliberate leak (which should raise post-GC heap and GC share until the alert fires). In production, check that dashboards show GC histograms for every instance and that the numbers are plausible — minor pauses of a few milliseconds, major pauses mostly short, GC share in low single digits for a healthy service.

Keep GC metrics per release so regressions are obvious after deploys, and pair them with the slope-based leak alert in alerting on memory leaks with growth slope. When GC share rises without a leak, investigate allocation rate with heap sampling or tune the young generation as in tuning --max-semi-space-size.

Validating GC instrumentation in staging Run an allocation-heavy load in staging and confirm minor GC counts rise in the dashboard. Then run a deliberate leak and confirm post-GC heap and GC share climb until the alert fires. In production, check every instance reports plausible histograms. Allocation-heavy load expect more minor GCs Minor count rises? histogram moves Deliberate leak expect post-GC heap rise Alert fires? GC share over threshold

Edge Cases and Gotchas

Durations are main-thread time only

Concurrent marking and sweeping on helper threads do not appear as main-thread pause time. A service can spend significant CPU on background GC with short pauses; compare process CPU with request work to see the full cost.

Incremental entries are many and small

Incremental marking steps generate many tiny entries. Aggregate them rather than logging them, and do not mistake their count for a problem — the total time matters.

Worker threads

Each worker’s isolate collects independently. Register observers inside workers (or report from them) if they do significant work.

Observer overhead

Observing GC events is cheap, but doing heavy work in the callback — synchronous logging, JSON formatting of every event — adds overhead exactly when the process is busiest. Aggregate in memory and export periodically.

Frequently Asked Questions

How do I measure garbage collection pauses in Node.js?

Register a PerformanceObserver for the 'gc' entry type from node:perf_hooks. Each entry reports a collection’s duration and kind. Aggregate durations into histograms and compute the share of wall-clock time spent in GC.

What do the GC kinds mean?

Minor is a scavenge of the young generation; major is a mark-sweep-compact of the old generation; incremental entries are small steps of incremental marking; weak callback entries cover processing of weak references and finalization. Major pauses usually matter most for latency.

What is a healthy GC share?

For most web services, a few percent of wall-clock time. Sustained values above about 10% indicate heavy allocation or a heap approaching its limit, and values that keep climbing alongside post-GC heap usage are a strong leak signal.

Is --trace-gc still useful?

Yes, for detailed investigation: it prints reasons, heap sizes and timing for each collection. The perf_hooks approach is better for continuous production metrics because it needs no restart and integrates with your metrics pipeline.

Can GC cause timeouts?

Long major pauses block the event loop, delaying request handling, timers and health checks. A 200 ms pause during a burst can push requests past tight timeouts; reducing heap size and allocation rate shortens pauses.

Should I alert on individual long pauses?

Usually not on single events, which can be normal. Alert on sustained patterns — high GC share, frequent long major pauses, or post-GC heap rising towards the limit — to avoid noise while catching real problems.

How is GC share different from GC pause time?

Pause time describes individual interruptions: how long the main thread stopped for one collection. GC share is the fraction of wall-clock time spent in collection over an interval, summed across all pauses. A process can have short pauses and a high share (many frequent scavenges from allocation churn) or a low share with one long pause (a large Mark-Compact on a big heap). Track both, because latency problems follow pauses and throughput problems follow share.

Does the performance observer work in serverless or short-lived processes?

It works, but short-lived processes rarely accumulate enough collections for a meaningful histogram, and the process may exit before entries are flushed. Aggregate per invocation (count, total pause, longest pause), emit the summary at the end of each invocation, and interpret it across many invocations rather than within one.