チームおにやんま - ISUCON6予選敗退しました

今年もいすこんに参加してきました。
運営メンバーのみなさま、今年もありがとうございます。

ISUCON5から今回までの準備はこちら
techblog.karupas.org

より突っ込んだ感想などはid:karupaneruraがまとめてくれるので、わたしは当日のチームの動きについてざっと書いておきます。

準備

前日の主にAzureまわりについて軽く。その他の準備についてはこちら。

前日までのAzureでの素振りは（matsuuさんが素振り用テンプレートを公開してくださるまでは）自分たちでひととおりGUIから用意していた。
ただエントリーが開始になって、案内のメールに

・開始時刻になると、ログイン後の画面にて予選用イメージURLが閲覧可能となります

と書いてあり、全部いりのテンプレートが来るのか「VMそのもののイメージURL（vhd）」がくるのかわからなかったので、とりあえず同一RG内に人数分のVMを用意できるような準備が必要かなと深読みしてスクリプト化した*1。
isucon6-qualifier/tools/azure at master · karupanerura/isucon6-qualifier · GitHub

当日の動き

08:30-09:00

集合。朝ごはんを食べ、お昼を買い込む。

チームあさやんま #isucon #きょうのもちもち

09:00-10:00

わりと余裕を持って準備。
もともと自分のサブスクリプション上で予選のすべてのリソースをまかなうつもりだったけど、VM立ち上げ+コピー時に事故るとつらいので、他メンバにRG作成+招待まで行っておいてもらった。

10:00-11:15

前述のコピースクリプトを打つにはいったん deallocate しないといけないので、まず立ち上げて動作確認&コードのコミットをすることに予め決めていた。
ベンチも回しとこうと試してみるものの、タイムアウト頻発で fail して、そんなはずは…と思い他言語で試してみるものの、fail。
その間に、何かあったときにすぐ移れるようにバックアップとしてもう一つRGを作り、デプロイしつつ、メインのVMを deallocate。
スクリプトを走らせてみるものの、CLIから取得したイメージのURLが404でコピーがかなわず*2、20分ほどハマってRG量産プランに変更。
id:ofsilvers にはバックアップ機で作業してもらうことにして、そこで再度ベンチを走らせたところ、何もしてないけどスコアが出た（2500くらい）。
「これが…インスタンスガチャ…！」

11:15-12:00

id:karupanerura 謹製の ansible も上記のわたわたで流せておらずプロファイルが取れていなかったものの、ざっとサービスを見た&コードを読んだ状態でやれそうなことをホワイトボードに書き出し。
それぞれの大まかな対応方針もそこで話し、仕掛かる順番はプロファイリング後だねということでいったん待ち。
その間に id:karupanerura は nginx/mysql まわりの conf の反映を、わたしは足す予定だった table（entry が持つ keyword のリスト）の定義をさくっと作ってコミット（これは結局使われなかったけど）。

12:00-15:00

プロファイルを取って、htmlifyの `SELECT * FROM entry` が重い（知ってた）から潰していくことに。
まず keywords だけ取ってくるようにしてから、ソートされた keyword だけをプロセスキャッシュした（45000点くらい/エラーあり）。
プロセス跨いでキャッシュしようということで memd に入れ替えたらエラーなし20000点ほどに下がってアレレとなる。
ミドルウェアあたりの問題が少なそうということで、手の空いたid:karupaneruraが isutar の N+1 クエリを、id:ofsilversが各 table の index をいいかんじにしてくれていた。
keywords のキャッシュを終えたあと、トップの記事表示のクエリ（SELECT * FROM entry + limit + offset + order by）の改善とかもしてみたけど大してスコアに寄与せず。

15:00-16:00

やっぱ htmlify の処理が重いね、とまずはごっそりキャッシュしてみる。
更新系のリクエストがきたタイミングでキャッシュは破棄する必要があったけど、破棄するより（エラーは出るけど）そのまま突っ走るとスコアが上がることに気づく（90000くらい）。コードはいったん破棄のままで。
そして isutar はいらないこだったので isuda に寄せる（このとき keywords で引くのではなく entry_id で引くように変更）。38000くらい。
そのすきにid:karupaneruraはKYTProfうったり、systemd まわりの ansible 化（task:perl が爆誕）をしてくれていた。

16:00-17:00

いったん手を止めて話し合う。
17:00になったら再起動することを再確認して、
結局ボトルネックは/、スロークエリには SELECT COUNT(*) がでていたことからカウント取るくんを Redis に置くなど。
このあたりでキャッシュ時のシリアライズに失敗しだして慌てる*3。
id:karupaneruraは一念発起してワーカー書くぞ！！となっていたのでどうぞどうぞする。
id:ofsilversはベンチと動作確認のかたわら mysql dump / restore などをやってくれていた。

17:00-18:00

再起動テスト、細々した改修（プロセス数の調節など）をしつつ、点数が出る構成にシフト。
memd を全廃してプロセスキャッシュに入れ替える。
ここで初期データをキャッシュにのせるの忘れてた！となり慌てて用意を始める（入らず。無念）。
worker 実装も Redis やばい、ビジーループ起こしててやばいとの声が隣から聞こえてくる*4。
わたわたしながら終了を迎える。

18:00-

反省会。
反省会中に結果が出て愕然として、sshしてみると確かに Perl の service が立ち上がっておらず 502 を返していた…。

感想

はーくやしい。くやしいけど、これが実力。これが ISUCON です。
反省点として一番大きいのは、htmlify の根本改善にほとんど手をつけられなかったこと。
キャッシュしたタイミングで CPU はりつきを解消できなかったことにもっと目を向けるべきでした。
Response time やスロークエリ以外の指標についての方針も定めておきたいところ。
あとはどうみても「はてなキーワードを支える技術」なのだから、とりあえずぐぐったらなにか知見が得られるはずというところに気づけばよかったですね！

しかし、1年分の素振りは主にオペレーションの面でしっかりと効いており、かなり手応えを感じられました。
今回は「できることをやって点を稼いだ」という感が否めなかったので、次はしっかり根本的なアプローチを画策しつつ点を稼ぐという二輪でやっていきたいです。

…と、こうして次回があることを期待してしまうのは心苦しいところもあるのですが、本当にステキなイベントなので、ぜひ来年もよろしくお願いいたします…！