追蹤垃圾回收

本指南將介紹垃圾回收追蹤的基礎知識。

在閱讀本指南結束時，您將能夠

在您的 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 診斷存儲庫的練習中找到此練習的源代碼。

它應該輸出類似以下的內容

[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 毫秒	進程開始運行以來的時間（以毫秒為單位）
掃描	GC 的類型/階段
2.4	GC 前使用的堆大小（以 MB 為單位）
(3.2)	GC 前的總堆大小（以 MB 為單位）
2.0	GC 後使用的堆大小（以 MB 為單位）
(4.2)	GC 後的總堆大小（以 MB 為單位）
0.5 / 0.0 毫秒（平均 mu = 1.000，當前 mu = 1.000）	在 GC 中花費的時間（以毫秒為單位）
分配失敗	GC 的原因

我們這裡只關注兩個事件

掃描
標記清除

堆被劃分為空間。其中一個是"新"空間，另一個是"舊"空間。

👉 實際上，堆結構有點不同，但我們將在本文中堅持使用較簡單的版本。如果您想要更多細節，我們鼓勵您觀看 Peter Marshall 的這個關於 Orinoco 的演講。

掃描

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 场景

標記清除

標記掃描用於收集舊空間的物件。舊空間是指那些在新空間中存活下來的物件所在之處。

此演算法由兩個階段組成

標記：將仍然存活的物件標記為黑色，其他物件標記為白色。
掃描：掃描白色物件並將其轉換為空白空間。

👉 事實上，標記和掃描步驟更為詳細。請閱讀此文件以獲得更多詳細資訊。

`--trace-gc` 的運作

記憶體洩漏

現在，如果您快速返回到先前的終端視窗：您將在控制台中看到許多Mark-sweep 事件。我們還看到事件後回收的記憶體量微不足道。

現在我們是垃圾回收的專家了！我們可以得出什麼結論？

我們可能有一個記憶體洩漏！但是我們如何確定呢？（提醒：在此示例中，這相當明顯，但在現實世界的應用程序中呢？）

但是我們如何找出上下文？

如何獲取壞的配置上下文

假設我們觀察到舊空間持續增加。
將--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中花費的時間，則應用程序嚴重受餓。
如果兩次GC之間的時間和在GC中花費的時間非常長，則應用程序可能可以使用較小的堆。
如果兩次GC之間的時間遠大於在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 診斷存儲庫的練習中找到此練習的源代碼。

現在，讓我們執行此腳本。

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複製到剪貼板

屬性	解釋
名稱	性能進入的名稱。
entryType	性能進入的類型。
startTime	高解析度的毫秒時間戳記，標記了性能進入的開始時間。
duration	此進入所經過的總毫秒數。
kind	發生的垃圾回收操作類型。
flags	關於垃圾回收的附加信息。

更多信息，請參閱有關性能鉤子的文檔。

下一步Node.js 簡介