#isucon2 に参加しました

#isucon2 に参加しました。とても楽しかったです。ありがとうございました。最終スコアは五位という結果に終わりましたが、うまくいったこともダメだったこともひっくるめて自分の実力は出せたので過程には満足しています。

事前準備

昨年の isucon では雰囲気に飲まれてほとんど何もできないままタイムアップを迎え、不本意な結果に終わりました。今年は去年の反省を踏まえて、チームメイトの @kentaro さんと @tnmt さんと事前にある程度の方針を決めて臨みました。

• 言語は基本 Ruby を選ぶ。仕事で使っているし、アプリケーションサーバの運用や rbenv などの周辺ツールの扱いにも慣れているので。とにかく手に馴染んだものを選ぶ。「なんとなくはやそう」みたいな曖昧な理由で node を選んだりしない。
• コードは GitHub にでも置いて、 Capistrano で一発デプロイできるようにする。そういう部分でもたつくと焦るので、足回りの整備は最初にやる。
• プロファイリングがネックで、 Perl なら Devel::KYTProf で丸裸にできるけど Ruby でそれに相当するものがあるか知らなかった。 New Relic に丸投げしては、というアイデアもあり前夜に準備だけしておいた (結局使わなかった)
• アプリケーションサーバの負荷分散は、おそらく昨年同様複数の role のサーバが用意されるだろうから割り当てを増やすのはアリだねと考えていた。
• データベースサーバについては MySQL だろうし、ふつうにスロークエリをチェックするとか設定パラメータを見るとか (余談ですがこれで Postgresql だったりしたらかなり戸惑うチームが多かったんだろうなーという)
• フロント静的キャッシュも選択肢にはあったけど (Varnish の ESI とか) たぶんそこまで手がまわらないだろうなーという感じ。実際それどころではなかった。
• キャッシュは去年整合性チェックでだいぶ苦しんだチームが多かったし、今年はキャッシュ一発で跳ね上がるみたいなのは避けてくるだろうからやれたらやる、くらいに考えていた。
• いろいろ意地悪な罠を仕掛けて来るだろうと踏んで、 DNS ルックアップが遅いかもとか、 ulimit とか、思いつくものは挙げておいた。

あと去年の反省で、ブラウザで実際にアプリが返すページを見ないままコードばかり追っていたので、重いクエリが具体的に何をしてるのか把握できず失敗したので、今回はブラウザで全部のページをひと通りみてコードと照らし合わせた。これは全体の概要を把握するのにとても役立った。

当日やったこと考えたこと

そんなわけで当日はこんな感じでした、というのを大雑把な時系列で。考えていたことややったこと、チューニング後のスコアなどは GitHub の wiki にメモを残していきました。これは後半に「いまどのチューニングまで適用済みだっけ？」というのを把握するのに役立ちました (あとブログ書くときも)

11:00

• とりあえずアプリケーションの配置などをみて、 ruby アプリケーションを GitHub のプライベートリポジトリに突っ込む
• Capistrano をセットアップしてる間にアプリのコードを読む

12:00

• public ディレクトリが symlink になってるので Capistrano のデプロイがこけて焦る
• config.ru に Unicorn の GC をリクエスト毎に走らせるという設定を発見して「きた！罠きた！はやいもう見つかったのか！これで勝つる！」と一人はしゃいだが無効化してもスコアが伸びず首をかしげる
• 懇親会で @tagomoris さんに聞いたら「すぎゃーんがアプリのチューニングしてるときに GC いろいろ試してて消し忘れたのでは。どのみち GC がネックになるようなお題ではなかったので関係ないし罠ではない」とのことで、これはだいぶハズしてしまった

13:00

