ISUCON9 参加記

TL; DR: 初参加にしては頑張ったので褒めてほしい。

ISUCON9に参加したので、大会前と大会中と大会後に何やったかを書く。

開催前

@_nemohem@fplwdが ISUCON9のメンバーを募集していたので「入れて入れて〜」と言って入れてもらう。まともなWebサービスの運営はほぼ経験が無いが、「知識を得ることが目的」とのことだったので、気軽に参加した。

気軽に参加したあと、本戦の開催日にはすでに予定があるので参加できないことがわかり、土下座するなどした。大変申し訳ありませんでした。

Golangを選択するということが予め決まったので“A Tour of Go”を流し読みするなどする。それから、前から気になっていた「みんなのGo言語」の第二版が出ていたので買ってベンチマークのところを読み、そこに書いてあった Profiling Go Programsを読んでpprofを知った。

あと開催の少し前に集まって練習する予定が、偏頭痛でドタキャンして土下座するなどした。その節は大変申し訳ありませんでした。二人のご厚意で、本番2日前にも集まることが出来たので顔合わせをしつつGolangの過去問を解いたりした。その時の感じから、@fplwdがインフラ、 @_nemohemと筆者がGolangアプリという担当に決定した。

開始直前

行きの電車の中で、複数台構成のためのNginxの設定を調べる。 upstreamproxy_pass を使ってよしなにすればいいらしい。ふーん。とりあえず知識だけ仕入れて現場に入る。

10:00 開始

開始。@_nemohemに鯖を立ててもらっている間にマニュアルを読む。ちんたら読みつつ /initialize のレスポンスに謎の Campaign キーが生えていることだけを把握する。このあたりで鯖が立ったので「負荷は自分で決めるらしいよー」「まじー?」という会話をしつつSSHする。 ls に色がついていなかったためキレつつ alias を設定するなどしていた。

今回は初めに動いている言語がGolangだったので、そのままベンチを回す。 2千数百点付いた気がする。過去のISUCONではGolang版は0点スタートというのも珍しくなかったので、わりと取り組みやすいのかなぁなどと考えながらとりあえずコードをgitに載せGitHubのプライベートレポジトリにつっこむ。ついでにpprofも仕込んでプロファイルをとる。 getNewCategoryItems が遅いっぽいのでコードを眺めるとN+1になっているっぽい。解消するためにSQLをゴニョゴニョし始める。

11:00 getNewCategoryItems のN+1を解消

とりあえずitemとuserとcategoryを INNER JOIN すればええやろとばかりにSQLを書き始めるが、 sqlx を知らなかったため、解読とコーディングに時間がかかった。ついでにcategoryは親カテゴリー名を取得するために再帰的なコードが書かれており、 SQLに落とせない。最終的にsqlxをsqlっぽく使う初心者丸出しコードで itemとuserのinner joinだけを書き上げ、投入してベンチを走らせるがSQLが間違っている。ぐだぐだのまま12時台へ。

12:00 N+1の解決と500エラー

結局1時間以上使ってなんとか動かしたが、謎の500エラーが /buy/sell に出て思ったよりもスコアが伸びない。負荷が足りないのかと Campaign1 にセットするがやっぱり伸びない。ついでにToo many connectionsのエラーが出たので@fplwdに対応してもらうなどした。

あとから聞いた話によると、DBのロックのかけかたがまずくデッドロックが起こっていたらしい(?)。結局これには最後まで気づかなかった。

何度かベンチを走らせても伸びないので、諦めてご飯を食べに行く。店に入るほどの余裕はなかったのでローソンで冷やし中華を買って食べた。麺がゴムっぽかったが、お腹も減っていたのでまあまあ美味しかった。タレで味がついていれば大抵の物は食えるんだなぁ。みつを。

13:00 カテゴリをメモリに乗せる

getNewCategoryItems のN+1を解決するためにはcategoryをよしなにしなければいけない。メンバーがcategoryテーブルに変更が加わらない(初期データの呼出しのみ)ことを見つけてくれたので、DBを叩いてcategoryテーブルの中身をダンプし、「categoryのidを与えると必要な情報を出してくれる関数のGolangコード」を出力するスクリプトをRubyで書く。これを使ってようやくN+1を解決した。長かった……。

14:00 遅いbcryptと6000点

このあたりでbcryptがアホ遅いことに気づく。以前Railsのチュートリアルをやったときに「動作時間で情報がもれないように、ハッシュ化されたパスワードの比較はどんな場合でも一定時間で終わるようになっている(≒わざと遅くなっている)」と読んだことを思い出し、これを通常の等号比較で行えないか検討する。しかし「ユーザにしてほしくないことは行いにくくする」というライブラリ作成の原則が bcryptに一貫されていて、脆弱性を仕込むことはできないようになっていた。仕方がないので「この部分は仕方がないんじゃなーい?」などと言いつつ諦める。

