POSTD PRODUCED BY NIJIBOX

POSTD PRODUCED BY NIJIBOX

ニジボックスが運営する
エンジニアに向けた
キュレーションメディア

Alex Kras

本記事は、原著者の許諾のもとに翻訳・掲載しております。

目次

Something you might want to bookmark: Simple Guide to Finding a JavaScript Memory Leak in Node.js by @akras14 https://t.co/oRyQboa8Uw

— Node.js (@nodejs) January 6, 2016

注釈:お気に入りに登録してください。
Simple Guide to Finding a JavaScript Memory Leak in Node.js (Node.jsでのJavaScriptメモリリーク発見簡単ガイド)

@akras14 http://www.alexkras.com/simple-guide-t…

初めに

数カ月前、私は、Node.jsでメモリリークのデバッグをしなければなりませんでした。このテーマに役立つ数多くの記事を見つけましたが、その一部をじっくり読み終えた後でさえ、問題のデバッグのために具体的に何をすれば良いのかまだよく分かりませんでした。

この記事の目的は、Node.jsでメモリリークを発見するための簡単ガイドを提供することです。分かりやすい方法を1つに絞って説明することが、(私が思うに)Node.jsでのあらゆるメモリリークデバッグの第一歩となるはずです。場合によっては、この方法は十分ではないかもしれません。参考になるかもしれない他のリソースへのリンクも張っておきます。

最小限の理論

JavaScriptは、ガベージコレクションを行う言語です。従って、Node.jsのプロセスで使われるメモリの全ては、V8 JavaScriptエンジンによって、自動的に割り当てられたり、割り当てを解除されたりします。

V8は、どのようにしてメモリの割り当てを解除すべきタイミングを知るのでしょうか?V8は、プログラムの中のルートノードから始まる全ての変数について、変数のグラフを保持します。JavaScriptには、論理値(Boolean)、文字列(String)、数値(Number)、オブジェクト(Object)という4つのデータ型があります。最初の3つは基本型で、割り当てられたデータを持ち続けるだけですが(例えばテキストの文字列)、オブジェクト(Object)とJavaScriptにあるその他全てのものは、オブジェクトで(例えば配列も)、他のオブジェクトへの参照(ポインタ)を保持できます。

memory-graph
注釈:(左から)ルートノード、回収可能

定期的に、V8はメモリグラフを確認し、ルートノードから到達できないデータグループを特定しようとします。ルートノードから到達できなければ、V8はそのデータはもう使われることがないと判断し、メモリを解放します。このプロセスが ガベージコレクション と呼ばれるものです。

いつメモリリークは発生するのか

JavaScriptでメモリリークが発生するのは、既に必要とされていないデータがまだルートノードから到達可能な場合です。この状態では、V8はそのデータがまだ使われていると判断し、メモリを解放しないのです。 メモリリークをデバッグするためには、誤って保持されているデータを特定し、V8がクリーンアップできるようにする必要があります。

また、ガベージコレクションは、常に稼働しているものではないことに注意しなければなりません。通常、V8は、適切な時期にガベージコレクションを開始します。例えば、定期的に、あるいは、空きメモリが減ってきたことを検知した時に、ガベージコレクションを開始します。Node.jsでは、各プロセスに使えるメモリ量が限られているため、V8は、メモリを効率的に使う必要があるのです。

node-error
注釈:Node.jsは、メモリ不足です。
alexkras.comにアクセスして、メモリリークを確認してください。

後者の 緊急ガベージコレクションは、重大なパフォーマンス低下の原因 になり得ます。

多くのメモリリークを起こしているアプリケーションがあるとしましょう。すぐに、Node.jsのプロセスは、メモリが不足し始めます。これにより、V8は、緊急ガベージコレクションを開始します。しかし、ほとんどのデータはまだルートノードから到達できる状態で、メモリ解放できる余地が少なく、ほぼそのままとなります。

遅かれ早かれ、Node.jsのプロセスは再びメモリ不足に陥り、再度ガベージコレクションを開始します。気付かないうちに、アプリケーションは、連続ガベージコレクションサイクルに入り、何とかプロセスを機能させようとし続けます。V8は、多くの時間をガベージコレクションに費やし、実際のプログラム実行に使われるリソースがほとんど残りません。

ステップ1. 問題の再現と確認