• リバースプロキシを nginx に変えるとスコアが落ちたので首をかしげる。罠があるのでは、と疑うがログを活用しきれず原因究明できなかった
• 講評や懇親会でいろいろ聞いた感じだと、 nginx の性能がよすぎるが故に app にプロキシしすぎて app が過負荷で性能が落ちる、ということだった
• 真っ先に Sinatra にログを吐かせるべきだったのにそれをやってないのは今回最大のミスだった
• スロークエリが全然流れないので long_query_time = 0 にして眺める。この時点では詳しくチェックできておらず、「サイドバーのクエリが重いけどチューニングは難しいだろうな」という程度の把握だった
• Apache に戻したあと Unicorn ワーカー数 50 は多いよね？コア数か その *2 くらいまでで十分じゃね？と思って 2 にしたらスコアが落ちたので二分探索で 24 ~ 36 あたりで安定。スコアが多少伸びたのでほっとしてとりあえずお昼ごはんを食べる。
• とりあえず WHERE 句の条件でインデックス張ってないものがあるので全部インデックスを張り少しスコアが伸びる

14:00

• Apache のリバースプロキシ先アプリの指定を hostname から IP アドレスに変える。 DNS ルックアップ的な罠がないか調べるためにとりあえずやってみるか、という感じ
• リバースプロキシサーバでも app を動かして三台体制で負荷分散する。分散比率は何度か試して rev:app1:app2 = 1:2:2 にした
• みんな言及していた ORDER BY RAND() は午前中のコードリーディングで気づいていたのでここに手を入れる。ここは自分の担当で、今回唯一結果を出して貢献できた部分だった。思考の流れはこんな感じでした:
• order_id IS NULL で RAND() ってことは別にランダムである必要ないよね？ ORDER BY id でいいんじゃないの
• でも連番で順番に割り当てていくだけならトランザクション張ってロールバックする必要なくね？どうしてこうなった
• 10人同時に買いにきたとき ORDER BY id で同じ id を10人に返したら9人ロールバックするのか！なんかまずそう
• ランダムに選ぶのはそのままで、そこを Ruby でやらせる。 SELECT id FROM stock WHERE ... AND order_id IS NULL で空席とってきて Array#sample でランダムに一件取得して UPDATE ... WHERE id = というクエリに変える
• これでスコアがそこそこ伸びた

15:00

• 静的コンテンツを httpd から直接返す
• このくらいの時間帯は自分はずっとアプリをいじっていたので詳しく把握してないけど、静的コンテンツの配信をちゃんとやるとまたスコアが伸び悩んであんちぽさんとつねさまが首をかしげていた。後から考えると、これも app へのリクエストが増えすぎてタイムアウトエラーが増えた、とかだったのかもしれないけどログで計測してなかったので原因がわからずじまいだったのが敗因だった

16:00

• 少し前に話題になった Ruby 1.9.3-p194 にパッチを当てると Rails アプリが 20~30% 高速化するというのを試してみようということで Ruby をビルドする。これもそこそこ効いて、概ね想定通りスコアが伸びた。
• 例の table タグを組み立てる部分が 64*64 のループでいかにも遅そうなのでここの改善に取り組む。ここも自分が担当して、手こずりつつも実装できたのだけど fail になってしまい無念の revert をした。思考の流れはこんな感じ
• app 側でハッシュの配列に突っ込む、ここでまずループしている
• テンプレート側でそのデータを展開して table タグを作っているけどこれループ一回でよくね？
• app 側で table タグを文字列連結で作って丸ごとテンプレートに投げればはやくなりそう？
• なんと tr の開きタグと閉じタグの位置を判定する部分でハマってだいぶ時間を無駄にしてしまった。テーブルがガタガタになったり、一列減ったり。アホすぎる
• どうにか完成させてデプロイするものの fail で、調べる余裕が無かったので revert してしまったけど、これは結局 app で時間のかかる処理をしてることには変わりないのでタイムアウトが頻発してしまったのかなーという感じ
• HTML のホワイトスペースも判定されるのか調べる意味で slim の pretty を off にするなども

17:00

