ログを読む技術について

ログを読むのは地味な仕事だと思われがちだ。 だが私は、ログを読むことを立派な低レイヤの技術だと考えている。

ログは「症状」であって「原因」ではない

ログに並ぶのは、たいてい症状だ。 レイテンシが上がった、メモリが増えた、応答が詰まった。

症状から原因へ降りていくとき、必要になるのは想像力ではなく、システムが何を出力できるかの知識だ。 カーネルが何を見ていて、何を数えているかを知らなければ、ログは文字列のままで終わる。

ページフォルトを「読む」

たとえば長時間動くプロセスのメモリ挙動。 /proc/<pid>/stat やカーネルのカウンタを時系列で並べると、ページフォルトの回数が見えてくる。

$ ps -o min_flt,maj_flt,rss -p 4123
 MINFLT  MAJFLT    RSS
 482931      27 1284400
$ # しばらく後にもう一度
$ ps -o min_flt,maj_flt,rss -p 4123
 MINFLT  MAJFLT    RSS
 691204     219 1532880

maj_flt(メジャーフォルト、ディスクからのページ読み込みを伴うフォルト)が伸びているなら、ワーキングセットが物理メモリに収まらなくなりつつある合図だ。 min_flt だけが伸びているなら、新しいページを触り続けているということ。 数字の「伸び方」を読むのが肝心で、瞬間値だけ見ても何も分からない。

断片化は、ログの「間」に現れる

厄介なのは 断片化 だ。 これは一行のログには出てこない。

確保と解放を繰り返すうちに、使える隙間が虫食いになり、RSSが下がりきらなくなる。 mmap で確保した領域の解放パターンや、アロケータのアリーナの推移を長い時間軸で並べて、初めて「下がらなさ」として姿を現す。 断片化は点ではなく、傾きとして読むものだ。

アラインメントと、見えないコスト

もう一つ、ログの裏に隠れるのが アラインメント のコストだ。 構造体の整列がずれていると、キャッシュラインをまたぐアクセスが増え、同じ処理でもCPUの待ちが増える。

これはアプリのログには絶対に出ない。 perf のカウンタや、地道なメモリレイアウトの確認と突き合わせて、ようやく「なぜか遅い」の正体にたどり着く。

結局 observability とは、システムが黙って数えている値を、こちらから読みに行く技術なのだと思う。 ログを読むとは、その入り口に立つことだ。

#mmap #observability