前述したように、V8 JavaScriptエンジンは、ガベージコレクション実行のタイミングを決定する複雑なロジックを持っています。その点を考慮すると、たとえNode.jsのプロセスでメモリの使用量が増加し続けるのを目にしたとしても、 それがメモリリークのせいだと分かるのは、ガベージコレクションが実行されて、 使われていないメモリが解放された後です。

ありがたいことに、Node.jsでは、手動でもガベージコレクションを開始することができますので、メモリリークを確認する際には、まずこれを実行します。 --expose-gc フラグを付けてNode.js を実行するだけです。例えば、 node --expose-gc index.js です。Node.jsがこのモードで実行されていれば、プログラムから global.gc() を呼び出すことによって、いつでもガベージコレクションをプログラムで開始することができます。

また、 process.memoryUsage().heapUsed を呼び出すことによって、プロセスで使われているメモリ量をチェックすることもできます。

手動でガベージコレクションを開始し、使用中のヒープを確認することによって、実際にプログラム内でメモリリークが起こっているかどうかを判断することができるのです。

サンプルプログラム

簡単なメモリリークプログラムを作りました。こちらでご覧いただけます。
https://github.com/akras14/memory-leak-example

これをcloneして、 npm install を実行してから、 node--expose-gc index.js を実行すると、実際の動作を確認することができます。

"use strict";
require('heapdump');

var leakyData = [];
var nonLeakyData = [];

class SimpleClass {
  constructor(text){
    this.text = text;
  }
}

function cleanUpData(dataStore, randomObject){
  var objectIndex = dataStore.indexOf(randomObject);
  dataStore.splice(objectIndex, 1);
}

function getAndStoreRandomData(){
  var randomData = Math.random().toString();
  var randomObject = new SimpleClass(randomData);

  leakyData.push(randomObject);
  nonLeakyData.push(randomObject);

  // cleanUpData(leakyData, randomObject); //<-- Forgot to clean up
  cleanUpData(nonLeakyData, randomObject);
}

function generateHeapDumpAndStats(){
  //1. Force garbage collection every time this function is called
  try {
    global.gc();
  } catch (e) {
    console.log("You must run program with 'node --expose-gc index.js' or 'npm start'");
    process.exit();
  }

  //2. Output Heap stats
  var heapUsed = process.memoryUsage().heapUsed;
  console.log("Program is using " + heapUsed + " bytes of Heap.")

  //3. Get Heap dump
  process.kill(process.pid, 'SIGUSR2');
}

//Kick off the program
setInterval(getAndStoreRandomData, 5); //Add random data every 5 milliseconds
setInterval(generateHeapDumpAndStats, 2000); //Do garbage collection and heap dump every 2 seconds

このプログラムは、以下のような動きをします。

  1. 5ミリ秒ごとに、ランダムにオブジェクトを生成し、 leakyDatanonLeakyData という名前の2つの配列に格納します。nonLeakyData配列は5ミリ秒ごとにクリーンアップしますが、leakyData配列のクリーンアップを” 忘れます “。
  2. 2秒ごとに、プログラムがメモリの使用量を出力します。(それに続くヒープダンプの生成については、次のセクションで詳述します)

node --expose-gc index.js (または npm start )でプログラムを実行すると、メモリに関するデータの出力が始まります。1-2分実行して、 Ctr + c で止めましょう。

メモリが急速に増加しているのが分かるでしょう。2秒ごと、それもメモリの状態を得る直前にガベージコレクションをしているにもかかわらずです。

//1. Force garbage collection every time this function is called
try {
  global.gc();
} catch (e) {
  console.log("You must run program with 'node --expose-gc index.js' or 'npm start'");
  process.exit();
}

//2. Output Heap stats
var heapUsed = process.memoryUsage().heapUsed;
console.log("Program is using " + heapUsed + " bytes of Heap.")

このデータの出力は、このような感じです。

Program is using 3783656 bytes of Heap.
Program is using 3919520 bytes of Heap.
Program is using 3849976 bytes of Heap.
Program is using 3881480 bytes of Heap.
Program is using 3907608 bytes of Heap.
Program is using 3941752 bytes of Heap.
Program is using 3968136 bytes of Heap.
Program is using 3994504 bytes of Heap.
Program is using 4032400 bytes of Heap.
Program is using 4058464 bytes of Heap.
Program is using 4084656 bytes of Heap.
Program is using 4111128 bytes of Heap.
Program is using 4137336 bytes of Heap.
Program is using 4181240 bytes of Heap.
Program is using 4207304 bytes of Heap.

