Cloud Profilerを使ってNode.jsのメモリリークの原因を特定する

Node.js のサーバーにおいて、メモリリークの原因の特定に Cloud Profiler を使って解決したので経緯などを含めて紹介します。

現象

Node.js のサーバーで、デプロイ後にメモリ使用量が増えていき、一定を超えると戻るという現象が発生していました。

このメモリ使用量が落ちているところのログを確認したところ

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

というログとともにプロセスが再起動していることがわかりました。明らかにメモリリークしてそうです。

原因をつきとめる

まずは現象を再現するために、ローカルやテスト環境に負荷をかけて試してみたんですが、再現できませんでした。そこで本番環境でプロファイルをとって原因を探ろうとしました。Node.jsでは以下のようなコードで heap snapshot を取れます。

import { writeHeapSnapshot } from "node:v8";

writeHeapSnapshot(pathToFile);

しかし、この v8 モジュールの heap snapshot を取る機能、調べた限り同期 API しかないうえに実行にも数秒〜数十秒かかり、その間すべてのリクエストがブロックされてしまいます。なので本番環境で気軽に実行することはできません^[1]。

そこで SRE チームに相談したところ、Cloud Profiler を使ってみるといいのではと助言をもらいました。Cloud Profiler は Google Cloud で提供されているプロファイリングのサービスで、Node.jsもサポートされています。

https://cloud.google.com/profiler/docs/about-profiler?hl=en

Cloud Profiler を使うの簡単で、npm でインストールしたら以下のコードを仕込むだけです。

$ npm install @google-cloud/profiler

require("@google-cloud/profiler").start({
  serviceContext: {
    service: serviceName,
    version: releaseVersion,
  },
});

これでデプロイしてしばらくすると以下のような heap のプロファイルが見れるようになります。

このプロファイルを見てみると、@grpc/grpc-js で多くメモリが増えていることがわかりました。

@grpc/grpc-js の依存を確認してみると @google-cloud/pubsub が利用しており、リクエストごとに PubSub のインスタンを作っているいかにも怪しいコードを発見しました。以下は簡略化した疑似コードです。

import { PubSub } from "@google-cloud/pubsub";

export async function publish({ projectId, topic, message }) {
  const client = new PubSub({ projectId });
  const messageId = await client
    .topic(topic)
    .publishMessage({ json: message });
  return messageId;
}

インスタンスを初期化したときにコネクションが貼られて閉じられてないのでコネクションが増え続けているのではないかというところにあたりをつけました。

テスト環境で再現を試みたときの負荷をかけるシナリオを確認してみると、このコードを通るシナリオがなかったため、シナリオを追加したうえで負荷をかけてみてばっちり再現した様子が以下のグラフです。

問題を修正する

コードを修正して、PubSubのインスタンを使い回すように修正します。もしくは毎回closeしてもいいと思います。

const clients = new Map();

// projectIdごとにPubSub clientをキャッシュして返す
function getClient(projectId) {
  if (clients.has(projectId)) {
    return clients.get(projectId)!;
  }

  const client = new PubSub({ projectId });
  clients.set(projectId, client);

  return client;
}

export async function publish({ projectId, topic, message }) {
  const client = getClient(projectId);
  const messageId = await client
    .topic(topic)
    .publishMessage({ json: message });
  return messageId;
}

これで再度負荷をかけてみるときれいに横ばいなグラフを描けました。

これを本番にデプロイしてメモリ使用量が増加しないことも確認できました。

まとめ

Node.jsでメモリリークの調査において Cloud Profiler が便利だったので事例として紹介しました。今回は負荷試験のシナリオの不備でテスト環境で再現できなかったため、本番でプロファイルを取るために利用しましたが、導入も簡単にできますし、パフォーマンス面でのオーバーヘッドもほとんどなく、本番環境で気軽にプロファイルを取れるのは非常に便利でした。

脚注

1. なんらかの方法でpodをリクエストから切り離すなどすれば可能かも