ISUCON12 予選敗退しました

どうも。Sazaです。

ISUCON12 予選に参加しましたが、スコア 0 点で敗退しました。

メンバー

@Saza_xxx: 主にインフラ担当
@energy_saving0 : 主に app 担当
@moririn2528_c : app 担当

やったこと

余裕なくて他のメンバーがやってくれたことはちゃんと追えてないので自分がやったことだけ書きます。

10:00 ~ 11:00

僕はひとまず開発環境の構築をしました。開発は VSCode SSH Remote を使ってサーバー上でやりました。最近知ったんですけど、ISUCON10 とかみたいにメモリ 1GB ぐらいのシビアな環境だと VSCode まともに動かせないっぽいですね。今回は 2 コア 4GB のインスタンスだったので耐えました。

導入したプロファイリングツールなどは以下の通りです。

top: サーバー全体の負荷を見る
alp: nginx のログを分析する
mysqldump: MySQL のスローログを分析する
pt-query-digest: MySQL のスローログをさらに詳細に分析するときに使う
pprof / gprof: Go の中でどの部分が重いのかを見る
measure: Go の中でどの部分が重いのかを見る2 (measuregen を使って仕込んだ)
goone: N+1 を検出する
sqlstr: ソースコードから SQL を抜け出す

ヒントは多い方がいいと思って色々入れたんですが、pprof とかは今回あんま見てなかったですね。

11:00 ~ 12:00

今回のやらかしポイント1。なんか MySQL のスローログが出なくてクネクネしてました。いつも SET GLOBAL を使ってスローログの設定をしていたんですが、isucon ユーザーに SUPER 権限がなくてできなかったので my.cnf をいじって設定しようとしたんですが、なんか設定が反映されなくてどうしよ〜って言ってたら1時間ぐらい経ってしまいました。結局、12:00 ぐらいに運営から質問への回答として、MySQL に root でログインする方法が与えられたので、それによって isucon ユーザーに SUPER 権限を与えてスローログ出すことに成功しました。

12:00 ~ 14:00

ようやくスローログを見ると、visit_history から SELECT するクエリが鬼のように重いのを発見してどうにかしようとしました。コードを読んでみると、visit_history は「各ユーザーが各大会に対し最初にランキング表を見たのがいつか」というのを参照するために使われているのに、ランキング表が閲覧されるたびにアクセス元ユーザーがどの大会のランキング表を見たかを記録していました。そのせいで、visit_history に無駄な INSERT やら MIN 演算やらがされていたので、データの持ち方を変えることで負荷を落とすことができそうだと考えました。
まず、visitor というテーブルを作り、そこに「各ユーザーが各大会に対し最初にランキング表を見たのがいつか」という情報をそのまま格納するようにしました。そのためには、まず visit_history の初期データから visitor にデータを移してくることをしないといけないので、その処理を /initialize でやるようにしました。すると visit_history のデータが多すぎて /initialize がタイムアウトしてしまいました。よって MySQL に CLI で接続してこのデータ移行をやったんですが、なんかベンチマークの整合性チェックでひっかかりました。ちゃんと /initialize 時にデータの初期化をやっていたつもりだったんですが、色々原因探して試してみてもずっとベンチが通らなかったので、「さてはデータ移行しようとしてもうまくいかないという罠だな〜！？」と思って諦めてしまいました。後日解説を見てみるとデータ移行できるよって書いてあってアになりました。なんでうまくいかなかったんだろう......

14:00 ~ 14:30

で、visit_history の SELECT が遅い問題はどうしたかというと、普通にインデックス入れるだけでも十分のような気もしたので、インデックス貼ってみるとしっかり負荷下がってました。早めにデータ移行諦めてインデックスに逃げればよかった...。今回のやらかしポイント2でした。

14:30 ~ 15:00

チームで話し合って、そろそろ複数台構成手をつけ始ようかということになって、僕はとりあえず MySQL を 2 つ目のサーバーに移行しました。これまでの修正によって MySQL の負荷はすでに大したことない状態になっていたのでスコアはほぼ変わりませんでした。

15:00 ~ 15:30

measure の計測結果を見てみると、Cache-Control: private をヘッダに付与する処理が app 側に書かれていて、これが結構重くなっていたっぽかったので、Nginx にやらせるようにしました。

15:30 ~ 17:00

ここから本格的に複数台構成に取り掛かっていきました。top の結果から、MySQL より app (と SQLite) がめっちゃ重いという状態になっていたので、app の処理をうまく各サーバーに分散させる必要がありました。今回は各テナントの情報が SQLite で保存されていたので、何も考えずに Nginx でトラフィックを各サーバーに分散させるとデータの整合性が取れなくなってしまいます。ここから SQLite を MySQL に移すの時間はないので、SQLite のまま処理を分散させるためには、リクエストをテナントごとに各サーバーに振り分けるということをする必要がありました。