ちなみにレギュレーション上は「平分のままDBに保存しないこと」のみが規定されていたため、例えばbcryptのcostを下げるなどすれば対応可能だったようだ。残念。

さてpprofを見ると getUseSimpleID が重いらしいので SELECT 時に取ってくるカラムの数を減らす。またcategoryを全部取ってくる SELECT が遅いらしいので、またまたDBをダンプして関数に変換したりなどした。ベンチをとると、このあたりで6000点を越えた。

わくわくしつつnginxのキャッシュやらgz圧縮などを設定すると 3000点に落ちたり5000点に浮上したりと安定しない。仕方がないのでキャッシュとgz圧縮はなくして、複数台構成にシフトすることで点数を稼ぐことにした。

15:00 複数台でバグる

ベンチがアクセスしてくるサーバ(フロントエンド)で静的ファイルを配信し、 Golangが動く必要がある場合はバックエンド1台目に投げ、さらにDBを動かす必要があればバックエンド2台目に投げる構成に決定する。さっそくNginxを設定するが、そもそもNginxで複数台構成を(練習を含め)経験した人間がチームに一人もいないことに気づく。Golang側のボトルネックがほとんど解消していると感じていたこともあり、朝に upstream を知った筆者が設定することになる。

フロントエンドとバックエンド1台目はわりとすぐに動いてくれたが、バックエンド2台目の設定で詰まる。バックエンド2台目で動いているリバースプロキシ用の NginxとMySQL間の通信がうまくいかない。3人で頭を突き合わせてあーでもないこーでもないと言っているうちに1時間経過する。

16:00 複数台で動く

MySQLはunix domain socketで接続を待ち受けるらしい。知らなかったよね。これに気づいてからは早かった。ベンチを回すと6000点か7000点くらい出た気がする。やったぜ。

top を見るとバックエンド1台目がCPUを使い切ってることが分かったので、フロントエンドにも処理を肩代わりしてもらうことにする。これは upstream127.0.0.1 を追加するだけではだめで、フロントエンドとバックエンド1台目のどちらかにアップロードされる画像ファイルに、これらの両方からアクセスできるようにする必要がある。 ISUCON7のfujiwara組が同様の問題を upload/01/upload/02/ に画像を振り分けた上で Nginxでスイッチすることで解消していたのでこれを真似る。fujiwara組の nginx.conf は公開されていなかったのだけど、Google検索し続けたらどうにかなった。

「残り30分でも動かなかったら単一構成に戻す」などと言っていたのが杞憂に終わってよかった。

17:00 ラストスパート

残り時間が1時間を切ったのでランキングが見えなくなった。このあたりでベンチを回して9000点台が出た。うれし〜〜。

初めの方に有効化してバグったキャッシュとかgz圧縮とかを復活させる?という話をしていたが、下手にいじって壊すのが怖い。結局ここで最適化は打ち止めにして、ログの出力やプロファイルのコードを消してベンチを回し続けることにした。なぜかベンチが二回に一回failするのでドキドキしながらベンチを回していた。ついでに再起動試験をし忘れていたことに気づいたので慌ててやった。

最終的に17:45に9670点が出て、ここで打ち切りにした。 17:50あたりからポータルサイトが不安定になっていたので、「ここで止めて正解やったなぁ」などと話しながら、夕飯の場所を決めた。

終了後

無事終了。公式が立てた感想戦のDiscordを眺めながら「デッドロックとか起こってたんかへー」「非同期APIはさっさと返してええんやなへー」「bcryptはやっぱり手を入れるべきやったんかへー」などと喋っていた。ついでにボーダー予想もしつつ「ボーダーは1万2千点くらいかなぁ」「いやもうちょっと高くて1万5千点くらいじゃないー?」などと喋っていた。

適当なところで切り上げてモダン焼きを食べに行った。美味しかった。

食べている途中で結果が発表された。残念ながら予選敗退だったが、ボーダーが意外と低くて 1万点くらいだったので「非同期APIに気づいてればなー」「デッドロックに気づいてればなー」「bcryptに手を入れてればなー」などとほざいていた。

ISUCON9 オンライン予選 全てのチームのスコア(参考値)が発表され、予選をボーダーで通過したチームのすぐ下に点差210点で自分のチームが付けていたことを知り泣いています。

感想、あるいは来年への備忘録

始まる前に思っていたよりもいいところにつけた(全参加者の上位5.1%)ので個人的には満足した。Webアプリについて実戦経験が無くても、意外と付け焼き刃でできることはいろいろあるのだなぁと実感した。

Golang側の改善がほとんどpprof一本槍だったので、もう少しいろいろなツールを利用すればデッドロックに気づけたのかなぁと思ったり思わなかったり。あとNginxの知識とかDBの知識とか、諸々のWeb周りの知識が欠けているというのも実感としてあるので、どうにかしていきたいですね(ふんわりとした問題意識)。

大変楽しかったので、できれば来年も出たいなぁと思いつつ。

お疲れ様でした。