トラブル☆しゅーたーず#05 〜過去からの贈り物〜」に参加してきました #トラしゅ

ということで、昨日行われたトラブル☆しゅーたーず#05 〜過去からの贈り物〜へ参加してきました。トラしゅ参加は2回目、今回はチーム3で参加したのですが、なんと優勝という評価を頂くことができました。
とはいえ私は色々わーわー言うだけという感じで、一緒に参加したチームの皆様には色々お世話になりまして、どうもありがとうございました、と感謝の限りです。特に@Kill_In_Sunさんには報告書作成の大半にプレゼンまでやっていただいて、どうもありがとうございました。あれだけできれば前途は明るいと思います、ええ、本当に。

また、イベントを開催してくださった運営の皆様、そして会場だけでなくニフティクラウドのサービスも提供してくださったニフティさん、本当にありがとうございました。

で、参加記録という事で、とりあえずログと記憶をたよりに、当日の流れをつらつらと書いてみようと思います。

今回のシチュエーション

前置きはイベントページの通りなので省略。システム構成は以下のような感じです。

このような構成で、WEBサーバがクラウド側のトラブルにより再起動した、というのが今回のシチュエーションです。
お客様からの連絡というのは

•サイトがおかしいみたいです
SSHアクセスもできなくなってます
•今日の16:00〜16:15のTVで取り上げられるのに
•今回はCMの効果をちゃんと確認したいので、どのくらいアクセスがあったとかそういうの教えてもらえますか

というもの。ちなみにこの時点で時刻は14時です。

まずは状況確認

一通りの説明とチーム分け発表が終わり、会議室に入ってまずやることはサーバアクセスの確認。すると、

  • BATCHサーバは普通にコンソールからでもsshでもアクセスできる
  • WEBサーバは確かにsshでアクセスできない、ではコンソールはというと、こちらも表示はできるが、用意されているrootユーザもhonbanユーザもパスワードが通らない

という状態。WEBサーバに入れないとどうしようもないので、一旦再起動しシングルユーザーモードで起動。するとなんとrootもhonbanユーザもshadowが埋められている、という事が判明。これじゃログインできるわけねぇわ、ということで、rootユーザのパスワードを再設定してコンソールからはログインができるようにしました。
さらには

  • 再度の再起動後もなぜかsshdがあがっておらず(chkconfigでは有効になっているのに、って/etc/rc3.d以下までは見てなかったな…!)、sshアクセスできない
  • sshdをあげてhonbanユーザでログインしようとすると鍵の認証ではじかれる。調べてみると~honban/.ssh/authorized_keysのownerがrootになっていた!

と早速罠全開。
なんとかログインしてサーバの様子を探ってみると、動作しているのはApacheMySQL、しかし/usr/local以下にはnginxも置いてあり、さらにphpのバージョンも5.3.2と5.3.4の2つがある、というカオス状態。nginxについては事前説明の中の山○君の証言に

エンジンエックスってどう考えても読めないっすよね

という一文があったことから、恐らくこいつが仕込んだものだろう、という想像はついたのですが、現状Apacheが動いているからとりあえず置いておこう、と言う事でスルー。

一方Webサイトのほうはというと、アクセスは普通にできるものの

  • 商品説明の横の小さい商品画像が見られない
  • 購入処理を進めていくと、最後の決済の所でエラーになる

と、正常には稼動していない状態。

エラーログを眺めて原因を探った所、前者はEC-CUBEの画像縮小表示用のスクリプトが正常に動かない事が原因と判明。ただし「imagecreatefromjpeg()関数が定義されていない」というエラーが出ているもののGDは有効になっており、じゃあ何でエラーになるんだ…、という原因までは、この時点では気づく事ができませんでした。
後者については「mysqliクラスが無い、ってエラーが出てる」という程度は確認できたのですが、DBに接続できなければそもそも商品情報やら他のページも表示できないはず…? と言う事で原因は最後までわからずじまい。

そうこうするうちにトラブルが

