ISUCON 12 予選にチーム「brand new」で出場して、全体13位(学生のみだと2位)でした

学生チーム「brand new」で @otofune@github.com と @tosuke@github.com と出場し、全体13位(学生チームのみだと2位) / 30642点で、無事一般枠で本選に出場することになりました。使用言語は Go でした。

事前準備

事前に以下の問題を練習していました (解いた順)。

  • ISUCON 11 予選
  • ISUCON 10 予選
  • private-isu
  • ISUCON 11 本戦

これらの練習の中で、

  • 練習で全然 netdata を見れていなかったので本番はちゃんと見たい
  • 誰がどのデプロイをしているかわからない。基本的に rinsuki が iTerm で全ホストに繋いだタブで Broadcast Input を使いデプロイしていたが、終わったかどうかが rinsuki 以外は画面共有を見ていないとわからないし、rinsuki が忙しかったり昼御飯に行っていたり御手洗に行くタイミングだとデプロイができない。

という課題が見つかりました。

まずは netdata をなんとかしようと思い、最初に netdata cloud の dashboard を試しましたが、なぜか横2列にしかグラフを並べられず、例年3台構成である ISUCON では横軸をホストにすることが難しいのはよくないと考えボツになりました。

それでもめげずにインターネットをさまよっていたところ、netdata は適当なHTMLを書くとそこにグラフを埋め込めるということがわかりました。

learn.netdata.cloud

なので、即席で適当にグリッドでグラフを出すHTMLを書き、練習に使ったホストを起動し直してテストしていました。

HTML

<!DOCTYPE html>
<head>
<meta charset="UTF-8">
<title>Dashboard Kamiya</title>
</head>
<body>
<script>
const hosts = [
"/isu01/",
"/isu02/",
"/isu03/",
]
const s = document.currentScript.parentElement
const parent = document.createElement("div")
parent.id = "parent"
for (const host of hosts) {
const hd = document.createElement("div")
for (const graph of ["system.cpu", "system.ram", "disk.nvme0n1", "net.ens5"]) {
const d = document.createElement("div")
d.dataset.netdata = graph
d.dataset.host = host
d.dataset.commonMax = graph
d.dataset.commonUnits = graph
hd.appendChild(d)
}
parent.appendChild(hd)
}
s.appendChild(parent)
</script>
<style>
#parent {
    display: flex;
    height: 100vh;
}
#parent > * {
    flex: 1;
    display: flex;
    flex-direction: column;
}
#parent > * > div {
    flex: 1;
}
</style>
<script src="dashboard.js"></script>
</body>

ダッシュボードはこのような感じでした *1。

練習環境は特に FW がなかったので、netdata のエンドポイントに直接アクセスするために HTTP でホストしていた*2のですが、本番は AWS EC2 のセキュリティグループで 22 と 443 しか疎通しないようになっていたので、ダッシュボードをホストしているサーバーから SSH Port Forwarding とリバースプロキシをして事無きを得ました (そんな予感はしていたので用意はしてあった)。

また、前夜の思い付きでさくっとデプロイ用の Jenkins を立てて、そこからブランチや commit hash 指定で全ホストにデプロイできるようにしたところ、これがかなり便利でした。

(origin/ を使え！と書いてあるのは、練習中にrebase 等で force push した時に git pull で更新するとわけわからんことになった経験があったので、それを回避したかった)

というのも、古の時代(4〜6年前)に Web アプリケーションをとにかくボタン1つでデプロイしたいという願望に囚われ Jenkins からの SSH でWebアプリケーションのデプロイをしていた経験があり (今はやめた) 、その時と同じように Jenkins から各ホストにSSHしてデプロイ処理を走らせるようにすれば、みんなが現在のデプロイの状態やビルドログを見られる上に、簡単にデプロイをできるのではないかという目論見と、昔別れた味方が物語の佳境の部分で参加してくる展開はアツいという気持ちがありました。

また、デプロイログを Discord の webhook チャンネルに垂れ流しており、Jenkinsを見に行かずとも、コケた部分でどこが悪かったか/どこを見に行けばよいかを推測できたりしたのも良かった点です (initializeでコケた場合は Jenkins のビルドログを見に行くんじゃなくてアプリのログを最初から見に行けるなど)。

これは普通に通った時

これは Go のビルドあたりでコケた時

これは initialize 内処理をミスったっぽい時

最終的にこの Jenkins でのデプロイは 103 回行いました。

予選当日

当日はまずデプロイスクリプトを本番の環境に合わせることから始めました。

Jenkins 側からは git fetch, checkout, rebase をした後にリポジトリ内のデプロイスクリプトを呼ぶ形にしており、Jenkins 側をいじることはほぼありませんでした (途中で rebase master を追加したりログを追加したりはしましたが)。