このデータをプロットすると、メモリの使用量の増大はもっと明確になります。

with-memory-leak
注意:データプロットの方法を知りたい場合は、このまま読み進めてください。不要の場合は、次のセクションに進んでください。

出力されたデータは、JSONファイルに保存し、それを読み込んでPythonの数行のプログラムでプロットしています。混乱を避けるために別のブランチに入れていますが、ここで確認していただけます。
https://github.com/akras14/memory-leak-example/tree/plot

関連する箇所は、こちらです。

var fs = require('fs');
var stats = [];

//--- skip ---

var heapUsed = process.memoryUsage().heapUsed;
stats.push(heapUsed);

//--- skip ---

//On ctrl+c save the stats and exit
process.on('SIGINT', function(){
  var data = JSON.stringify(stats);
  fs.writeFile("stats.json", data, function(err) {
    if(err) {
      console.log(err);
    } else {
      console.log("\nSaved stats to stats.json");
    }
    process.exit();
  });
});

そして

#!/usr/bin/env python

import matplotlib.pyplot as plt
import json

statsFile = open('stats.json', 'r')
heapSizes = json.load(statsFile)

print('Plotting %s' % ', '.join(map(str, heapSizes)))

plt.plot(heapSizes)
plt.ylabel('Heap Size')
plt.show()

plot ブランチは、チェックアウトして、通常通りにプログラムを実行することもできます。プログラムが終わったら、 python plot.py を実行して、プロットを生成してください。また実行の前にはコンピュータに、 Matplotlib ライブラリをインストールしておく必要があります。

他にも、エクセルを使ってデータをプロットすることができます。

ステップ2. 最低3回のヒープダンプ採取

さあ、これで問題が再現できました。次は何をするのでしょうか。今度は、問題がどこにあるのかを突き止め、手直ししなければいけません。

前出のサンプルプログラムの以下の部分にお気付きかもしれませんね。

require('heapdump');
// ---skip---

//3. Get Heap dump
process.kill(process.pid, 'SIGUSR2');

// ---skip---

ここでは以下のサイトにあるnode-heapdump モジュールを使っています。
https://github.com/bnoordhuis/node-heapdump

node-heapdumpを使用するための準備は以下の通りです。

  1. モジュールをインストールする
    2.プログラムの先頭に配置する
    3.Unix系プラットホーム上で kill -USR2 {{pid}} を呼び出す

もし kill という要素を初めて見たのであれば、これはUNIXのコマンドで、あらゆる実行プロセスに対し、(特に)カスタムシグナル(ユーザ定義シグナルともいう)を送ることができるものです。Node.jsのheapdumpは、 ユーザシグナル2 、すなわち -USR2 とプロセスIDを受け取ると、そのプロセスのヒープダンプを採取するように設定されています。

サンプルプログラムの中では、 process.kill(process.pid, 'SIGUSR2'); を実行させることにより、 kill -USR2 {{pid}} コマンドを自動化しています。ここで process.killkill コマンドのためのNodeラッパーです。また SIGUSR2 はNode.jsでの -USR2 の呼び方で、 process.pid は現在のNode.jsのプロセスIDを得ます。完璧なヒープダンプを採取するために、ガベージコレクションの後、その都度このコマンドを実行します。

process.kill(process.pid, 'SIGUSR2'); はWindows系プラットホーム上で動きませんので、代わりに heapdump.writeSnapshot() を実行してください。

この例は heapdump.writeSnapshot() があれば、少しばかり簡単なのかもしれません。しかし、Unix系プラットホーム上で kill -USR2 {{pid}} シグナルを使えば、ヒープダンプを開始することができ、役に立つということをお伝えしたかったのです。

次のセクションでは、メモリリークを分離するために、生成されたヒープダンプを活用する方法についてお話しします。

ステップ3. 問題の発見

ステップ2では、頻繁にヒープダンプを生成しましたが、 必要なのは少なくとも3カ所です 。理由はすぐに分かるでしょう。

ヒープダンブを入手したら、次はGoogle Chromeを使って、Chromeの開発者ツールを開いてください(Windowsの場合はF12キー、Macの場合はCommand + Option + iキーで開きます)。

