垃圾回收追踪

本指南将介绍垃圾回收追踪的基础知识。

读完本指南后,你将能够

  • 在你的 Node.js 应用程序中启用追踪
  • 解读追踪日志
  • 识别你的 Node.js 应用程序中潜在的内存问题

关于垃圾回收器(GC)的工作原理有很多知识需要学习,但如果你只记住一件事,那就是当 GC 运行时,你的代码是不运行的。

你可能想知道垃圾回收运行的频率和时长,以及其结果是什么。

准备工作

为了本指南的目的,我们将使用这个脚本

// script.mjs

import  from 'node:os';

let  = 1_000_000;
const  = new ();

function () {
  const  = {
    : .(),
    : .(),
    : .(),
    : .(),
  };

  .();
}

function () {
  .(`Total: ${.} entries`);
}

// execution
(() => {
  while ( > 0) {
    ();
    ..(`~~> ${} entries to record\r`);
    --;
  }

  ();
})();

尽管这里的泄漏很明显,但在真实世界的应用程序中,找到泄漏的源头可能很麻烦。

带垃圾回收追踪运行

你可以使用 --trace-gc 标志在进程的控制台输出中看到垃圾回收的追踪信息。

$ node --trace-gc script.mjs

注意:你可以在 Node.js Diagnostics 仓库中找到此练习的源代码。

它应该会输出类似这样的内容

[39067:0x158008000]     2297 ms: Scavenge 117.5 (135.8) -> 102.2 (135.8) MB, 0.8 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
[39067:0x158008000]     2375 ms: Scavenge 120.0 (138.3) -> 104.7 (138.3) MB, 0.9 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
[39067:0x158008000]     2453 ms: Scavenge 122.4 (140.8) -> 107.1 (140.8) MB, 0.7 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
[39067:0x158008000]     2531 ms: Scavenge 124.9 (143.3) -> 109.6 (143.3) MB, 0.7 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
[39067:0x158008000]     2610 ms: Scavenge 127.1 (145.5) -> 111.8 (145.5) MB, 0.7 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
[39067:0x158008000]     2688 ms: Scavenge 129.6 (148.0) -> 114.2 (148.0) MB, 0.8 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
[39067:0x158008000]     2766 ms: Scavenge 132.0 (150.5) -> 116.7 (150.5) MB, 1.1 / 0.0 ms  (average mu = 0.994, current mu = 0.994) allocation failure
Total: 1000000 entries

难以阅读?或许我们应该回顾一些概念,并解释一下 --trace-gc 标志的输出。

使用 --trace-gc 检查追踪日志

--trace-gc(或 --trace_gc,两者都可以)标志会在控制台输出所有垃圾回收事件。每一行的构成可以描述为

[13973:0x110008000]       44 ms: Scavenge 2.4 (3.2) -> 2.0 (4.2) MB, 0.5 / 0.0 ms  (average mu = 1.000, current mu = 1.000) allocation failure
标记值解释
13973运行进程的 PID
0x110008000Isolate(JS 堆实例)
44 ms自进程启动以来的时间(毫秒)
ScavengeGC 的类型/阶段
2.4GC 前已使用的堆内存(MB)
(3.2)GC 前的总堆内存(MB)
2.0GC 后已使用的堆内存(MB)
(4.2)GC 后的总堆内存(MB)
0.5 / 0.0 ms (average mu = 1.000, current mu = 1.000)GC 耗时(毫秒)
allocation failureGC 的原因

我们这里只关注两个事件

  • Scavenge
  • Mark-sweep

堆被划分为多个*空间*。其中包括一个名为“新生代”(new space)的空间和另一个名为“老生代”(old space)的空间。

👉 实际上,堆的结构要复杂一些,但本文中我们将使用一个简化版本。如果你想了解更多细节,我们鼓励你观看 Peter Marshall 关于 Orinoco 的这个演讲

Scavenge

