IT 基盤部の増田です。新卒2年目で業務では主にモバゲーや社内向け SaaS のインフラ運用を行っています。

本記事ではサーバーのメモリ使用量増加の原因を SystemTap で調査したときの話を紹介します。 この記事を通して、手掛かりを元に少しずつ核心に近づいていく、謎解きゲームのような楽しさを感じていただければと思います。

問題発生

調査を開始したきっかけは、サーバーのメモリ使用量増加のアラートが頻繁に鳴るようになったことでした。 調べてみると、メモリ使用量は特定の系統のサーバー全台で増えていました。 まずは、サーバで起動しているプロセスのメモリ使用量を ps や top で確認しましたが、アラートの原因となっていそうな怪しいプロセスは見つかりません。 そこで、メモリ使用量の詳しい内訳を見てみることにしました。

/proc/meminfo を確認したところ、Slab キャッシュのメモリ使用量が多いことが分かりました。 Slab キャッシュとは、Linux カーネルがよく使用するオブジェクトのキャッシュです。 この Slab キャッシュのさらなる内訳は、slabtop で確認することができます。 使用量が最も多かったのは inode で、次点で dentry でした。 inode のメモリ使用量は、他の系統のサーバーと比べて大幅に大きかったので、これが問題の原因のようでした。

dentry・inode とは

dentry は親、及び、子の dentry への参照を持つことで、ファイル・ディレクトリの階層構造を表します。 また、ディレクトリ名・ファイル名も dentry が保持しています。 一方、ファイル・ディレクトリのメタデータは inode によって管理されます。 ただし、dentry は自分でメタデータを持たない代わりに、inode への参照を持ちます。 まとめると以下のとおりです。

• dentry
  • ファイル・ディレクトリの階層構造を表す
  • ファイル名・ディレクトリ名を保持する
  • inode への参照を持つ
• inode
  • ファイル・ディレクトリのメタデータを保持する

次は、キャッシュがどのように生成されるのかを見ていきます。 dentry と inode は、パス解決をした際に作成されます。 パス解決とは、パス名に対応する dentry の階層をたどっていくことです。 この過程で、パス名に対応する dentry が存在しなければ dentry が生成されます。 また、検索されたパスにファイルが存在するならば、そのファイルに対応する inode が dentry から参照されます。 よって、検索されたパスが多ければ多いほど、これらのキャッシュの量が増えます。

試しにキャッシュを削除してみましたが、翌日になると元と同程度の量のキャッシュが再生成されていました。 どうやら、キャッシュは定期的に生成されていそうです。 また、dentry と inode の両方が増えているので、たくさんのファイルのパスが検索されていそうです。 もしかしたら、ファイル数の多いディレクトリでパス検索がなされたことが原因で、キャッシュが増えているのかもしれません。 find . -type f を駆使すれば、ファイル数が多いディレクトリのあたりをつけられそうですが、今回は dentry・inode を誰が作成したかを直接的に調べるアプローチを取ってみます。 具体的にどうするかというと、dentry・inode はカーネルによって生成されるので、このカーネルの処理を監視し、処理の呼び出し元のプロセスを探します。

カーネルの処理を監視する

カーネルの状態を監視するための仕組みはいくつか存在しますが、今回の環境には SystemTap がインストールされていたので、これを利用してみました。 SystemTap を使用すると、カーネル上の特定のイベントにフックして独自の処理を追加できます。 inode、または、dentry を生成する関数にフックして処理を追加すれば、キャッシュが誰によって生成されたかを調査することができそうです。

それでは、SystemTap を利用して、誰によってどのパスに対応するキャッシュが生成されたかを調べてみましょう。 ここで、パスの情報は dentry が持っているので、今回は dentry を生成する処理にフックを仕掛けました。 dentry を生成する d_alloc という関数にフックを仕掛け、呼び出し元のプロセス名、及び、生成された dentry と対応するパス名を出力します。 おおよそ以下のようなスクリプトを作成し、dentry.stp として保存しました。

#!/usr/bin/stap

probe kernel.function("d_alloc").return {
  if (d_name($return) != "") {
    printf("%s,%s\n", execname(), reverse_path_walk($return))
  }
}

そして、Slab キャッシュを削除した上で、sudo stap -v -g dentry.stp でスクリプトを実行し、キャッシュが再生成されるのを待ちました。

解決

翌日、ついに問題の原因が解明されました。 メモリ使用量が増加していたのは、特定のディレクトリに残ってしまっていた大量のログファイルの inode が生成されたためでした。

本来、古いログファイルはバッチによって定期的に掃除されるのですが、特定のアプリのログだけは削除されずに大量に残っていました。 その理由はファイル名の形式にありました。 我々の運用では、ログファイルを hoge.log.YYYYMMDD のように命名していて、この形式のファイル名を持つログファイルのみをバッチで削除しています。 ところが、問題のログファイルはファイル名が fuga.log.YYYYMMDDhhmm のようになっていたため、ファイルが消えずに残っていました。 そして、このバッチがこれらのログファイルのパスを検索した際に、dentry・inode が生成されていました。 また、Slab キャッシュを削除しても翌日になるとメモリ使用量が元に戻っていたのは、このバッチが毎日実行されていたからでした。

最終的には、ログファイルを定期的に掃除するバッチに変更を加え、溜まっていたログファイルも削除するようにし、この問題は解決されました。 こうして、メモリ使用量増加のアラートから、Slab キャッシュという手掛かりを見つけ、SystemTap を用いて原因解明、ついには解決までこぎつけました。

感想

今回の調査では SystemTap の便利さを実感しました。 フックをカーネルの関数に仕掛けてログを取得できる仕組みは、とても強力で有用だと感じました。 今後は SystemTap の後継である bpftrace も試してみたいです。

また、自分が所属する IT 基盤部は日頃から「品質 » スピード」を徹底しています。 inode・dentry について、時間をとってでもきちんと理解した上で、調査を進めることを上司に推奨されました。 「なぜ」を深ぼることを重視する組織なのは自分の性に合っていて、とても楽しくトラブルシューティングができました。 読者の皆様にも謎を解き明かすワクワク感をこのトラブルシューティングの事例から感じていただければ幸いです。