Azure Web Appsでほぼ爆発した話

艦これのイベントが始まりましたね。
ぐらばくさんが作っている提督業も忙しい!のプラグインにゔぇいさんが作っているMapHPという物があります。

2016-02-13 (1).png

こんな感じでゲージ破壊のマップがある場合、あと何回でクリア出来るか表示してくれるやつです。
実は前回のイベントから出撃制限札を提督業も忙しい!本体ではなく、僕が管理してるサーバーにデータを設置してそれを取得する形式になっていましたが、今回はMapHPのプラグインもプラグインデータを本体で持つのではなく、サーバーに設置するという話になりました。

イベント開始前に既にプラグイン側、サーバー側とも実装が完了しており、イベント開始後に動作確認も取れたので提督業も忙しい!4.2.1としてリリースされた。
※WebJobが回ってる時、サーバーレスポンスが遅い気がするという不安要素を残しつつ

翌日Azureのポータルを見に行ったらHTTPサーバーエラーが多発していた。

Pasted image at 2016_02_12 03_22 PM

直近1時間のアクセス数10.7万に対して3.1万のエラーである。
平均レスポンスタイムも1分を超えていて到底利用できる状態ではなかった。
WebJobが回ってる時が重いと思っていたのでWebJobを全部(2つしかないけど)止めてみたけど変わらず。
BasicプランSサイズ3インスタンスでこの状況だったのでリクエストを捌ききれていないと判断し、
仕方なく3インスタンスまでしかスケールアウト出来ないBasicから10インスタンスまでスケールアウト出来るStandardプランでSサイズ10インスタンスに変更してみた。

Pasted image at 2016_02_12 04_31 PM.png

つ、強いぞ!
10インスタンスにした途端サーバーエラーはなくなり、レスポンスタイムは短くなって行った。
これで解決かと思いきやそんな事はない。
StandardプランSサイズ10インスタンスは1時間約63円消費される一般的な個人で使うには高すぎる値段なのだ。
使用しているアカウントはMicrosoft Community Championship(だっけ?)で貰ったBizSparkアカウントで月額15,500円使えるのだが、ことが判明した時点での残りクレジットは約10,000円。
このままでは約6日しか維持できず、月末まで維持できないのだ。

しかも様子見で9インスタンスにしてみたけど徐々にレスポンスタイム伸びて30秒超えてきた辺りで10インスタンスに戻するという小物っぷりを発揮。

そうこうしてる間に原因の1つが判明。
プラグイン側の実装がまずかったようで、とんでもない頻度でリクエストを投げていたそうな。
修正後にログ確認したところ、確かに同一IPから短時間に多数のリクエストが来ていた。
本来このプラグインは出撃ボタンを押した時に取得する予定だったので精々多くても1秒に2,3回ぐらいで済むはずだった。

これを修正した4.2.2がリリースされ告知される。

キャプチャ.PNG
もはや様式美

そんなこんなで原因の1つは取り除かれたのだが、4.2.1のプラグインをいつまでも使い続ける人もいるのでサーバー側も対応しなければなりません。

Pasted image at 2016_02_13 12_45 AM.png

これは修正する直前ですが、直近1時間のCPU使用時間が10インスタンスで5時間に達しています。
1インスタンス辺り平均30分使われてることになります。
ここを下げないことにはインスタンス数を減らすことが出来ません。

原因はおおよそ目処がついていました。
サーバー側は出来上がったデータを送ってた訳ではなくWebJobで解析バッチが回ってたんですが、
それを元に毎回MapHPプラグイン用に処理を行っていたので遅くなっていました。
更に言うと、解析結果はMySQL保存されているのですが、リクエストがあるたびにアクセスがしてたのでMySQLのコネクションが死んだのが一番の原因です。

本来であればこのデータはそんな頻繁に変更される情報ではないのでキャッシュに乗せるのがベストなのですが、AzureでMemcachedなどのキャッシュサービスは非常に高く、BizSparkでは賄いきれないのです。
だからと言って放置する訳にも行きません。
修正版がリリースされたあともアクセス数は伸び続け、一時は直近1時間で22.3万アクセスに達しました。

解決方法は色々悩んだんですが一番シンプルで簡単な、最終的に出力するデータをローカルにファイルとして一定時間保持しておくという手段を取りました。

Pasted image at 2016_02_13 01_37 AM.png

この時点での直近1時間のアクセス数は約17万、だいぶ軽減されました。
深夜の時間帯に入って若干アクセス数が減りましたが、それに比べてCPU使用時間は激減しました。

現在はStandardプランSサイズ5インスタンスまで下げて様子を見ていますが、この様子であれば月末までは維持できそうです。

今回の事件は僕がAzureのログの見方を分かってれば起こらなかった可能性があります。
Linux系のサーバーだとhttpアクセスログをtail -f access.log | grep hogeみたいなので見たい情報をリアルタイムに見れますが、
Azure Web Appsはそうも行かずリアルタイムにアクセスログを見る方法を知りません。
誰かおしえてください。

そんなこんなで今回もブログが死んだぐらばくさんから一言。
キャプチャ.PNG

はい。

広告

Azure Web Appsでほぼ爆発した話」への1件のフィードバック

コメントを残す

以下に詳細を記入するか、アイコンをクリックしてログインしてください。

WordPress.com ロゴ

WordPress.com アカウントを使ってコメントしています。 ログアウト / 変更 )

Twitter 画像

Twitter アカウントを使ってコメントしています。 ログアウト / 変更 )

Facebook の写真

Facebook アカウントを使ってコメントしています。 ログアウト / 変更 )

Google+ フォト

Google+ アカウントを使ってコメントしています。 ログアウト / 変更 )

%s と連携中