そんな感じで状況確認をしていると、なんとsshで繋いでいたWEBサーバの反応がなくなりました。コンソールを見てもらうと、OOM-Killerが発動している事を示すログが。
メモリ搭載量は1GBあり、本来であればこれで足りないと言う事は無いはずなのですが、ともかくサーバの応答がなくなった以上サービスも止まっており、この状態を長引かせるわけにはいかん、ということでサーバの再起動を実施。
並行してお客様にsorryサーバ作成の可否を問い合わせ、許可が得られたのでsorryサーバを作成する事になりました。ただ残念ながら、IPアドレスを付け替えたりと言う事ができなかったので、このsorryサーバは最後まで使われる事がありませんでした。

サーバ復帰後、メモリが足りなくなった原因を調べるもはっきりとした原因は発見できず。my.cnfでのMySQLキャッシュ割り当てが大きめであった事から、キャッシュとして確保されるメモリが多すぎるのでは? という推測を立てて、とりあえずはサーバをメモリ搭載量が多いプランに切り替えることで凌ごう、と言う事になりました。
そうこうしている間にもサーバの応答がなぜかなくなってしまって再度コンソールからリブートを掛けたり、再びOOM-Killerが発動してやっぱりコンソールからリブートを掛けたり、と対応に追われつつも、なんとかサーバのスペックアップ(メモリ搭載量を1GBから4GBへ)が間に合い、16時のテレビ放映を迎える事ができました。

ただし、この時点でもWebサイトの問題2点は未解決。「じつはApacheじゃなくnginxを動かさないと駄目なんじゃね?」という話があったのでnginxを起動させてみるも、デフォルトのWebページが表示されてしまい、こりゃ駄目だ、と言う事で即座にApacheへ切り戻し。
実はこの時点で「なんでデフォルトのWebページが出るんだ」という事をもっと追求していれば、正解にたどりつけていたんですが、まぁ詳しくは後程。

16時!

16時になった瞬間、大量のアクセスが押し寄せてきたため、サーバの負荷が上昇していきました。同時にメモリ使用量も増加し、早くも4GBのメモリを使い果たしそうな勢いになりました。
なんでだ、と思って調べてみると、なんとApacheのMaxClientsが15000という数字に設定されている事が判明。preforkで15000とか何考えてるんだ! とかうめきながらあわててまず1000に、続いて500にMaxClientsを変更しました。このときの再起動が、結果的には功を奏したわけですが、まぁラッキーパンチではありましたね…。
依然としてWebサイトの問題は解決しないものの、「まぁ、アクセスできてるしまぁ……」と言う事で半分くらいはもうあきらめムード。とりあえず発表資料作りましょうか、ということで、アクセスログを集計したり、資料をやいのやいのといいながらまとめたりしつつ、タイムアップの18時を迎えたのでした。

ちなみにこの後も1度OOM-Killerが走って、サーバの応答がなくなったためにリブートを実施しています。このタイミングで何故メモリが足りなくなったんだろう、と言う事を考えていれば、種明かしを待つでもなくOOM-Killerが走った原因が分かった…かもしれません。

種明かし

18時のタイムアップを迎えて、最初に集まったミーティングスペースへ戻ってみると、ホワイトボードに各チームのタイムラインが記録されていました。
これはまぁ前回も同じだったので、さてどんな感じだったのかな、と眺めてみると

攻撃!
そうか、あのOOM-Killerは攻撃を食らった事によるものだったのか、でもあれ、アクセス数は大して増えてなかったはず…、と思って色々思い返してみると、そういえばApacheのバージョンが2.2.14と割と古めだった事を思い出しまして、

となったわけです。

さらには15:30にatコマンドで再起動が仕込まれている事もここで判明。

atコマンドとか前職勤務時代に1度くらいしか使ったこと無いわー、ってかそりゃcronのログを見ても何もでてないわけだわ、と、仕込みのすごさ(あるいはエグさ)に改めて舌を巻いた次第です。

