エラーログで障害原因を突き止めろ！

サーバー

技術解説

連載 :

ログ管理、これだけは！

2008年12月16日(火)

菊地宏一郎

エラーログに対応する～OOM Killer編

続いて、/var/log/messagesに図2-1のようなログが記録された場合の対応を考えてみましょう。このログはOOM（out of memory） Killerによりhttpdプロセスが強制終了されたことを示すログです。

OOM Killerとは、システムがメモリ枯渇すると、稼働中のプロセスを強制終了させて空きメモリを確保するLinuxカーネルの仕組みで、メモリ枯渇によるシステム停止を防止するために用意されています。

このログが記録された場合、まず必要になるのはプロセスの存在確認です。OOM Killerは比較的重要なプロセスも容赦なく強制終了させてしまいますので、必要なプロセスが存在しているかを確認する必要があります。

図2-1のログではhttpdが終了させられているので、以下のコマンドを実行しhttpdプロセスの存在を確認します。

$ ps -e | grep httpd

もし、プロセスが存在しない場合には、速やかにhttpdを起動させましょう。

# /etc/init.d/httpd start

OOM Killer により引き起こされた障害を復旧させたところで、根本的な対策を考えます。例えば、メモリを大量に消費しているアプリケーションを特定し、重要なアプリケーションであれば、改修するなどしてメモリの使用量を抑止します。不要なアプリケーションが問題を引き起こしていた場合には、起動させないなどの対策をとりましょう。また、物理メモリの増設が必要になるかもしれません。

ただ、問題のあるアプリケーションを起動させないようにする以外の対策は、即座に実施できるものでもありません。そこで、ここでは、当座の対策として、swap領域を増やす方法を紹介します。

以下は、2GBのswapファイルを /var/tmp/swap0 に作成し、追加のswap領域として利用する場合の例です。

# dd if=/dev/zero of=/var/tmp/swap0 bs=1024 count=2097152
# mkswap /var/tmp/swap0
# swapon /var/tmp/swap0

なお、システムがメモリ枯渇状態になっても、OOM Killerが発動せずにサーバーが応答不能になったり、リセットしてしまったりすることもあります。こうした場合、ログ監視だけでメモリ枯渇状態が発生していたことに気がつくことは困難ですので、ログ監視とは別に、システムリソースの監視も行うのが一般的です。

エラーログに対応する～Apacheのプロセスダウン

続いて、Apacheのエラーログ (/var/log/httpd/error_log) に、図2-2のようなエラーメッセージが記録され、httpd プロセスが異常終了してしまった場合の対策を考えましょう。

まず、AApacheのプロセスは異常終了しており存在していないはずなので、Apacheを起動させます。Apacheが無事起動したら、原因の調査に移りましょう。

続いて、ApacheはどこからかSIGHUPを送られた後でsegmentation faultを起こしているので、このSIGHUPの送信者を突き止めます。まず、誰かの作業の可能性を考え、lastコマンドで当該時間帯のログイン記録を確認しましたが、誰かがログイン記録した形跡はありませんでした。念のため/var/log/secureも確認しましたが、こちらにも不審なログは記録されていませんでした。

となると、cronで何かが動いていたのかもしれません。cronのログ（/var/log/cron）を確認してみましょう。ログを確認したところ、4:00 ごろに実行されていたプログラムは、毎時間のcron処理 (run-parts /etc/cron.hourly) と日次のcron 処理(run-parts /etc/cron.daily)の2つでした（図2-3）。Apacheは、4:02にSIGHUPシグナルを受信していますので、4:02に実行された cron.dailyの方が怪しそうです。

cron.dailyで実行されるプログラムは、/etc/cron.daily/ディレクトリにあるスクリプトです。実際に確認したところ、図2-4のようになっていました。これらの中ではlogrotateが怪しそうですので、Apacheのlogrotateの設定を確認してみましょう。/etc/logrotate.d/httpdの内容は図2-5のようになっていました。

postrotateの「/sbin/service httpd reload」は実際には「/etc/init.d/httpd reload」が実行されます。/etc/init.d/httpdを確認するとreloadの処理はreload関数として定義されていました（図2-6）。

reload関数の中でSIGHUPが発行されていますので、図2-2の1行目のSIGHUPはlogrotate時のSIGHUPに間違いないようです。

SIGHUPを受けてApacheが異常終了する、という問題は、PHP 4.3のころにPCRE extensionのバグで発生していたことがありますが、どうも、CentOS 5でapache 2.2＋PHP 5.1.6の環境でも、使用するextensionによってはごくまれに発生することがあるようです。

原因が分かったところで、対策を考えます。今回の場合は以下の対策が考えられます。