私が歌川です

@utgwkk が書いている

ISUCON12 チーム :old_noto_innocent: で本選に出て7位だった #isucon

ISUCON

最終スコアは167,491点で、7位でした。あともう1手ぐらい打てれば上位入賞できたかもしれません。

本選の問題

今回の本選の問題は、育成型放置ゲーム「ISU CONQUEST」の高速化でした。ブラウザから動作確認するとUnity製のゲームが動いていておもしろかったです。

www.youtube.com

最終的なサーバー構成

今回の本選ではサーバーが5台与えられました。

  • 1
    • App (Go)
    • nginx
  • 2
    • DB (MySQL, users.id % 3 == 0 用)
  • 3
    • DB (MySQL, users.id % 3 == 1 用)
  • 4
    • DB (MySQL, users.id % 3 == 2 用)
  • 5
    • App (Go)

やったこと

リポジトリはこちらです。

github.com

分析グッズを導入する (10:45)

予選のときと同じ分析基盤を使うためにアプリケーションコードを直してまわりました。具体的には context.Context を引き回すなどです。ひと通り導入できるまで時間がかかってしまっているのは今後の課題ですね。

ここでプロファイラやトレーシングの様子を見ると、明らかにDBがボトルネックになっており、とくに POST /login や POST /user が重たすぎる、ということが分かりました。まずはそれらのエンドポイントから改善していくことにしました。

プレゼント付与・ログインボーナスまわりのN+1クエリを解消する (11:26)

プレゼント付与処理 (Handler.obtainPresent 関数) やログインボーナス受け取り処理 (obtainLoginBonus 関数) でN+1クエリが発行されていたので解消しました。受け取り済かどうかの判定をテーブルからSELECTしてきてあとで使うぐらいなので、ここはサクッとできました。

プレゼント付与時にbulk insertする (11:53)

N+1を解きほぐしたあとはbulk insertするようにしました。INSERTするものがない (スライスの長さが0) ときに NamedExecContext を呼び出すとエラーになるので気をつけましょう (1敗)。

このあたりで10749点を記録しました。

user_present_all_received_history テーブルに複合インデックスを貼る (12:05)

プレゼント付与時の以下のクエリが重たく、EXPLAINしたらインデックスが足りなかったので足しました。

SELECT * FROM user_present_all_received_history WHERE user_id=? AND present_all_id IN (?)

このあたりで20264点を記録しました。インデックスを足すだけで1万点ぐらい上がってて景気がいいですね。

アイテム付与処理を解きほぐしながらクエリ発行回数を減らす (13:37)

アイテム付与処理は、付与対象のアイテムの item_type カラムの値で分岐しつつ、別々のテーブルにクエリを都度発行するという実装になっていました。ここを解きほぐさないと先に進めなさそうでしたが、見るからに手をつけたくない雰囲気をかもし出していました。まあ、手をつけないといけないんですが……。

以下のような作戦でロジックの解きほぐしとクエリの効率化を進めました。

  • アイテム付与処理を管理するstructを作る (ItemObtainer struct)
  • ループ内のアイテム付与関数の呼び出しを置き換える*1
    • 同じシグネチャで呼べるようにする
    • 付与するアイテムのリストを溜めておく
  • ループを抜けたときに一括でクエリを発行できるようにする*2

元々の関数と同じような返り値を保持するならスライスの順序を保持する必要があるのか？ と思いましたが、よく見ると返り値を捨てていたので気にする必要はありませんでした。

このあたりで43862点を記録していました。

DSNに interpolateParams=true を足す (13:50)

SQLのプレースホルダ置換を有効にするアレです。スコアが10000点ぐらい上がってウケました。

dsas.blog.klab.org

このあたりで54594点を記録していました。プレースホルダ置換は、ISUCONにおいては常に有効にすることにして初手で入れてしまってもいいのかもしれません。

users.id ごとにDBを分割する (15:28)

