追踪垃圾回收

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

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

在您的 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();
})();

JavaScript复制到剪贴板

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

使用垃圾回收追踪运行

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

$ node --trace-gc script.mjs

Bash复制到剪贴板

注意：您可以在 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

Bash复制到剪贴板

难以理解？也许我们应该回顾一些概念并解释 `--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

Bash复制到剪贴板

令牌值	解释
13973	正在运行进程的 PID
0x110008000	隔离区（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

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

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

Scavenge

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

让我们想象一个 Scavenge 场景

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

v8 会将对象提升到老空间，而不是在两次 Scavenge 操作后被垃圾回收。

👉 完整的 Scavenge 场景

Mark-sweep

标记清除用于从老空间收集对象。老空间是新空间中幸存的对象所在的地方。

该算法由两个阶段组成

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

👉 事实上，标记和清除步骤要复杂一些。请阅读此文档以了解更多详细信息。

`--trace-gc` 在行动中

内存泄漏

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

现在我们已经成为垃圾回收的专家！我们可以得出什么结论？

我们可能存在内存泄漏！但我们如何确定呢？（提醒：在这个例子中非常明显，但现实世界的应用程序呢？）

但我们如何确定上下文？

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

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

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

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

Bash复制到剪贴板

您应该会遇到 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 [...]

Bash复制到剪贴板

现在，尝试将其设置为 100mb

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

Bash复制到剪贴板

您应该会遇到类似的情况，唯一的区别是最后一次 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

Bash复制到剪贴板

注意：在实际应用程序中，在代码中查找泄漏的对象可能很麻烦。堆快照可以帮助您找到它。访问专门用于堆快照的指南

缓慢

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

查看跟踪数据，特别是连续收集之间的时间。
查看跟踪数据，特别是围绕在 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();
})();

JavaScript复制到剪贴板

使用 Set 来存储数据并不是一个坏习惯；你只需要关心程序的内存占用。

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

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

node --trace-gc script-fix.mjs

你应该观察到两件事

标记清除事件出现的频率更低
内存占用不会超过 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');

JavaScript复制到剪贴板

使用性能钩子

在 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();

JavaScript复制到剪贴板

使用性能钩子检查跟踪

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

例如

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

TypeScript复制到剪贴板

属性	解释
name	性能记录的名称。
entryType	性能记录的类型。
startTime	高精度毫秒时间戳，标记性能记录的开始时间。
duration	此记录的总毫秒数。
kind	发生的垃圾回收操作类型。
flags	关于 GC 的附加信息。

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

下一步Node.js 简介