• db サーバもお昼ごろに innodb_buffer_pool_size 2G を発見してメモリ 16G もあるんだから増やそうぜと何も考えず増やしていたけど、上記のテーブルタグを作ったりしてるときにふと、データサイズ小さいからメモリ割り当て増やす意味なくね？と思って db サーバでも app を動かす提案をする。 bundler が入ってないとか足回りで多少もたつきつつもなんとかぎりぎりで間に合わせることができた。これも割り当て比率を安定させて最終スコアを出したのと同じ構成になった。
• お昼前から何度かトライしてはうまくいかず revert していたキャッシュの導入を最後の三十分でもう一度トライした。しかしやはり fail になってしまうのでこれも無念の revert でタイムアップ。キャッシュの実装を引き継いでなんとか間に合わせたかったけど力及ばずだった。

結果

最終スコアは

1631 tickets
score:301347

でした。最後の画面に出ていたスコアを目視したところ五位でフィニッシュ。チケット枚数実績から想定するとベンチ時間はたぶん一分だったと思います。自己ベストは

1639 tickets
score:299875

でした。

やってみてよかったこと

• Capistrano 導入はよかった。デプロイが誰でも一発だし時間も手間もかからず、 supervisor restart までできるのでとにかく楽でトライ & エラーしやすかった
• ORDER BY RAND() の改修でスコアが伸ばせた
• 三人チームでいいかんじに役割分担できた。 @tnmt さんがミドルウェアまわり、僕がアプリケーションとクエリまわり、 @antipop さんはそれら全部と足回りの整備で、無駄に暇してるようなことがなかった
• 事前のブリーフィングなどで方針を決めておいたので大筋ではやることを順序立てて決めて実行していくという流れができて、現地で迷うことが少なかった

よくなかったこと

• アプリケーションのログを出さなかった。これちゃんとやってログしっかりみてれば... という後悔ポイント多数
• ログ以外でもボトルネックの調査が中途半端だった。アプリの CPU 負荷が高いなら具体的にどの処理が重いのかちゃんと特定しきれないままコードをいじったりしてしまった
• 実装力が低かった (これは自分のことです...)
• これはいけるだろというチューニングをしても期待したほど結果が出なかったときに首をかしげたり、それがけっこう続いて焦ってしまった

感想

こういうスプリント勝負は「迷ったら負け」なんだなーと実感しました。今回自分としてはそこそこ健闘できたと思っていて、それはやはり迷って手が止まっている時間が少なく済んだからかなーと思っています。上位の話を聞いても、 Redis 載せ替えの大改造をした @typester さんも一プロセスのアプリが全てオンメモリで処理するというこれまた大改造をした @nihen さんも、最初からやると決めていたようなので、ボトルネックの見極めの的確さや実装のはやさ正確さももちろん大事だし最終的にはそこで差がつくわけですが、まず決断がはやくないと勝負の土俵に立てないのかな、と思いました。

それからこれも @typester さん @nihen さんの話を聞いていて感じたことですが、普段から仕事なりプライベートなりで扱い慣れているものを使うのも最善手を打ち続けるためには必須で、だから普段から経験を積んで引き出しを増やしておくことが大事なのかなーと思いました。ここは自分たちも扱い慣れている Ruby を選択したのは正解だったと感じています。

あと上位はやはり役割分担もきっちりしていて、個人の能力を最大限引き出せているあたりでもレベルの高さを感じました。去年の藤原組のコメントで「すぎゃーんがアプリを大改造していて完成したけど結局 reject した (にもかかわらず優勝した)」という話が印象に残っていて、堅実なチューニングをしつつ一方でトライする作業も進める、というのは良さそうだなと思っていたので、今回はなんとなく自分がそういう役回りを受け持ったのですが力不足だった、という感じでした。その点、藤原組は @fujiwara さんと @songmu さんが確実にスコアを伸ばす間に @typester さんが実装を進めてうまくいった、という勝ちパターンだったし、 @nihen さんの山形組も同様のアプローチで、判断力と実装力のどちらも活かせたチームが良い結果を出したのかな、と思いました。

最後に

いろんな方から弊社のいろんなひとが「次は SqaleCon やってよ」などとリクエストをいただき、社内でも話題にはあがっています。 isucon レベルのガチなコンテストでなくとも、 Sqale で何かやりたいなー、とは思っています (何の確約もできませんが)