この形にした理由として、Jenkins側のスクリプトは何も考えずに3サーバー分同じものをコピペしているので毎回3回コピペすることになるのはだるいというのと、ブランチによってデプロイしないといけないものが異なる場合があるためでした (あとデプロイスクリプトが前回の手動デプロイ時のものを継承していたという裏事情もあります)。

Docker 剥がし (@rinsuki)

今回は最初 Docker Compose でアプリが動いていて、network_mode は host になっているし*3、まあそのまま動くならそのままに、でも何かあったらすぐ外そうと考えていたところ、なぜか全サーバーで docker compose build を走らせた時に 01 のサーバーだけ BuildKit で走り 02 と 03 では BuildKit ではない旧来の docker build で走っていた (ように見えた) ので、ここで後々トラブルになったら嫌だな…と感じスッと Docker を剥がしました。

スコアは変動なしでした (3000点台)。

CSV 入稿の bulk insert 化 (@rinsuki)

次にすぐできそうだった CSV 入稿の bulk insert 化をしました。これは簡単で、そもそも for で NamedExec を呼ぶだけになっていたので for を外して NamedExec にスライスを渡すだけでした。

スコアは400くらい上がりました (3000点台→3400点台)。

MySQL をサーバー 02 に移行 (@rinsuki)

このあたりで htop を見たところ、mysqld が app に負けじと CPU を使っていたので、MySQL を 02 サーバーに移行したりしました。それでも MySQL が圧倒的にCPUを使っていましたが、ちょうどこのあたりで @otofune が ID 採番処理の改善を行い、ひとまず app 側が再びネックになる程度の重さまで軽減できました。

スコアは600点くらい上がりました (4000点台)。

JWT のキャッシュ (@otofune)

JWT の PEM を毎回パースしていたのを起動時だけに行うようにしてくれました。

スコアは150点くらい上がりました (4150点くらい)。

ID 採番変更 (@otofune)

MySQL に毎回問い合わせで採番しているところを UUID に変更してくれました。

@otofuneによると、どこかの問題で Go の ULID 生成ライブラリがロックを取っていて…という話だったのでできるなら ULID は避けたいなと思って調べたところ ID でソートしているところがなかったのでスパっと UUID にしたそうです。

スコアが2800〜3500点くらい上がりました (6970点〜7658点)。

SQLite のマイグレーションの機構作り (@rinsuki)

その後はテナントごとの保存データが SQLite に保存されているということがわかり、今後インデックスを貼ったりなどで既存データのマイグレーションが欲しくなりそうだと感じたので SQLite のDBのコピー後に全 SQLite データベースにマイグレーション用の SQL を叩き込むという Python スクリプトをささっと書きました。

なぜ Python だったかというと、似たようなバッチ処理を別件で数日前に書いたばっかりで、だいたいどういう感じで書けばいいかという勘があったためです (逆に言うと Go で glob 呼ぶ方法がわからなかった…が MySQL 移行の時に SELECT id FROM tenant したらいいということに気づきました)。

#!/usr/bin/env python3
import sqlite3
from glob import iglob

migrate_sql = open("./migrations/sqlite.sql", "r").read()

count = 0

for dbpath in iglob("../tenant_db/*.db"):
    count += 1
    try:
        with sqlite3.connect(dbpath) as db:
            db.executescript(migrate_sql)
            db.commit()
    except:
        print("in", dbpath)
        raise

if count == 0:
    raise Exception("count=0... probably wrong iglob pattern or current directory?")

ついでにインデックスを適当に貼ろうと思ってフィーリングで CREATE INDEX player_score_row_num ON player_score(row_num DESC) を貼ったのですが、スコアが1000点前後下がったのでボツにしてマイグレーション機構だけマージしました。

MySQL のマイグレーションの機構作り…をしようと思ったら visit_history を倒す必要があった (@rinsuki)

この後、MySQL側にもマイグレーションを入れたくなるかなと思い MySQL もinitialize時に1から構築するようにしたのですが、90_data.sql の挿入がやたら遅くベンチマーカーに怒られてしまいました。

とりあえずデプロイ時にのみ初期化する (/initializeではそのまま特定範囲のレコードを消すまま) でマージしましたが、そのあとなぜ遅かったのかの調査をしました。

その結果、visit_history にすごい量のレコードがある上に、本来必要なのはユーザー毎の初回の閲覧タイムスタンプだけだったということがわかったので、構造が同じ first_visit_history を生やし、tenant_id, competition_id, player_id のユニーク制約を貼り、INSERT IGNORE INTO でそのユーザーのレコードが既に存在したら INSERT を無視するようにしたところ、MySQL サーバーのCPU使用率がかなり下がりました (SQLite の MySQL 移行は結局途中で断念したのでこのまま最後まで MySQL はかなり暇をしていました)。

