謎のServiceUnavailableの原因を追え！

CentOS7のEOSLが近づいてきて、SIerの皆様はOS切替に奔走していることと思います。
弊社でも複数のOS切替案件が動いていて、その際発生したServiceUnavailableの原因調査に悩まされた話をします。

前提知識・条件

ServiceUnavailableとは

e-words.jp

503エラーです。サーバが「ちょっとこれ以上働けないから無理です」っていう状態です。

構成

ロードバランサ１台、その先にアプリケーション用のサーバが3台います。
WebサーバはApache、アプリケーションサーバとしてTomcatで動いています。
なお、すべてのアプリケーション用サーバの性能・設定は同一になっています（設定ミスってなきゃ…）

ServiceUnavailableの発生条件

クライアント側でボタンクリック後60秒で発生している。３台すべてのサーバで発生する。

調査順

順を追って調査していきます。

1. Tomcatのログを確認する（catalina.out、gcログ）
   503エラー、つまりサーバの処理能力の限界ということらしいのでまずtomcatのログ周りを確認しました。
   gc頻発しているとか、Exceptionとか何かしらのログがあると思ったのですが、ServiceUnavailable発生時刻には何のログもありませんでした。

2. Apacheログを確認する（http、errorログ）
   503エラーを返している。つまりhttpのログとして503が記録されているのではないかと思い、ログを追います。
   しかし該当時間に503を返しているログがありません。
   はて、どこでServiceUnavailableが発生しているのでしょうか？

3. Tomcat、Apacheの設定を確認する
   先述した前提条件にある通りServiceUnavailableはボタンクリック後60秒で発生しています。ですので、どこかの設定で『60秒経過したら503にする』というタイムアウト的な設定が入っていると考えました。 しかし、どこにも『60秒』の設定がありませんでした。

4. LBのログを確認する
   LBのログにも何もでていません。完全な無風状態でした。

   正直、この時点でLBが怪しいと思っていました。Tomcatが503を返したのであれば、Apacheのhttpログに503エラーが記録されるはずだと考えていたのでTomcatの可能性は非常に低いです。Apacheが503を返したのだとしても、やはりhttpログに503が記録されそうな気がします（検証してないですが）

5. LBが犯人であることを特定する
   LBが怪しすぎるので、アプリケーション用サーバにLB経由ではなく直接アクセスできるように設定変更し、直アクセスで動作確認を実施しました。
   すると、直接アクセスした場合ボタンクリック後60秒経過しても同様の事象が発生しなかったのです。 LBが犯人であることが確定しました！

6. LBの設定値を見直す
   各種設定を見直し、60秒の設定を無事発見しました。 設定変更すると無事ServiceUnavailableが発生しなくなりましたとさ、めでたしめでたし。

所感

振り返ってみると、当たり前の調査を順にやっただけだな？と思えるのですが、やっている最中は「どこで発生しているのかまじでワカラン」状態でした。
また、今でこそ多少の経験値があるので調査の次の1手が思い浮かびますが、これが5年目くらいの時に起きていたら「どこ調べたらいいの」状態で涙していただろうなと思い、記事にさせていただきました。アプリ開発者でも平然とインフラ寄りの仕事振られるのが辛いです。