Scavenge 是一种在新生代空间执行垃圾回收的算法名称。新生代是创建对象的地方。新生代被设计得很小,以便垃圾回收可以快速进行。

让我们想象一个 Scavenge 场景

  • 我们分配了 ABCD
    | A | B | C | D | <unallocated> |
    
  • 我们想分配 E
  • 空间不足,内存耗尽
  • 然后,触发一次(垃圾)回收
  • 死对象被回收
  • 存活对象将保留
  • 假设 BD 已经死亡
    | A | C | <unallocated> |
    
  • 现在我们可以分配 E
    | A | C | E | <unallocated> |
    

v8 会将经过两次 Scavenge 操作后仍未被垃圾回收的对象晋升到老生代空间。

👉 完整的 Scavenge 场景

Mark-sweep

Mark-sweep 用于从老生代空间回收对象。老生代是那些从新生代中存活下来的对象所居住的地方。

该算法由两个阶段组成

  • 标记 (Mark):将仍然存活的对象标记为黑色,其他对象标记为白色。
  • 清除 (Sweep):扫描白色对象并将它们转换为空闲空间。

👉 事实上,标记和清除步骤要更复杂一些。请阅读此文档以获取更多细节。

--trace-gc 实战

内存泄漏

现在,如果你快速回到之前的终端窗口:你会看到控制台中有很多 Mark-sweep 事件。我们还看到,事件发生后回收的内存量微不足道。

现在我们是垃圾回收专家了!我们能推断出什么呢?

我们可能遇到了内存泄漏!但我们如何确定呢?(提醒:在这个例子中非常明显,但在真实世界的应用程序中呢?)

但是我们如何找到上下文呢?

如何获取不良分配的上下文

  1. 假设我们观察到老生代空间在持续增长。
  2. 减少 --max-old-space-size,使得总堆内存更接近限制
  3. 运行程序直到内存溢出。
  4. 生成的日志会显示失败的上下文。
  5. 如果发生内存溢出(OOM),将堆大小增加约10%,并重复几次。如果观察到相同的模式,则表明存在内存泄漏。
  6. 如果没有内存溢出,则将堆大小固定在该值——一个紧凑的堆可以减少内存占用和计算延迟。

例如,尝试用以下命令运行 script.mjs

node --trace-gc --max-old-space-size=50 script.mjs

你应该会遇到内存溢出(OOM)

[...]
<--- Last few GCs --->
[40928:0x148008000]      509 ms: Mark-sweep 46.8 (65.8) -> 40.6 (77.3) MB, 6.4 / 0.0 ms  (+ 1.4 ms in 11 steps since start of marking, biggest step 0.2 ms, walltime since start of marking 24 ms) (average mu = 0.977, current mu = 0.977) finalize incrementa[40928:0x148008000]      768 ms: Mark-sweep 56.3 (77.3) -> 47.1 (83.0) MB, 35.9 / 0.0 ms  (average mu = 0.927, current mu = 0.861) allocation failure scavenge might not succeed
<--- JS stacktrace --->
FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory [...]

现在,尝试将其设置为 100MB

node --trace-gc --max-old-space-size=100 script.mjs

你应该会遇到类似的情况,唯一的区别是最后的 GC 追踪日志会显示一个更大的堆大小。

<--- Last few GCs --->
[40977:0x128008000]     2066 ms: Mark-sweep (reduce) 99.6 (102.5) -> 99.6 (102.5) MB, 46.7 / 0.0 ms  (+ 0.0 ms in 0 steps since start of marking, biggest step 0.0 ms, walltime since start of marking 47 ms) (average mu = 0.154, current mu = 0.155) allocati[40977:0x128008000]     2123 ms: Mark-sweep (reduce) 99.6 (102.5) -> 99.6 (102.5) MB, 47.7 / 0.0 ms  (+ 0.0 ms in 0 steps since start of marking, biggest step 0.0 ms, walltime since start of marking 48 ms) (average mu = 0.165, current mu = 0.175) allocati