開発者ツールのナビゲータの”Profiles”タブを選び、画面の一番下にある”Load”ボタンを押します。そして、採取した最初のヒープダンプを探して、選択します。以下の手順に従って、ヒープダンプをChromeのビューにロードします。

続けて、残りの2つのファイルもビューにロードします。例えば、採取したヒープダンプの最後の2つを使っても構いません。最も重要なのは、採取した順番通りにヒープダンプをロードすることです。”Profiles”タブは以下のようになっていると思います。

3-Heap-Dumps
ヒープの容量が時間の経過とともに少しずつ増えていることが、上の図からお分かりになるでしょう。

3点 ヒープダンプ法

ヒープダンプをロードしたら、”Profiles”タブにサブビューがたくさん増えているのを目にして、途方に暮れてしまうでしょう。しかし、その中で特に役立つと思ったビューが1つあります。

最後に採取したヒープダンプをクリックするとすぐに、”Summary”ビューに移動します。”Summary”ドロップダウンの左側に、”All”と書かれた別のドロップダウンがあるのに気付くはずです。そのドロップダウンをクリックします。また、下の図を参考にして、“Objects allocated between heapdump-(最初のヒープマップ) and heapdump-(最後から2番目のヒープマップ)”を選んでください。

3-Heap-Dump-View

これで、最初のヒープダンプと最後から2番目のヒープダンプの間のどこかで割り当てられた全てのオブジェクトが表示されます。ガベージコレクションによって収集されているべきオブジェクトが、最後のヒープダンプの中にいまだに留まっているというこの事実は、問題の原因であり、調査しなければなりません。

実際はなかなか見事な機能ですが、あまり直感的な見つけ方ではないし、いとも簡単に見落としてしまいます。

少なくとも最初は、”(string)”の様にカッコの中にあるものは無視する

サンプルアプリケーションのアウトラインステップが完了した後は、以下のようなビューが作られて終了です。

shallow size がオブジェクト自体の大きさを表し、 retained size サイズがオブジェクトとその子オブジェクト全体の大きさを表すことにご注意ください。

memory-leak

どうやら、あるべきではない5つのエントリが、私の最新のスナップショットに保たれているようです。その5つとは、(array)、(compiled code)、(string)、(system)、そしてSimpleClassです。

この5つの中で、 SimpleClass だけは見覚えがあるでしょう。サンプルアプリケーションの、以下のコードから発生したものだからです。

var randomObject = new SimpleClass(randomData);

最初に(array)や(string)のエントリを調べたいという誘惑にかられるかもしれません。Summaryにある全てのオブジェクトは、コンストラクタの名前でグループ化されています。配列や文字列の場合はJavaScriptエンジン内部のコンストラクタです。あなたのプログラムが、明らかにこれらのコンストラクタで作られたデータを保持し続けていますが、そこに踏み込んで調査しようとすると多くのノイズも得てしまうため、メモリリークの原因を見つけるのがさらに難しくなってしまうのです。

ですから、まずは飛ばしてしまう方が賢明です。その代わり、サンプルアプリケーションの SimpleClass のコンストラクタのように、明らかに怪しいものがないか調べてみましょう。

SimpleClassコンストラクタのドロップダウンアローをクリックし、結果リストから作られたオブジェクトをどれか選んでみます。するとウィンドウの下の方に保持のためのパスが現れます(上の図を見てください)。そこから、leakyData配列がデータを離さないことがとても簡単に検出できます。

もしもあなたの使っているアプリケーションが、サンプルほど恵まれていなかったら、内部のコンストラクタ(例えば文字列)を調べ、そこからメモリリークの原因を明らかにする必要があるかもしれません。その場合のコツは、しばしばいくつかの内部のコンストラクタグループに現れる値のグループを特定し、メモリリークの疑いを示す手がかりとして使うことです。

例えば、サンプルアプリケーションの場合は、ランダムな数字を文字列にしただけに見えるような文字列をいくつも目にするでしょう。それらの保持用のパスを調べれば、Chromeの開発者ツールがleakyData配列を示してくれるでしょう。

ステップ4問題解決の確認

怪しいメモリリークを特定し、それを修正したら、ヒープの使い方に大きな違いが感じられるはずです。

例えば、サンプルアプリケーションで、次の行のコメント化を解除したとします。

cleanUpData(leakyData, randomObject); //<-- Forgot to clean up

