前回（というか前日）のエントリ：
酒飲んだノリで深夜に記事を書くとろくなエントリにならないという教訓が得られたのが前エントリの反省でした。こんばんは、kariaです。
というわけでISUCON7の予選に出た話です。チーム名はLabALICE、メンバーは私と id:naught00 と id:macotasu でした。ISUCONって何よって人はいい感じにググって調べてください。
開始前
昨日みんな期日前投票行ってるし余裕やろと思いきや、投票用紙出す機械が紙詰まり起こして結局並んでたの巻 pic.twitter.com/jvd8Pw2WI9
— karia (@karia) 2017年10月22日
競技開始時間が遅れることが前日にアナウンスされていたので、台風接近で大混雑していた期日前投票を避け当日投票所に行く事ができました。投票用紙のデプロイマシーンで紙詰まりというトラブルが発生するといった出来事があったものの数分で解消し、無事に集合することが出来ました。
デプロイ待ち #isucon pic.twitter.com/h7FyOCiHzS
— karia (@karia) 2017年10月22日
当初のアナウンスでは競技時間が12時-20時だったので、NEWDAYSのヘンなおにぎりを買って競技時間中に食べようと思っていたのですが、さらに1時間遅れることになったので待ち時間中に速攻で食べ終わってしまい、追加でカフェイン分を調達しに行きました。エスプレッソショットを普段よりもさらに+1しています（トータルで3ショット分になっている）。しかしこいつ紙撮るの好きだなおい。
13時開始との知らせを受けて @MacoTasu がラジオ体操でアップをはじめた #isucon
— karia (@karia) 2017年10月22日
このとき手持ちのiPhoneで本当にラジオ体操を流していたのが個人的にツボでした。
競技時間中
今回のお題はisubataというチャットツール風Webアプリ。似たようなツールをどこかで見たような……？
最初にコードをgithubに上げたり解析してもらうのは一旦他の2人に任せて、環境まわりの整備からスタート。これらはほぼ事前にやると決めていたことでした。
SSHを鍵認証にするのはパスワードを何度も入力する手間を省けるというのもあるのですが、パスワードを間違えすぎるとログインできなくなるfail2banが最初から入っており（レギュレーションにも書いてあった）、実際ログインできなくなっている人達をサポートチャットで見かけたため事故防止として初期にやりました。
nginxのログはとりあえず詳細に出さないと何もわからんということで、真っ先に変更にかかりました。そこからalpに食わせるところまではお作法みたいなところがあるのですが、alpの結果をどこに貯めようかという話になり、標準入力を食べてSlackに吐くシェルスクリプトを事前に作っておきました。たとえば、 echoでとある文字列を食わせると
こんな感じ。まあQiitaとか調べれば沢山出てくるやつです。
このスクリプトにalpの結果を出力するようにしていたので、nginxのログ解析結果がslack経由で即チーム内に共有されるようになっていました。またalp実行直前にnginxのアクセスログをローテーションしてからalp専用サーバー（※）に送るようにするのも事前にスクリプトを用意していました。
※alp専用というわけでは無かったのですが、今回提供されるさくらのクラウド＋最新のUbuntuという環境に慣れる意味も含め、自前でさくらのクラウドを1台調達していました。ただ、解析以外の処理を肩代わりさせることはレギュレーション違反になってしまうため、実態としてはalpでのnginxログ解析専用サーバーと化していました。
MackerelとNew Relicは仕事用とは別に今回のチーム用にアカウントを事前に取得していたのですが、その数日後にNew Relicの営業さんから「導入に問題はございませんでしたか？」という電話がかかってくるという心温まる出来事があったのを覚えてます。
そんなNew Relicさんが表示してくれる、いかにもダメそうなWeb Transactions timeの様子。タイムゾーンがJSTじゃないのでいい感じに脳内変換してね。
Throughputはこんな感じ。確か、ポータルサイト上での初期スコアは6000点台だったと思います。
そんなこんなで、環境整備が終わってから取り組んだのがこのあたり。
- pumaが動作するサーバーとは別に、DBサーバーにnginxを立ててロードバランサー代わりにする
- 画像をDBではなくローカルで保存するようにし、極力pumaではなくnginxから返すように
- nginxでPOST /profileを1台で処理するよう仕向ける
みたいな事をして2万点届くか届かないかみたいなところでした。ここまでで16時頃だったかな。
画像ローカル保存化はほぼやってもらったので、自分はnginxおじさんを主にやっていた感じでした。今回は複数台構成ということで画像ローカル保存は結構悩みどころで、これが本物の商用環境なら迷わずAmazon s3にポイッと投げるでしょうけどISUCONのレギュレーション的にそういうわけにいかず、かといってどこか1台のサーバーに集約してNFSマウント……みたいな事をすると様々な地雷が待ち受けている（最悪OS再起動に失敗する恐れがある）ため、結局nginx芸で特定のパスだけ1台に集約する方針をとりました。
ここからしばしジリ貧な感じで、
- MySQLのmax_connectionを増やす
- nginxやMySQLが悲鳴を上げ始めたのでOSのlimitを変え始める
- pumaのworkerやthreadを増やす
- サーバー構成を nginx+puma( POST /profile 専用) 、puma(それ以外)、MySQL&redis に変更（役割が分かれて見通しがよくなった）
- jsやcssもgzipで返すようにnginxのconfigをかえる
等々色んな事を試したのですがスコアはほぼ変わらず。その間にひたすらコード改善やredis化やpumaのunix domain socket化などなど色々やってもらいつつスコア伸び悩みの原因を探り、事態が打開されはじめたのが18時か19時頃。
- GET /fetchに含まれるsleep 1をやめる（正確にはやめたわけではないけど）
- 画像やjs,css等に対して考え得る限り304 Not Modifiedを返すようにした
この辺が入った事により一気に8〜9万点台まで上がりました。後者がログを見る限り19:53の出来事。これが個人的には最大の反省点で、あまりにも遅すぎたと思っています。
というのも、nginxの設定によりベンチマーカーに304 Not Modifiedが返るようになり帯域等のリソースが大幅に節約できることを過去問題で練習した時に知っていたのですが、当初Chromeのdeveloper toolで様子見したときに304が返ってくる様子を目撃していたため、設定はそのままでも良いかと思い込んでいたのです。「本当に304返ってる？」と突っ込まれてよくよくログを調べると全然304を返しておらず、慌ててnginxの設定を再確認したのがこの時間でした。この辺はレスポンスコードの統計とか取っとけばもうちょっと早く気づけたね。
このあたりでベンチをガンガン回し始め、MySQLの載っているサーバーのLoad Averageが10を越えるようになり、CPUリソースをほとんど使い切った状況に。
スロークエリは全然出てないし、max_connectionを極端に上げなくてはならない状況からするとクエリというかコネクション数自体が異常かなぁ、という辺りでタイムアップに。最後に再起動試験とか不要なプロセス止めたりとかしましたが、良くも悪くも大した影響はありませんでした。
結果
- 最終スコア:
8261979,590 - ベストスコア: 94407
※自力で最後に撮ったベンチ結果のスクショと、公表された最終結果が異なったので最終結果のほうに修正しました（10/24 14:40追記）
んで本選出場権をゲットできたチームはこちら。
一般枠のボーダーラインは210472点でした。というわけで43位。うーむ、ざんねん。
感想
やるからには予選突破したかったなぁというのが正直なところですが、本番や練習を通じて普段触らないような部分に詳しくなれたり、逆にこれまでの経験が生きてきた部分もあるかなと思っていて（OS再起動時にプロセスがちゃんと上がって来るように気をつけようとか）、一定の成果は得られたかなーと思います。練習を繰り返すことで本番に向けて改善のプロセスを回すことも出来たしね。
足りなかった十数万点はおそらくひとつチューニングがハマると指数関数的に効果を発揮するものだと思っていて、そのあたりは他の方のエントリを参考にしようと思います。特にDBコネクションプールの辺りはタイムアップで消化不良感が出てしまったし、事前準備で盛り込み切れなかった点のひとつなので。チームの方針としてruby以外の他言語の実装を試す時間を省略したので、他言語の様子がどうだったのかなーというのも確認してみたいと思います。
最後に運営の皆さん、予選用の場所と練習用サーバーリソースを提供してくれたアニメイトラボ社、そして誘ってくれた id:macotasu と一緒に出場してくれた id:naught00 に感謝です。ありがとうございました！
