ISUCON12に参加して予選敗退した

2022/07/23に開催されたISUCON12予選に参加して61位で敗退しました。言語はNode.jsで13000点位になりました。最終的にApp+SQLite1台、MySQL1台の構成にしました。

isucon.net

当日の流れ

10:00頃

まずは環境を作成しないといけないためAWSGUIから作成。その間にルールを読むなどしました。

10:15頃

環境作成が完了した後はNodeJS実装が動くように設定変更してとりあえずベンチマークを回してみました。 結果は1989点で他チームは最大で3414点位に見えました。 Dockerで動いていることが分かり、MySQLとかもDocker内だとログ解析ツールが使いづらそうだなと危惧してた所アプリケーションだけDocker内で安心しました。

10:45頃

秘伝のタレやベンチ用スクリプトを投入したり、kataribeやpt-query-digestを導入したりして再度計測すると2938点となり、MySQL側が重いことが分かりました。

11:00頃

MySQLのインデックスが全然無いので張ってから計測すると2476点に落ちました。

11:30頃

スローログとかを読んでいるとREPLACE INTOという見慣れないクエリが実行されていたのでコード側を読んでみました。 すると、同じ値をひたすら入れようとしていてそこで生成されたIDを使っているようでした。 固定値にしたり、0からアプリでインクリメントしたりしたらfailしたので初期値を元と同じようにしてDBを使わずアプリ側でインクリメントするようにしたところ2854点と少し上がりました。Cache-Control: publicにして怒られることもありました。 また、docker環境にソースコードの変更を反映するためにマウントするディレクトリの追加とかもしました。

12:15頃

DBへの同時接続数とか良くあるよなと思い設定したり、JWTの検証用鍵を検証する度にファイルから読んでいるのを初期化時に1回だけにしたりしたところ3000点ちょっとになりました。

13:40頃

コードを読んでいるとSQLiteを使っているのを発見。なんとなく遅い印象があったのでMySQLに移行することを検討しました。 sqlite3-to-sqlというそれ用のスクリプそれでクエリに変換してMySQLに喰わせたところ、30秒どころか数分経っても終わりませんでした。1.dbが170MB、その他も合わせて340MBくらいのサイズがありとてもじゃないが終わらなそうなのでMySQLへの移行を諦めました。

14:20頃

SQLiteのまま高速化するために、一度開いたファイルを閉じないように変更しました。ついでにインデックスも張る処理を追加しました。 他にもvisit_historyは最小値があれば良いので既に値があれば追加しないようにチェックを追加したりSELECT *の所を必要なカラムに絞ったりしました。 結果3333点と少しだけ増加しました。

16:00頃

SQLiteのDBを作る際に毎度同じデータを入力として外部コマンドを実行しているので先にファイルを作っておいて代わりにそれをコピーしてくるようにしました。SQLiteのトレースログがあるが使っていないので削除しました。 他には/api/player/player/:playerIdで1個ずつcompetitonを取っている部分のN+1問題の解決や/api/player/competition/:competitionId/rankingでUserを毎回取っている部分のN+1問題の解決をしました。

キャッシュについても実装しました。 JWTの検証は重いはずなので同じトークンが何度か渡されてくる場合があることを確認し、検証に通った場合に結果をキャッシュしました。 /api/player/competition/:competitionId/rankingについては一部のクエリの結果が3秒遅延しても良いとあったので、マージンを取ってこのクエリの結果を2.5秒キャッシュするようにしました。ただし、rankAfter毎にキャッシュを作成する不調がありました。 注意点として、/api/organizer/competition/:competitionId/scoreが実行された場合はその結果が即時反映される必要があるのでその場合はキャッシュが不正になったことを記録して、不正な場合はランキング側でキャッシュを破棄する実装も行いました。 結果、3885とGoの初期スコアと思われるスコアより上になりました。

16:10頃

billingReportを作るときに中で毎回competitionを取るようになっていたので、呼び出し側で一括で取ってそれを渡すように変更しました。

16:20頃

SQLiteのクエリをMySQLに挿入するのはbulk insertになっていないからだと考え、INSERT文をまとめたところ、何かのサイズが足りないというエラーが発生しました。デフォルトで6Mだったこれを256MBに上げて再度実行したところ、VMが反応せずSSHもできなくなり、VMを立ち上げ直すことになり時間を大分浪費しました。

17:10頃

スコアがほとんど伸びないのでSQLite部分を改善しようとしました。 ファイルロック部分を改善しようとRead/Writeのロックを分離しようと考えましたがうまい方法は思いつきませんでした。

トランザクションを使おうとすると一度オープンした接続を使い回せないということでそこを元通りにしました。 トランザクションは書き込む側でのみBEGIN IMMEDIATEで開始し、読み込む側ではトランザクションもロックも利用しないようにしたところ9500点近くを取ることができました。 競技中はコミットしていないクエリの結果が読み取られない分離レベルなんだなと思っていたのですが、コメント通りだとplayer_scoreを読んでいるループ中でコミットされる不整合が発生するはずなので何故うまく動いていたかは不明です。

17:45頃

残り1時間は再起動試験を使用かなと思っていたのですが、結果的にVMを立ち上げ直す必要が生まれてちゃんと動いたことから実装を続けました。ただし、スローログやNginxのログの停止などはスコア向上のために行いました。 キャッシュを2.5秒から2.8秒に延ばしたり、SQLiteがjournalなるファイルを書き込んでいたので調べてメモリを利用するように変更したり、MySQLの同時接続数を16に増やしたりしたところ11686点になりました。

17:55頃

残り時間わずかだったのですがMySQLを他のVMに移すくらいならできるのではと思い、コンフィグを投入しAppのサーバから設定できるようにbindやユーザの設定を変更してApp側の環境変数も変更しました。 うまく動かなかったときに環境変数を戻せるようにしてから実行した結果、13000点を超えました。 この時、インデックスの設定を一切入れてなかったことに後日気付きました。

感想

事前準備としてprivate-isuを解いたのですが、あまりうまくいっていなかったので本番はそれよりかなり良くできたと思います。 コンテスト中はSQLiteからMySQL移行の部分でやりたいけどできないという部分でかなり時間を使ってしまった印象があります。ただ、ボトルネックを見てそこを改善するサイクルは回せていたと思います。 最終的にはボトルネックのrankingページなどが2.6s->0.6sくらいになったのは良かったです。

今回は一人チームで参加したのですが以下のようなメリット、デメリットがあると感じました。

  • メリット
    • デプロイやベンチ実行のタイミングの相談が不要
    • 変更内容の相談・議論が不要
  • デメリット
    • 人手が足りず、並列か可能な作業も直列で行う必要がある
    • 一人分の知恵しか使えない

メリットのデプロイやベンチ実行のタイミングの相談についても3台のVMを一人一台割り当てれば複数台構成にする前は解決する話なので、やはり複数人の方がメリットがあると感じました。