MySQLのCPU使用率がずっと高いままだったので、ユーザーデータごとにDBを分割するようにしました。

このあたりで119577点を記録していました。

アプリケーションを分割する (15:44)

アプリケーションのCPU使用率も上がりつつあったので、残っていたサーバーにアプリケーションを分割するようにしました。採番ロジックをアプリケーション側に寄せていたので、サーバーの番号をIDに埋め込めるように書き換えました。

このあたりで134670点を記録していました。

セッションキーに users.id の値を含める (17:23)

確率的にベンチマークの最初の整合性チェックが落ちる、という現象に頭を悩まされていました。たまにベンチマークが通るので、最初は気にしていなかったのですが、どんどん顕在するようになって焦ります。採番ロジックのバグや、ベンチマーカーのバグを疑いましたが、どうもそれらは違いそうです。

実は、先述したDB分割のさいにバグを埋め込んでいました。セッションキーを取得するときに、セッションキーを発行した先のユーザー用のDBを見ることができておらず、ベンチマーカーが意図したレスポンスを返せずに整合性チェックに通らなくなっていました。原因になかなか気づけなかったのですが、id:nonylene さんがトレーシングの様子と見比べながら原因を突き止めてくれました。今回のMVPだと思います。

最初は users.id ではなくセッションキーの頭文字に応じてDBを振り分ければよいかと思いましたが、セッションキーを再発行する処理でうまくいかない (セッションキーを全て無効化できない) ため、発行するセッションキーに users.id の値を含めてなんとかしました。競技終了が見えてきたタイミングでしたがなんとか修正できたのでよかったです。しかしヒヤヒヤした……。

分析グッズを剥がし、ログ出力を止める (～競技終了)

これ以上破壊的変更を加える余裕はなさそう、ということで分析グッズを無効化したり、echoのアクセスログを止めたりしました。それと並行して、ガチャのマスターデータのキャッシュ実装が途中までできていたので、バグを直しつつ投入して何度かベンチマークを走らせてみましたが (「これ以上破壊的変更を加える余裕はなさそう」とは何だったのか？？)、18万点ぐらい出たものの再起動試験に通らないことが分かったので導入を断念しました。

感想

ISUCONは2016年 (ISUCON 6のとき) から毎年参加していて、本選に出るのはこれで4回目でした。それなりに手は打てて、順位表の上から数えるほうが早いぐらいのスコアを残せるようになったのはよかったと思います。アプリケーションコードとトレーシングやプロファイラの出力を見ながら作戦を考えて (考えてもらい)、順に試す、というサイクルがうまく回っているのだと思います。今回は失格/failになったチームが多かったようで、我々もセッションキーの不具合に気づかないままだったら……と思うとヒヤヒヤします。

一方で、上位入賞を狙うにはもうちょっと手数や実装の精密さが足りていなかったとも思いました。とくに今回はDB分割まわりで競技終了ギリギリまで悩むことになるバグを埋め込んでしまったのが悔やまれます。以下はもうちょっと余裕があれば導入できたかもしれない作戦です。

  • プレゼント配布時にbulk updateする
  • DB接続まわりのパラメータチューニング
  • ガチャまわりのN+1クエリを解消する
  • マスターデータをキャッシュしまくる

キャッシュ以外は感想戦で試してみているけど、20万点は超えたものの30万点には届かないので更なるブレイクスルーが必要そう……。このあたりは上位入賞チームの作戦を聞いてみたいです。

今回も予選・本選ともにおもしろい題材の問題で、競技に取り組んでいてすごく楽しかったです。運営の皆様ありがとうございました。次こそは優勝したいですね。

*1:https://github.com/innocent-team/isucon12f/blob/4e886dacb90c23b5b03bfcfe927d32b9a77b0bc7/go/main.go#L633-L652

*2:https://github.com/innocent-team/isucon12f/blob/4e886dacb90c23b5b03bfcfe927d32b9a77b0bc7/go/main.go#L830-L845