さらに上記の first_visit_history を生やしてinitializeした後の初期データをダンプし直し、初回閲覧のレコードだけをリストアするようにしたところ、initializeも爆速になったので、無事 MySQL が1から構築できるようになりました (が最終的に first_visit_history 以外は MySQL に手を加えなかった…)。

しかし、この改善はあまりスコアに影響するわけではありませんでした (グラフ見る限りはほぼ変化なし？)。恐らく SQLite がネックになりまくっていたのですが、それでも MySQL サーバーの負荷は下がったので後々の SQLite 側の邪魔にならないための先手を打てた…と思っておきます。

SQLite の player_score テーブル改善 (@tosuke, @rinsuki)

その後に SQLite の player_score をよく見ると、実はプレーヤー毎に最後のスコアだけ残せばよいという仕様が判明し、@tosuke がマイグレーションの書き方がわからんと言っていたので、私がマイグレーション用の SQL を、@tosuke に Go 側の実装の変更を担当してもらいました。SQLite DB へのマイグレーションの仕組み自体は先に書いておいたこともあり SQL はすんなり書けました (たしか)。

これでスコアがめちゃくちゃ伸び、突然16000点台に飛びました。飛びすぎて瞬間1位になりました。

ランキングのクエリ改善 (@otofune)

player_score テーブルが持つデータとテーブルへの挿入部分は以前改善したのですが、player_score を参照するクエリはまだ最適化されていませんでした。

player_score を参照する処理のうち、ランキングのクエリの改善を @otofune がやってくれて、スコアが3万点まで伸びました (これがほぼ最終スコアです)。

SQLite to MySQL (断念, @rinsuki)

player_score テーブルへの挿入高速化が終わると私は基本的に SQLite の MySQL 移行を始めていたのですが、まず一番 JOIN をすることがなさそう(=他の人の作業に影響しづらそう)な player テーブルを移行してみたところ、retrievePlayer の N+1 が解消できていなかった上にキャッシュが何もなかったこともあり MySQL がめちゃくちゃ CPU とネットワーク帯域を食いまくり、時間内での解決の見込みが立たなかったので MySQL 移行のブランチは最終的には捨てることになりました。

ちなみにスコアのグラフ上で一旦また 16000 点に落ちているのは、MySQL 移行のために一旦ランキングのクエリ改善を revert していたためです(player_name の JOIN があるので player テーブルの移行と競合していた)。

最後の最後で SQLite DB が壊れた！？

最後の最後、再起動を試したちょっと後くらいになぜか POST /initialize が通らなくなりました。

ログを見ると上で書いた SQLite のマイグレーション内で DB が壊れているとかそういう感じのことを言ってコケていたのですが、とはいえ initial_data からコピペしてきているだけのはずだし…再起動でディスクが壊れる超レアケを引いたか？と思い、とりあえず /initialize が通る 03 から initial_data を tar.gz にして転送しつつ 01 での調査をしていたところ、 sql/init.sh では tenant_db/*.db しか消しておらず、我々が SQLite の WAL モードをオンにしていた影響で *.db-wal がそのままになっていたのが原因ということがわかり、それらも消すようにしたところ解決しました。

おまけ

  • Goのファイル分割 (@otofune)
    • Go はファイル分割が気軽にできて便利
  • SQLite を WAL にした (@tosuke)
  • /api/player/player/:player_id の N+1 を解消した (@tosuke)
    • SQLite で読み込み系 N+1 を減らしても効果が薄い？
  • nginx の gzip を切る (@otofune)

このへんは彼らの記事で語られるかもしれません (投げやり)

所感

ISUCON に出たのは ISUCON8 (2018年) 以来で久々だったのですが楽しかったです。

ただ、残り一時間半のタイミングで SQLite から MySQL に移行しようとして1時間を潰したのはもうちょっと冷静になれば SQLite のまま改善のほうに振れたと (やるとしても最初から手を付けるべきだった) 思うので、本選では賢さSにしてどこに労力を割くべきか正しく判断できるようになりたいです。

俺たちの夏はまだ続く！ということで、また本選でお会いしましょう。

おまけ

東工大の人多すぎて草 (我々は東工大生ではありません)

*1:スクショは iPad の Safari ですが、このスクショを撮った後 iPad からスクショを共有するのがだるいということに気づき Sidecar に変えました

*2:普段使っているものに includeSubDomains が付いた HSTS が存在しないか自信がなかったのでドメインも普段の *.rinsuki.net とは分けた

*3:network_modeがhostになっていないとなんかボトルネックがあるらしいというウワサを聞いていた