追踪垃圾回收

本指南将介绍垃圾回收追踪的基本原理。

在本指南结束时，您将能够

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

关于垃圾回收器如何工作有很多需要学习，但如果您只学习一件事，那就是当 GC 运行时，您的代码不会运行。

您可能想知道垃圾回收运行的频率和时长，以及结果如何。

设置

为了本指南的目的，我们将使用以下脚本

// script.mjs

import os from 'node:os';

let len = 1_000_000;
const entries = new Set();

function addEntry() {
  const entry = {
    timestamp: Date.now(),
    memory: os.freemem(),
    totalMemory: os.totalmem(),
    uptime: os.uptime(),
  };

  entries.add(entry);
}

function summary() {
  console.log(`Total: ${entries.size} entries`);
}

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

  summary();
})();

即使这里的泄漏很明显，但在实际应用程序的上下文中找到泄漏源可能很麻烦。

使用垃圾回收追踪运行

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

$ node --trace-gc script.mjs

注意：您可以在 Node.js Diagnostics 存储库中的 exercise 找到此示例的源代码。

它应该输出如下内容

[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
0x110008000	Isolate (JS 堆实例)
44 ms	自进程启动以来经过的时间（以毫秒为单位）
Scavenge	GC 的类型 / 阶段
2.4	GC 之前使用的堆大小（以 MB 为单位）
(3.2)	GC 之前的总堆大小（以 MB 为单位）
2.0	GC 之后使用的堆大小（以 MB 为单位）
(4.2)	GC 之后的总堆大小（以 MB 为单位）
0.5 / 0.0 ms (average mu = 1.000, current mu = 1.000)	在 GC 中花费的时间（以毫秒为单位）
allocation failure	GC 的原因

我们将只关注这里的两个事件

Scavenge
Mark-sweep

堆被划分为空间。在这些空间中，我们有一个名为“new”空间，另一个名为“old”空间。

👉 实际上，堆结构有点不同，但为了本文，我们将坚持使用更简单的版本。如果您想了解更多详细信息，我们建议您观看 Peter Marshall 关于 Orinoco 的 talk。

Scavenge

Scavenge 是一种算法的名称，它将对新空间执行垃圾回收。新空间是创建对象的地方。新空间被设计成小而快，以便进行垃圾回收。

让我们想象一个 Scavenge 场景

我们分配了 A、B、C 和 D。
```
| A | B | C | D | <unallocated> |
```
Shell
我们想要分配 E
空间不足，内存已耗尽
然后，触发（垃圾）回收
死对象被回收
活对象将保留
假设 B 和 D 已死
```
| A | C | <unallocated> |
```
Shell
现在我们可以分配 E
```
| A | C | E | <unallocated> |
```
Shell

v8 将把对象提升到旧空间，这些对象在两次 Scavenge 操作后未被垃圾回收。

👉 完整的 Scavenge 场景

Mark-sweep

Mark-sweep 用于从旧空间收集对象。旧空间是幸存下来的对象生活的地方。

此算法由两个阶段组成

Mark：将仍然存活的对象标记为黑色，将其他对象标记为白色。
Sweep：扫描白色对象并将它们转换为可用空间。

👉 事实上，Mark 和 Sweep 步骤要复杂得多。请阅读此 document 了解更多详细信息。

`--trace-gc` 实践

内存泄漏

现在，如果您快速返回到之前的终端窗口：您将在控制台中看到许多 Mark-sweep 事件。我们还看到，事件后收集的内存量微不足道。

现在我们是垃圾回收方面的专家了！我们可以推断出什么？

我们可能存在内存泄漏！但是我们如何才能确定呢？（提醒：在这个例子中很明显，但是实际应用呢？）

但是我们如何才能找到上下文呢？

如何获取错误分配的上下文

假设我们观察到旧空间持续增加。
减少 --max-old-space-size，使总堆大小更接近限制
运行程序直到内存不足。
生成的日志显示失败的上下文。
如果命中 OOM，则将堆大小增加约 10% 并重复几次。如果观察到相同的模式，则表明存在内存泄漏。
如果没有 OOM，则将堆大小冻结为该值 - 打包的堆会减少内存占用和计算延迟。

例如，尝试使用以下命令运行 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

注意：在实际应用程序的上下文中，可能很难在代码中找到泄漏的对象。堆快照可以帮助您找到它。请访问专门介绍堆快照的指南

缓慢

您如何断言是否发生了过多的垃圾回收或者导致了开销？

查看追踪数据，特别是连续回收之间的时间。
查看追踪数据，特别是 GC 中花费的时间。
如果两次 GC 之间的时间少于 GC 中花费的时间，则应用程序严重匮乏。
如果两次 GCS 之间的时间和 GC 中花费的时间都很长，则应用程序可能可以使用更小的堆。
如果两次 GCS 之间的时间远大于 GC 中花费的时间，则应用程序相对健康。

修复泄漏

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

让我们稍微修改一下我们的脚本

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

let len = 1_000_000;
const fileName = `entries-${Date.now()}`;

async function addEntry() {
  const entry = {
    timestamp: Date.now(),
    memory: os.freemem(),
    totalMemory: os.totalmem(),
    uptime: os.uptime(),
  };
  await fs.appendFile(fileName, JSON.stringify(entry) + '\n');
}

async function summary() {
  const stats = await fs.lstat(fileName);
  console.log(`File size ${stats.size} bytes`);
}

// execution
(async () => {
  await fs.writeFile(fileName, '----START---\n');
  while (len > 0) {
    await addEntry();
    process.stdout.write(`~~> ${len} entries to record\r`);
    len--;
  }

  await summary();
})();

使用 Set 存储数据根本不是一个坏习惯；您只需要关心程序的内存占用量。

注意：您可以在 Node.js Diagnostics 存储库中的 exercise 找到此示例的源代码。

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

node --trace-gc script-fix.mjs

您应该观察到两件事

Mark-sweep 事件出现频率较低
内存占用量不超过 25MB，而第一个脚本超过 130MB。

这是非常有意义的，因为新版本对内存的压力小于旧版本。

要点：您认为如何改进这个脚本？您可能看到新版本的脚本很慢。如果我们再次使用 Set 并且仅在内存达到特定大小时才将其内容写入文件呢？

getheapstatistics API 可以帮助您。

奖励：以编程方式追踪垃圾回收

使用 `v8` 模块

您可能希望避免从进程的整个生命周期获取追踪信息。在这种情况下，请从进程内部设置标志。 v8 模块公开了一个 API 来动态设置标志。

import v8 from 'v8';

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

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

使用性能钩子

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

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

// Create a performance observer
const obs = new PerformanceObserver(list => {
  const entry = list.getEntries()[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
obs.observe({ entryTypes: ['gc'] });

// Stop subscription
obs.disconnect();

使用性能钩子检查追踪

您可以从 PerformanceObserver 中的回调获取 GC 统计信息作为 PerformanceEntry。

例如

PerformanceEntry {
  name: 'gc',
  entryType: 'gc',
  startTime: 2820.567669,
  duration: 1.315709,
  kind: 1
}

属性	解释
name	性能条目的名称。
entryType	性能条目的类型。
startTime	高分辨率毫秒时间戳标记性能条目的开始时间。
duration	此条目经过的总毫秒数。
kind	发生的垃圾回收操作的类型。
flags	关于 GC 的补充信息。

更多信息，您可以参考关于性能钩子的文档。

Node.js 简介