注意:在真实的应用程序中,在代码中找到泄漏的对象可能很麻烦。堆快照可以帮助你找到它。请访问专门介绍堆快照的指南

运行缓慢

你如何判断垃圾回收是否发生得太频繁或导致了开销?

  1. 查看追踪数据,特别是连续回收之间的时间间隔。
  2. 查看追踪数据,特别关注 GC 所花费的时间。
  3. 如果两次 GC 之间的时间小于 GC 所花费的时间,那么应用程序正严重受阻。
  4. 如果两次 GC 之间的时间和 GC 所花费的时间都非常长,那么应用程序可能可以使用更小的堆。
  5. 如果两次 GC 之间的时间远大于 GC 所花费的时间,那么应用程序相对健康。

修复泄漏

现在让我们来修复这个泄漏。我们可以用一个文件来存储我们的条目,而不是使用一个对象。

让我们对脚本做一点修改

// script-fix.mjs
import  from 'node:fs/promises';
import  from 'node:os';

let  = 1_000_000;
const  = `entries-${.()}`;

async function () {
  const  = {
    : .(),
    : .(),
    : .(),
    : .(),
  };
  await .(, .() + '\n');
}

async function () {
  const  = await .();
  .(`File size ${.} bytes`);
}

// execution
(async () => {
  await .(, '----START---\n');
  while ( > 0) {
    await ();
    ..(`~~> ${} entries to record\r`);
    --;
  }

  await ();
})();

使用 Set 存储数据本身并不是一种坏习惯;你只需要关注程序的内存占用情况。

注意:你可以在 Node.js Diagnostics 仓库中找到此练习的源代码。

现在,让我们执行这个脚本。

node --trace-gc script-fix.mjs

你应该会观察到两件事

  • Mark-sweep 事件出现的频率降低了
  • 内存占用不超过 25MB,而第一个脚本超过了 130MB。

这是很有道理的,因为新版本对内存的压力比第一个版本小。

思考题:你觉得如何改进这个脚本?你可能发现新版本的脚本很慢。如果我们再次使用 Set,并且仅在内存达到特定大小时才将其内容写入文件,会怎么样?

getheapstatistics API 可能会对你有帮助。

附加内容:以编程方式追踪垃圾回收

使用 v8 模块

你可能不想在进程的整个生命周期内都获取追踪信息。在这种情况下,可以在进程内部设置标志。v8 模块提供了一个 API,可以动态设置标志。

import  from 'v8';

// enabling trace-gc
.('--trace-gc');

// disabling trace-gc
.('--notrace-gc');

使用性能钩子

在 Node.js 中,你可以使用性能钩子来追踪垃圾回收。

const {  } = ('node:perf_hooks');

// Create a performance observer
const  = new ( => {
  const  = .()[0];
  /*
  The entry is an instance of PerformanceEntry containing
  metrics of a single garbage collection event.
  For example:
  PerformanceEntry {
    name: 'gc',
    entryType: 'gc',
    startTime: 2820.567669,
    duration: 1.315709,
    kind: 1
  }
  */
});

// Subscribe to notifications of GCs
.({ : ['gc'] });

// Stop subscription
.();

使用性能钩子检查追踪日志

你可以通过 PerformanceObserver 中的回调函数获取 GC 统计信息,其形式为 PerformanceEntry

例如:

{
  "name": "gc",
  "entryType": "gc",
  "startTime": 2820.567669,
  "duration": 1.315709,
  "kind": 1
}
属性解释
name性能条目的名称。
entryType性能条目的类型。
startTime标记性能条目开始时间的高分辨率毫秒时间戳。
duration此条目经过的总毫秒数。
kind发生的垃圾回收操作的类型。
flags关于 GC 的附加信息。

更多信息,你可以参考关于性能钩子的文档