何を残し、何で人を起こすのか

一言でいうと

ループの遅延とヒープの使用量は、プロセスの内部でしか正確に見えません。外から見るCPU使用率は、塞がったプロセスと忙しいプロセスを区別できません。そのためメトリクスを内部から取り出して残し、アラートは平均ではなく、テールと継続時間に設定します。

なぜ必要なのか

ループが塞がっている間、CPU使用率は100%に近くなります。ところが、仕事をとてもうまくこなしているときも100%です。外から見るメトリクスだけでは2つを区別できず、そのため「CPUが高い」というアラートは、この事故について何も教えてくれません。逆に、ループが塞がって応答できないのにCPUは閑散としている場合もあります。スレッドプールが満杯になって待っているときです。

レイテンシのログも同じように不十分です。応答時間はすでに起きたことの結果で、その結果を見て原因をたどるには、「同じ時刻にほかのリクエストも遅かったか」を人が目で突き合わせる必要があります。プロセスの内部でループが止まった時間そのものを測っておけば、その段階を飛ばせます。遅くなったリクエストの一覧の代わりに、「12時04分20秒にループが410ms止まった」という1行が残ります。

どう動くのか

Nodeは、この目的のための道具を2つ提供しています。1つは前に見たperf_hooks.monitorEventLoopDelay()で、もう1つはperformance.eventLoopUtilization()です。2つは別々の問いに答えます。

monitorEventLoopDelay()はどれだけ遅れたかを分布として返します。ヒストグラムなのでpercentile(99)とmaxをすぐ取り出せ、値はナノ秒で、サンプリング間隔のデフォルト値は10msです(1つ目のモジュールで見た下限はここから来ます)。定期的に読んでreset()すると、区間ごとの分布になります。

eventLoopUtilization()はどれだけ忙しかったかを返します。公式ドキュメントはこの値を「イベントループがイベントプロバイダー(例: epoll_wait)の外で過ごした時間の割合」と説明しています(perf_hooks)。CPU使用率と似て見えますが、別の値です。ループの統計だけを見て、CPUは見ません。前回の呼び出しの結果を引数として渡すと、その間の変化量を返すので、区間ごとの利用率を得るのに自分で引き算をする必要がありません。このAPIはNode 14.10.0で導入されました。

メモリ側はprocess.memoryUsage()が担当します。rssはOSがこのプロセスに割り当てている物理メモリで、heapUsedはV8が実際に使っている量です。背圧の事故では2つが一緒に上がり、特にストリームのバッファーに溜まったBufferはexternal側にも見えます。4つ目のモジュールの実測で、背圧を無視した側はRSSが131MB増え、守った側は増えませんでした。同じコード、同じ入力で、1行の違いです。

const h = monitorEventLoopDelay({ resolution: 20 });
h.enable();
setInterval(() => {
  const p99ms = h.percentile(99) / 1e6;      // 나노초로 나온다
  const maxMs = h.max / 1e6;
  const rssMB = process.memoryUsage().rss / 1048576;
  h.reset();                                  // 다음 구간을 위해 비운다
  // 여기서 남긴다 — 로그 한 줄이든 지표 노출이든
}, 10000);

現場での姿

アラートをどこに設定するかが、実際に難しいところです。3つを守れば、おおむね静かで役に立つアラートになります。

1つ目は、平均に設定しないことです。 1つ目のモジュールで見たとおり、300msの停止が1回あっても平均はほとんど動きません。p99とmaxを使います。

2つ目は、一度跳ねただけで人を起こさないことです。 起動直後のコンパイル、ときどき動く大きなGC、デプロイ直後のキャッシュ充填で、大きな値が1回ずつ出ます。「p99がしきい値を超えた状態が5分以上続いたら」のように継続時間を条件に入れます。1回の跳ねは記録として残し、人は起こしません。

3つ目は、しきい値を測って決めることです。 このコースのラボで各自がベースラインを測ったのは、そのためです。静かな状態のp50がいくつか、通常の負荷でp99がどこにあるかを知らなければ、しきい値は推測になります。ベースラインの何倍、または応答時間バジェットの何分の1といった根拠があってこそ、あとで人がその数字を直せます。

メモリのアラートも同じ原則です。絶対値より増加速度のほうがよいです。背圧の事故は上限まで線形に上がるので、4つ目のモジュールで作った算数で「いまの速度なら何分後」を計算しておけば、上限に達する前に手を打てます。上限に達したあとに来るアラートは、すでに再起動されたプロセスへの訃報に近いものです。

最後に、これらのメトリクスはプロセスごとに別々に見る必要があります。ワーカーを複数立ち上げたりクラスターで動かしたりすると、1つのプロセスだけが塞がっても全体の平均は問題なく見えます。メトリクスにプロセスの識別子を付けないと、4つ目のモジュールで見たものと同じ種類のごまかしが生じます。

次のクイズで確認すること

ループの遅延と利用率がそれぞれどんな問いに答えるのか、なぜ外から見るCPU使用率ではこの事故を見分けられないのか、そしてアラートを平均ではなくテールと継続時間に設定する理由を確認します。前の4つのモジュールで自分で測った数字が、そのまま根拠になります。