Diary of a Perpetual Student

Perpetual Student: A person who remains at university far beyond the normal period

ISUCON 12: はじめての ISUCON 体験記

ISUCON 12 予選にチーム「横浜の缶詰」*1として参戦し、最終スコア 9368 点を残して敗退しました。参考値ではありますが 104 位(661 チーム中?)ですね。

isucon.net

結果としては残念な感じですが、初めての ISUCON で今後の成長に繋がるやり方を貫き通せたところが良かったと思っています。次回以降も前向きにチャレンジしていきます。

さて、事前準備や当日の様子・学びについて振り返っていきます。

事前準備

まず、3人で作戦会議をしました。アプリケーション担当 2人 + インフラ担当 1人という形で分担することにしました。(自分はアプリ担当。)

また、事前演習として、チームで ISUCON 10 予選問題を解きました。計測すると明らかに「なぞって検索」が支配的に重いことが分かるのですが、ここの改善は MySQL の GEOMETRY 型(初見)が登場してとても難しいです。なんとか改修することができたのですが、演習時間のほとんどをこれ1本に注いで終わってしまいました。

演習後、チームで KPT 法による振り返りを行いました。以下はその抜粋です。

  • K: deploy 周りのスクリプト用意されていてよかった
  • K: log の grep テク大事
  • K: 計測して改善のムーブを大事にできた
  • P: 今何をしているか共有できなかった
  • P: 重いタスクを2つに分割したつもりだったけど完全に分割できていなかった。2人で同じところにハマってしまった
    • T: リソース効率よりもフロー効率を重視して、基本ペアプロで進めていく

加えて、チームでの事前演習とは別に社内の ISUCON 練習会に参加しました。朝まで飲んでいたら寝坊したので、本番前日はたとえ飲みに行っても終電で帰るという強い誓いを立てました。

予選当日

このセクションでは、アプリケーション担当の id:arthur-1 目線で競技中のタイムラインを記述する。(インフラ担当の頑張りはあまり記述していない。)

9:30 起床

起床チャレンジ成功。ゴミ捨てチャレンジには失敗した。

10:00 マニュアル・ドキュメント読み合わせ開始

インフラ担当が準備している間にアプリ担当2人でマニュアルを読んだりブラウザで動作確認したりしていた。

10:30 リポジトリ準備完了

インフラ担当がソースコードGitHubリポジトリとして共有した。ソースコードをまじまじと眺めて、テナントごと SQLite のファイルがあるのに気づき戦慄する。

動画で CSV によるスコア入稿が重いという話があったので、 func competitionScoreHandler を読んでいた。明らかに n+1 なので、bulk insert にしたり一括で select するようにしたい。

11:00 対戦環境が整う

Discord に alp や slow-query の結果を投稿してくれる君が動くようになった。alp の結果を正規化し、ベンチを回して解析結果を眺めようやくスタートラインに立つ。

GET /api/player/competition/:competition_id/ranking エンドポイントを 2人がかりで改善していくことに決定。

11:30 competitionRankingHandler をターゲットに

visit_history という謎テーブルはどうやら課金額の計算に使用しているらしいことが分かる。以下の修正方針を立てる。

  • player_score テーブルに index 張りたい
  • retrievePlayer を for文で回しているところが n+1 なので直したい

改善したいクエリって slow_query に載ってるのか?という痛い指摘を受けたけれど、残念ながら SQLite なので改善すべきクエリなのかはわからない。

11:50 player_score に index 張った

他のクエリに影響がでないよう player_score 関連のクエリを洗い出して index 設計。SQLite だと CREATE TABLE と同時に INDEX 作れないことを知る。

12:20 デプロイ成功 & index の効果をベンチで確認

自分達で build したバイナリのデプロイ成功。スコアは誤差レベルでほとんど変わっていない。

12:40 SQLite 脱却の決意

GET /api/player/competition/:competition_id/ranking の n+1 クエリ脱却に成功。デプロイしたが、スコアは向上せず、むしろ下がってしまった。pprof や alp の結果を見ると明らかに良くなっているのだけれど。

これは SQLite なのが悪いと断定した。また、以下の点から出題者が MySQL への移行を推奨しているのではないかと思った。

  • テナントごと DB が分かれているにもかかわらず、tenant_id カラムが用意されていること
  • SQLite の db ファイルを SQL のクエリ列に変換するスクリプトが用意されていること

SQLite のままだと3台フルに生かした複数台構成にしにくいこともあり、脱却を決意した。

13:50 アプリケーションコードの SQLite 脱却完了

昼休みを交互に取りながら、SQLite 脱却作業を行う。

tenantDB にアクセスしに行っているコードを adminDB に書き換える作業が完了した。残すは初期データの生成のみ。

14:10 tenantDB の初期データを MySQL に作り替え始める

