ISUCON12予選を全体29位、学生枠1位で突破した

こんにちはdas08です。

今年もISUCONに参加してきました！ISUCONは8時間で改善の余地のあるWebアプリをチューニングして高速化しスコアを競う大会で、 今回で2回目の出場でした。

チームメンバー

• das08 (電気電子工学科4回生)
• tinaxd (同上)
• arakistic (同上)

昨年のISUCON11に引き続き、メンバー全員同じ学科でチームを組みました。
チーム名の「快適PandA」は私たちが趣味で開発したComfortable PandAという 京大の学習支援システムを改善するブラウザ拡張機能の名前から来ています。

使った技術など

• 言語: Goを採用しました
• ツール: alp, pt-query-digest, pprof, htop, dstat, slackcatなど
  その他RedisやVarnishなど飛び道具も使えるように練習していました。

予選当日

4:30 起床

完璧な状態で予選に挑むぞ！と思って早めに寝たのですが、最近の院試勉強のストレスとISUCONのドキドキで早く起きてしまいました。
眠くならないようにカフェインをとってゴロゴロしてました。

9:40 チーム集合

ISUCON公式配信を見ながらDiscordで集まり軽く方針決めをしました。

• コードフリーズは30-45分前，予選通過ラインを越えそうになければ15分前
• 初動ムーブ
  など

10:00 競技開始

競技が始まりました！今年のテーマは「ISUPORTS」というe-Sportsライクなマルチテナントサービスを8時間で高速化してねというお題でした。
私がEC2でサーバーを構築しながらマニュアルをメンバー全員で読み合わせました。キャッシュ使えそうだねー、このエンドポイントでスコアが伸びるんだなみたいなことを話していました。
コードを見ているとSQLiteがテナントごとに使われるという仕様で、これはマイグレーションいるのか...?と覚悟しました。

10:30 初回ベンチ(Score: 2500)

最初は何にも変更せず素直にベンチを回しました。キリのいいスコアが出て幸先がいいです。

10:35 DB分離(Score: 3930)

初回ベンチ中にhtopでサーバーのCPU使用率をモニタしていたところ、100%に張り付いていたので即AppとDBを分離することに決めました。
練習段階で3分で分離できるようにしていたので、すぐに分離しました。

10:35 ログ系追加(Score: 3506)

nginxとMySQL、あとAppにpprofなどを追加しました。
スコアは案の定下がりましたが、ログがないことにはチューニングできないので仕方がないです。

11:04 MySQLにIndex追加(Score: 3904)

Index職人のarakistic氏にやってもらいました。
この段階で11位くらいでした。

11:46 DockerからAppを剥がす(Score: 3969)

AppがDockerに乗っていた関係でpprofができず困っていました。
後々Dockerから剥がすことになる未来が見えたので、早い段階でDockerから降ろそうという結論に至りました。

12:01 N+1の改善(Score: 4392)

alpのスローエンドポイント分析などからN+1を見つけたのでチームメンバーが改善してました。

12:20 Bulk Insert(Score: 6898)

competitionScoreHandler()でループ内で1件ずつINSERTしていたらしく無駄だったのでBulk Insertに変更していました。

12:32 Bulk Insert2など(Score: 7411)

playersAddHandler()でも同様にBulk案件があったので対応してもらいました。その他細々とした改善も入っています。

この時点で全体3位とかなり好調な滑り出しです。
学生チームが上位30位に結構入っていたので、社会人チームは先にSQLiteのマイグレーションをやってそうだなと感じていました。

12:39 Redisでプレイヤー情報をキャッシュ(Score: 4727)

各テナントごとにSQLiteでプレイヤー情報をもっており、retrievePlayer()で取得するたびにflockしていたのでRedisでキャッシュを持った方がいいじゃんと思い 実装しました。
しかしスコアは大きく減少してしまい泣く泣くrevertしました。
後に気づきますが、appとredisのtcpコネクションのオーバーヘッドが思ったより大きいのと、構造体をjsonでstringifyしていたので時間がかかっていました。
そこでGoのインメモリに置いちゃえと実装方針を切り替えました。

~14:55 悪夢の時間(Score: 変動なし)

ここから2時間ほど沼プレイでした。もしかしたらISUCON名物かもしれないですね。

• tinax氏: SQLiteをMySQLにマイグレーション。1.dbが重すぎてInsertに時間がかかり大変そうだった。
• 自分: インメモリキャッシュがバグり散らかしていた。
• arakistic氏: ベンチFailしてて辛そうだった。

15:00すぎても進捗がなかったら方針会議するかぁとぼんやり思っていました。

14:55 競技結果のキャッシュ(Score: 9277)

arakistic氏が先に沼から抜けてcompetitionRankingHandler()で終了した競技結果をキャッシュに持つ実装を仕上げてくれていました。
2時間沼っていたので正直かなり救われました。チームの意識もかなり前向きになった気がします。

 1if competition.FinishedAt.Valid {
 2    if finishedCompRankCache == nil {
 3        finishedCompRankCache = make(map[string]SuccessResult)
 4    }
 5    //終了済みの大会のランキングはキャッシュから読み出す
 6    res, ok := finishedCompRankCache[competitionID]
 7    if ok {
 8        return c.JSON(http.StatusOK, res)
 9    }
10}

この辺から早く起きすぎた影響が出てしまい、メンバーの作業内容を追えなくなってしまいました。SQLiteのマイグレーションをやめる決断を この段階で決めた気がしますが覚えていません笑

16:28 SQLite改善(Score: 10892)

SQLite継続することになったので、SQLiteでもインデックスを貼るように改善してくれてました。
SELECT DISTINCT(player_id)クエリが遅かったので、これを排除するパッチをあてたそうです。

16:40 ID採番方法の改善(Score: 18823)

ユニークIDの生成方法としてREPLACE INTO id_generator (stub)を実行してデッドロックが発生しなければauto incrementされたidをユニークIDとして使う 実装になっていましたが、明らかに無駄だったのでgithub.com/google/uuidのUUID生成を使う方針にしました。

1import "github.com/google/uuid"
2// システム全体で一意なIDを生成する
3func dispenseID(ctx context.Context) (string, error) {
4	u, _ := uuid.NewRandom()
5	uu := u.String()
6	return uu, nil
7}

ここまでスコアが伸びるとは思いませんでしたが、ようやく予選突破のボーダーが見えてきたので安堵しました。

17:17 MySQL分割(Score: 0)

ここまで2台構成だったので、htopの様子からMySQLのテーブルを分割すればCPU使用率が下がりスコアが伸びると判断しました。
Initializeでこけてしまったのと、17:30にコードフリーズをすると決めていたので諦めてrevertしました。

17:30 コードフリーズ(Score: 20408)

コードフリーズは絶対厳守方針だったのでこれ以上の改善をやめました。ログ系を全て切り、レギュレーションに引っかからないように Clarも含めていろいろな視点から確認しました。再起動試験も同時並行でおこなって、ブラウザでの動作確認も済ませました。
チームメンバーに心配性が2人いるのと、重箱の隅をつつくのが得意なので完璧な状態にすることができてよかったです。

スコアの推移

こんな感じでした。
最終スコアは20408でした。

感想

今年も本戦に出場できてとても嬉しいです！
特に今年はボトルネックに対するアプローチが難しい印象で、計測の大切さを改めて教えてくれる素晴らしい問題だと思いました。

色々準備してた技が試せなかったので、本番ではボトルネックをうまく得意領域に持ち込んで優勝したいと思います！