具体的には、Nginx の設定で、テナント名が a~l, A~L のリクエストは 1 台目のサーバーに、テナント名が m~z, M~Z のリクエストは 3 台目のサーバーに振り分けるということをしました。(今書いてて気づいたんですがテナント名が数字で始まるパターンがないか確認してなかったですね...)
これをすれば 1 つのテナントに対してその情報が複数のサーバーにバラけてしまって整合性がなくなるという問題はなくなります。
ところが、この構成でベンチマークを通すためにはまだまだやることがありました...。

/initialize を他のサーバーにも飛ばす

ベンチマークの最初に叩かれるエンドポイント、/initialize では DB の初期化処理をしていて、これでベンチマークを実行するための DB の状態を作っています。DB が MySQL だけの構成なら一つのサーバーに /initialize を送るだけで十分なんですが、SQLite の初期化をするためには SQLite を動かしているすべてのサーバーに対し /initialize を送る必要があります。
そのため、ベンチマークから /initialize を受けるサーバーから、もう一方のサーバーに /initialize を叩くということをしていました。最初、この処理を Nginx にやらせようとしていたんですが、そうすると /initialize を転送する処理が非同期で行われるっぽくて、/initialize が完了する前にベンチマークが走ってしまい整合性チェックで落ちるという問題が発生する、などというトラブルに見舞われて時間を溶かすなどしていました。悲しい。

テナント作成を他のサーバーにもやらせる

admin のエンドポイントに、テナント作成をやってくれるものがあって、そのときに SQLite の DB が作成されるようになっていました。admin は a から始まるので、admin のリクエストはサーバー 1 に振り分けられます。そのため、SQLite のテナント DB はサーバー 1 にしか作成されなくなってしまい、サーバー 3 に作られるはずの DB が存在しないというエラーが起きます。これに対応するため、テナント作成時にもう一方のサーバーの API を叩くことでその DB を作らせるということをしました。
後で解説を見たら、テナント作成時に DB を作成しなくても、あるはずの DB が存在しないと分かったタイミングで新たに DB を作ればもっと楽にできたようです。思いつかなかった...。

17:00 ~ 18:00

この時点での自チームのスコアが 8600 ぐらいで学生 5 位のチームが 10000 ぐらいという状況でした。app 担当の 2 人からはもう手をつけられそうなところないとのことで、ここはもう残りの 1 時間で処理の分散をさらにいい感じにすることで予選突破できるのでは！？という感じでした。そこで、サーバー 2 は MySQL しか動いておらず、まだリソースに余裕のある状態だったのでこいつにも app の負荷を分散させようとしました。
Nginx でサーバー 2 を admin からのリクエストだけを処理させるようにして、残り 2 台でそれ以外のテナントの処理をさせるようにしました。残り 1 分の時点でその修正が完了し、なんとか最後にベンチを走らせた結果、Fail でした...。後で見てみると、他のサーバーのテナント作成 API を叩くとき、リクエスト先の IP アドレスを間違えていました...。今回のやらかしポイント3。

反省

という感じで終わりでした。

振り返ってみると、実装力不足とか知識不足のせいで時間を無駄にしていたことがかなりあったなと思いました。スローログ出せずに 1 時間も止まったり、visit_history のデータ移行で 2 時間も止まったりしていたのは本当にひどかったです。my.cnf いじる練習をもっとしとくべきでした。

複数台構成で詰まった原因として、まず「そのシステムがどういう構成でどういう仕組みで動いているのか」ということに注意を向けなかったことがあるなと思っていました。どんなタイミングで SQLite の DB が作成され、どんなふうに接続されるのかとかを最初に確認しておきたかったです。SQLite にインデックス貼れなかった原因もそれですね。

あと、終わった後は、「SQLite のせいで複数台構成失敗したやんけ〜」とか言い訳してたんですが、解説とか見てみると SQLite のまま、MySQL だけ他サーバーに分離するだけでも、app 側をいじるだけで十分ハイスコアを狙えるようでした。app 側でなかなか芯食った改善ができなかったのも厳しかったです。当日マニュアルにキャッシュ貼っていいよって書いてあったのでやればよかったです。

今回の問題は非常にトリッキーな内容でしたが、それによって過去問素振りだけで身につけた付け焼き刃の知識が通用しないものになっていたと思います。完全に実力不足でした。

来年は絶対決勝行きたいです。