tenantDB 初期データの mysql 向けの dump ファイルを作りたい。sqlite3-to-sql スクリプトの出力結果を MySQL に食わせているけど永遠に終わる気配がない。これはでかい釣り針に釣られてしまったのではないかと焦り始める。

15:15 bulk insert に変換する

sqlite3-to-sql スクリプトの出力結果を bulk insert に変換するスクリプトができたので、初期データを MySQL に移すのを試してみる。

max_allowed_packet に邪魔されて実行できない。

15:30 MySQL 移行諦める

事前練習でなぞって検索に全振りしてしまった反省から、 MySQL 移管を損切りすることに決める。

これができないと App 2+ DB 1 のような複数台構成を目指すのがかなり無理になってしまい、インフラ担当が今後できる改善ポイントが減ってしまうので、やり遂げる技術力がなくてただただ残念に思っていた。

作戦会議をして、全体としては GET /api/organizer/billing の改善に pivot することに決めた。

また、僕は動画で紹介されていた CSV 周りの処理が気になっていたので、 POST /api/organizer/competition/:competition_id/score の改善に取り組むことにした。

15:50 competitionScoreHandler の n+1 を直す

POST /api/organizer/competition/:competition_id/score の処理が n+1 になっていたので直した。元から NamedExecContext を使っていたので bulk insert に書き換えるのが簡単だった。優しさを感じる。

この頃インフラ担当が App + DB の 2台構成を試していたのでスコアの比較はできなかったが、少しは改善しているように見えた。

16:45 billingHandler の改善を進める

visit_history を記録しているけど、課金に必要なのは最初の visit の情報だけなので、 min_visited_at を記録するテーブルとして分割することにした。コードの改修が終わってベンチを回すも整合性チェックに fail する。

どうやら、初期化時にテーブルの生成ができていないようだ。webapp/sql/admin/10_schema.sql に書けば良いと思っていたけど、このファイルはアプリケーションでは使っていないことに気づく。init.sql に移し替える。

16:55 最高スコア記録

インフラ担当の頑張りによって、最高スコア 9777 点を記録する。確か player_id の謎の生成方法をやめて uuid に変えていた。

17:05 min_visited_at 初期データ作り

500 エラーは発生しなくなったが、引き続き整合性チェックに引っかかる。そもそも、初期から visit_history にレコードがあるので、ここから初期データの min_visited_at を作らなければならないことに気づく。

ここを直すと大幅にスコアが伸びると期待されていたので、焦りながらも黙々と進める。

17:30 初期データ作り失敗

min_visited_at の初期データを作るクエリを組み立てるのに試行錯誤していた。成功するも整合性チェックに通らず。どうやら課金額 50 円ほど少なく計算されてしまっているようだ。課金計算という言葉に拒否感を覚え始める。

インフラ担当が店じまい(デバッグログ出力の停止など)を始める。

18:00 競技終了

最終スコアは 9368 点。結局 GET /api/organizer/billing の改善を完遂することはできなかった。最後のデバッグログ停止などはあまりスコアに響かなかったようだ。

チームで振り返りをした後解散。夕食を食べて酒を買い出しに行き、社内のオンライン反省会に参加した。PHP 大好き〜〜と語っていた。

スコアの変遷

感想

個人的には、以下の点について反省しています。

仕様の理解をおろそかにしていて、改善アイデアが参照実装コードに縛られていた

コードがユーザにどんな機能を提供しているのかの理解をおろそかにしていました。コードを見れば、「あっ、ここは n+1 なので直せるな」といったことはすぐに分かります。しかし、このような一目でわかる小手先の改善だけでは戦っていけません。その関数が結果として何を返しているかをあまり考えずにいたので、「visit_history テーブルってそもそも必要なくない?」などの抜本的な改善のアイデアに辿りつくことができませんでした。

ブラウザ上でアプリケーションを動かすのをもっと丁寧にやると良いのかもしれません。

コーディング速度が遅かった

単純に、改善ポイントを見つけてから改善するまでの時間をもっと短くしたいと思いました。チームでは Go 言語を選択したのですが、僕は Go を読み書きし始めて日が浅く、流暢にプログラムを書くことができませんでした。

ISUCON に関する圧倒的な情報量・pprof などの使いやすい解析ツールの有無を考えると、Go 言語を選ばないとハンディキャップになってしまいます。仕事でも Go 言語を使う機会がかなりあるので、半年以内には素早く書ける言語にしていきたいです。

とは言ったものの、最初の練習から比べるとかなり書けるようになったので、その分は自分を褒めたいです。NamedExecContext を見て「おっ!」と反応するのは golang 初見ではできなかったでしょう。

最後に

ISUCON めちゃくちゃ楽しい!!!本当に isuports(esports) そのものだと思いました。ISUCON に取り組むことで得た技術力やマネジメント力はきっと業務に活かせると確信しています。来年も絶対出るぞ!!!!

*1:チーム名は ISUCON チーム名ジェネレータ で決めました。たまたま自分は横浜市民でした