サーバが2時間ほど死んで、復旧するまでのドキュメンタリー


22時頃、保守フェーズに入っているあるウェブアプリケーションの担当者から、アクセスできなくなっていると電話。サーバには職場からしか繋げないのだが、たまたま職場に後輩が残っていたため、電話して口頭で作業させた。そのウェブアプリの構成は以下のようになっている。

実際はもっとサーバの台数も多いのだが、まぁ主要なサーバはこんな感じだ。なんのことはない、割と一般的なJavaのウェブアプリといえる。とりあえずトラブルシューティングとしてやったことを列挙。ちなみにサーバはRHEL4、apacheは2.0、tomcatは5.0、mysqlは4.1、javaは1.5。

ps -ef|grep httpd|wc -l
/usr/local/apache2/bin/apachectl graceful
/etc/init.d/tomcat restart && apache: /usr/local/apache2/bin/apachectl graceful
mysql: mysql -uroot -p -e'show processlist'|grep Locked

ここまでやって、とりあえずDBで詰まってるわけではないことが判明。単純なプロセス再起動で復旧しないことから、アクセスの異常増加かハードウェア異常じゃないかと疑ってみる。httpdのプロセス数はMaxClients 512に設定してあるが、2台ともFULL。全サーバでtop/sarを確認するも特に異常なし。そこで思い立って hdparm -t /dev/sda してみる。通常は50MB/sec?80MB/secくらい出るのだが、webの1台だけ1.5MB/secとかいうふざけた野郎がいるのを発見。とりあえず shutdown -r now したらIOの速度は復旧。デバイスドライバのbugっぽげ。

ここまでやって、自宅からVPNで接続できる担当者と連絡が付いたので、後輩はお役後免にする(なにをやらかすかわからない子なのでw)。リブートまでしたものの、状況は先ほどと変わらず。訳がわからないので、とりあえずもう1台のwebもリブートしてみよう、ということになり実施する。が、担当者がshutdownのオプションを間違えて(多分solarisと間違ってる…)リブートじゃなくてまともに電源断。サーバの置いてある現地とは連絡が付かないため状況はさらに悪化…

webが片肺になってしまったので、httpd.confでMaxClientsとServerLimitを倍に設定。だがプロセス数300前後で反応がなくなる。問題はapacheではなさそうなので、次に散々泣かされているmod_jkを疑ってみる。netstat -a|grep ESTABLISHED とかすると、tomcatサーバの1台がコネクションを捕まえっぱなしになっていることが判明。ブラウザからjkstatusの管理画面を見ると、1台はrecovering、1台okで残りはerrorになっている。原因究明は後で良いので復旧第一ということで、tomcatを全部再起動してその後apacheも再起動。そうするとあら不思議、今までの重さがウソのように完全に復旧しましたとさ。とりあえず10分ほど動作確認して、問題なさそうなので解散。電源は朝入れれば良いと言うことで…

実際はもう少し色々試行錯誤があったのだけど、ダイジェストにするとおおよそこんな感じ。22時だからまだ良かったよ…寝てても容赦なく電話くるから。しかし根本原因がよくわからない。IO性能が異常に劣化してたのはbugだとしても、1回目のtomcat全部再起動で復旧しなかったのが謎。なんかtomcatって、stop/startを素早くやりすぎるときちんと再起動しないことがあるような気がするのだが、それなのかなー。てか、もうmod_jkは止めたい。でもapache2.2はまだちょっと怖いし、sticky session使ってるし…代替案でいいのがない。