で、正解は

結局未解決となったWebサーバの2つの問題、商品画像が出ない問題と購入処理が最後まで行かない問題は、phpコンパイルオプションで必要な機能が指定されていなかった、というのが原因でした。
実はApacheがロードしていたphpはバージョン5.3.2のもので、正しくコンパイルされたphpは5.3.4、/usr/local/php-5.3.4以下に配置されているものでした。で、これをロードしているのがあのnginxだった、というオチだったのです。
Apacheではなくnginxを起動させる必要がある、というところまでは正解だったのですが、さらにphp-fpmも動かす必要があったのです。これをやらないとphpが動作せず、結果的にnginxのデフォルトのページが見えてしまう、という次第。というかあれがデフォルトのページだったのかというと、多分違った気がしますが、ここは未検証。

我々のチームはWebサイトを落とさない、という1つ目の目標はクリアできた(おかげで優勝する事ができたのですが)のですが、ここに気付く事ができなかったというのは悔いが残るポイントです。というか最低限起動スクリプトくらいは置いといてくれよぉ…。

各チームのプレゼン、解答編の発表が終わった後は毎度恒例の懇親会へ。ここでも色々と面白い話をうかがうことができました。「WEBサーバのrootのパスワードが潰してあったのは、あれは意図的ではなくうっかり」というのを聞いた時には思わず膝から崩れましたけど…w
あとここまで触れていなかったBATCHサーバ。山○君が

tweetしていたものの、「あいつの言う事だから絶対そんなはずは無い、何かあるはずだ」と思ってみんなで色々調べていたのですが、本当に何もしていなかった、というのが判明したのも懇親会の席でした。
でももっと慄然としたのは「どのチームも触れてない罠がまだいっぱいあったんですけどねー」という一言。この時にと決意したのでした。

思ったこと

前職では運用管理を請け負うサービスの中の人でしたし、今も某Webサービスの会社のインフラ管理をしているわけですが、いずれも

  • システムのあらまし(どういうサーバがいてどういう働きをしているか、どんなデーモンが動いているか、アプリケーションはどこに何があるか)を理解しており
  • どんな事が起きたらどうする、というシミュレーションを事前にしており
  • 何か起こった時も密に担当者と連絡を取り合える(というか、今は私自身が担当者ですが)

という環境を整えた上であったので、今回のようにすべて即興かつタイムリミットが迫った状態で、というのは中々いい刺激になりました。
対応をしながら、あるいは懇親会の席で思ったのは

  • やはり事前のシステム把握は大事、正常な状態で何がどう動いているのか、を知っておく事が正常復帰への第一歩。
  • ある障害が発生した時に正しい原因を見つけられるように、日頃から「どういう障害が/どういう事象が起きうるか?」という事をシミュレートし、思い出せるようにしておくべき。
    • 特に今回は、「Apache脆弱性を突いた攻撃がくるかもしれない、来た場合にはApacheがメモリを大量に消費してハングアップするかもしれない」という事に思い当たれば、Apacheのアップデートはできなくても、iptablesで攻撃元のアクセスを遮断するとか、兆候が出た時点でApacheを再起動するとかいう対応策が取れた
    • またこれは構築時の話として、「サーバが再起動するかもしれない」ということを考えていれば、再起動後もnginxが正しく起動するように設定できていたはず。

といったあたり。「備えあれば憂いなし」は金言だと思います。
ただまぁ経験上、備えの斜め上の事態が発生する事もよくあるので、そんな場合には即応力というかとっさの判断力が必要になる、とは思います。こっちの訓練は…どうしたらいいんでしょうね。

おまけ

帰りの副都心線の中でふと「サーバもう1個用意して自分でLAMP環境作って、アプリケーションのtar玉とmysqldumpでのダンプデータをコピーして、そっちをサービスインさせるという手があったな」という凶悪な手を思いついたのですが、IPアドレスを差し替えられない時点で駄目ですね。動作確認とか色々しないといけないですし。