そしてステップ1で説明したアプリケーションをもう一度実行すると、以下のような結果が出力されます。

Program is using 3756664 bytes of Heap.
Program is using 3862504 bytes of Heap.
Program is using 3763208 bytes of Heap.
Program is using 3763400 bytes of Heap.
Program is using 3763424 bytes of Heap.
Program is using 3763448 bytes of Heap.
Program is using 3763472 bytes of Heap.
Program is using 3763496 bytes of Heap.
Program is using 3763784 bytes of Heap.
Program is using 3763808 bytes of Heap.
Program is using 3763832 bytes of Heap.
Program is using 3758368 bytes of Heap.
Program is using 3758368 bytes of Heap.
Program is using 3758368 bytes of Heap.
Program is using 3758368 bytes of Heap.

もしもこのデータをプロットしたら、以下のようになります。

without-memory-leak

やりました!メモリリークはなくなりました。

メモリ使用の最初のスパイクが残っていることに注意してください。これは、プログラムが安定するのを待つ間は普通のことです。分析の際に、このスパイクをメモリリークと解釈しないように注意してください。

他のリソースへのリンク

Chromeの開発者ツールを使ったメモリのプロファイリング

この記事に書いたことのほとんどは、上のビデオから引用しました。この記事が存在する唯一の理由は、私がこのビデオを2週間のコースの間3回繰り返し見て、キーポイント(だと私が信じているもの)を特定しなくてはならなかったからで、他の人たちにはこの発見のプロセスを簡単にしてもらいたいと思ったからです。

この記事の補足として、上のビデオを見ることをお勧めします。

その他のお役立ちツール-memwatch-next

これは、また別のステキなツールで、ここで挙げておく価値があると思います。このための論法は、 こちら で読むことができます(短い記事ですし、時間を割く価値はあります)。

あるいは、直接こちらのリポジトリをご覧ください。 https://github.com/marcominetti/node-memwatch

クリックを省略するために、 npm install memwatch-next を使ってインストールすることができます。

そして、2つのイベントと一緒に使います。

var memwatch = require('memwatch-next');
memwatch.on('leak', function(info) { /*Log memory leak info, runs when memory leak is detected */ });
memwatch.on('stats', function(stats) { /*Log memory stats, runs when V8 does Garbage Collection*/ });

//It can also do this...
var hd = new memwatch.HeapDiff();
// Do something that might leak memory
var diff = hd.end();
console.log(diff);

最後のコンソールログは次のようなものを出力し、どんなタイプのオブジェクトがメモリの中で増えたのかを知らせてくれます。

{
  "before": { "nodes": 11625, "size_bytes": 1869904, "size": "1.78 mb" },
  "after":  { "nodes": 21435, "size_bytes": 2119136, "size": "2.02 mb" },
  "change": { "size_bytes": 249232, "size": "243.39 kb", "freed_nodes": 197,
    "allocated_nodes": 10007,
    "details": [
      { "what": "String",
        "size_bytes": -2120,  "size": "-2.07 kb",  "+": 3,    "-": 62
      },
      { "what": "Array",
        "size_bytes": 66687,  "size": "65.13 kb",  "+": 4,    "-": 78
      },
      { "what": "LeakingClass",
        "size_bytes": 239952, "size": "234.33 kb", "+": 9998, "-": 0
      }
    ]
  }
}

すばらしいですね。

Developer.chrome.comの、JavaScriptのメモリのプロファイリング

https://developer.chrome.com/devtools/docs/javascript-memory-profiling

これは必読です。ここで触れた全てのテーマとそれ以上のものをカバーしていますし、より詳しく、より正確に書かれています。

下に挙げた、Addy Osmaniによるトークをお見逃しなく。デバッグのコツやリソースをたくさん紹介しています。

スライドは、 こちら から入手できます。サンプルコードは、 こちら です。

まとめ

  1. メモリリークを再現し特定しようとする時は、ガベージコレクションを手動で開始させます。 --expose-gc フラグを使ってNode.jsを実行し、プログラムから global.gc() を呼び出してください。
  2. https://github.com/bnoordhuis/node-heapdump を使って、少なくとも3回、ヒープダンプを採取しましょう。
  3. メモリリークを分離させるために、3点ヒープダンプ法を使います。
  4. メモリリークがなくなったことを確認します。
  5. 問題解決です。