ISUCON12予選の復習をしました 2
この記事は何か?
ISUCON12の復習記録です。
第2回はISUCON12 予選の解説 (Node.jsでSQLiteのまま10万点行く方法)の「2 Ranking APIが重いのでひとまずループクエリをなくす」を試します。
目次
- 環境構築 (alp, pporf)
- 「2 Ranking APIが重いのでひとまずループクエリをなくす」を試す
1. 環境構築 (alp, pporf)
alpとpporfをインストールします。alpのインストール手順は過去に書いたので省略します。
- pporfインストール
go install runtime/pprof
go install net/http/pprof
vi isuports.go
-----------------
+
+ "runtime"
+ _ "net/http/pprof"
@@ -137,6 +140,12 @@ func Run() {
e.Debug = true
e.Logger.SetLevel(log.DEBUG)
+ runtime.SetBlockProfileRate(1)
+ runtime.SetMutexProfileFraction(1)
+ go func() {
+ http.ListenAndServe("0.0.0.0:6060", nil)
+ }()
-----------------
make
sudo systemctl restart isuports
sudo apt install graphviz
セキュリティグループの設定で1080を開放
go tool pprof -http=0.0.0.0:1080 /home/isucon/webapp/go http://localhost:6060/debug/pprof/profile?seconds=90
http://xxx.xxx.xxx.xxx:1080/にアクセス
- alp結果
alp --sum -r -f /var/log/nginx/access.log | head -100 +-------+--------+--------+---------+--------+--------+--------+--------+--------+-----------+------------+-------------+-----------+--------+-----------------------------------------------+ | COUNT | MIN | MAX | SUM | AVG | P1 | P50 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) | METHOD | URI | +-------+--------+--------+---------+--------+--------+--------+--------+--------+-----------+------------+-------------+-----------+--------+-----------------------------------------------+ | 18 | 2.764 | 16.020 | 189.032 | 10.502 | 2.764 | 12.688 | 15.708 | 5.091 | 0.000 | 14439.000 | 245022.000 | 13612.333 | GET | /api/player/competition/9fa538f9/ranking | | 16 | 0.140 | 18.724 | 183.480 | 11.467 | 0.140 | 17.804 | 18.588 | 8.684 | 13563.000 | 13636.000 | 217081.000 | 13567.562 | GET | /api/player/competition/9fa53e35/ranking | | 31 | 0.016 | 17.592 | 135.380 | 4.367 | 0.016 | 0.156 | 17.464 | 5.416 | 13650.000 | 13741.000 | 423394.000 | 13657.871 | GET | /api/player/competition/9fa52cc0/ranking | | 27 | 0.028 | 17.632 | 132.436 | 4.905 | 0.028 | 0.192 | 10.464 | 5.561 | 13654.000 | 13708.000 | 368743.000 | 13657.148 | GET | /api/player/competition/9fa53286/ranking | | 20 | 0.012 | 10.188 | 119.448 | 5.972 | 0.012 | 9.972 | 10.156 | 4.851 | 0.000 | 13730.000 | 260867.000 | 13043.350 | GET | /api/player/competition/9fa53ed0/ranking | | 38 | 0.008 | 18.508 | 116.096 | 3.055 | 0.008 | 0.044 | 17.724 | 4.939 | 912.000 | 3439.000 | 124093.000 | 3265.605 | GET | /api/player/competition/9fa5278c/ranking | | 19 | 0.000 | 9.648 | 105.476 | 5.551 | 0.000 | 9.428 | 9.620 | 4.686 | 0.000 | 13633.000 | 244237.000 | 12854.579 | GET | /api/player/competition/9fa53fc1/ranking | | 23 | 0.020 | 7.888 | 99.780 | 4.338 | 0.020 | 6.480 | 7.888 | 3.786 | 13571.000 | 13721.000 | 312385.000 | 13581.957 | GET | /api/player/competition/9fa5325a/ranking | | 26 | 0.020 | 7.624 | 98.900 | 3.804 | 0.020 | 0.252 | 7.620 | 3.710 | 0.000 | 13727.000 | 325444.000 | 12517.077 | GET | /api/player/competition/9fa537bf/ranking | | 34 | 0.016 | 7.572 | 95.484 | 2.808 | 0.016 | 0.076 | 6.908 | 3.116 | 13457.000 | 13669.000 | 458558.000 | 13487.000 | GET | /api/player/competition/9fa52a27/ranking | | 28 | 0.020 | 8.356 | 87.816 | 3.136 | 0.020 | 5.228 | 7.048 | 2.963 | 13555.000 | 13682.000 | 379750.000 | 13562.500 | GET | /api/player/competition/9fa52efc/ranking | | 33 | 0.924 | 15.380 | 84.456 | 2.559 | 0.000 | 1.804 | 6.764 | 2.576 | 0.000 | 1565.000 | 46830.000 | 1419.091 | GET | /api/admin/tenants/billing | | 17 | 0.076 | 8.368 | 80.968 | 4.763 | 0.076 | 7.756 | 8.232 | 3.897 | 13639.000 | 13653.000 | 231922.000 | 13642.471 | GET | /api/player/competition/9fa546cf/ranking | | 16 | 0.072 | 7.352 | 79.784 | 4.986 | 0.072 | 7.128 | 7.320 | 3.299 | 13686.000 | 13686.000 | 218976.000 | 13686.000 | GET | /api/player/competition/9fa54745/ranking | | 29 | 0.012 | 4.060 | 44.864 | 1.547 | 0.012 | 0.048 | 4.052 | 1.923 | 11049.000 | 14504.000 | 416088.000 | 14347.862 | GET | /api/player/competition/9fa533be/ranking | | 28 | 0.012 | 3.320 | 36.696 | 1.311 | 0.012 | 0.036 | 3.316 | 1.593 | 2908.000 | 12357.000 | 330278.000 | 11795.643 | GET | /api/player/competition/9fa53adb/ranking |
GET /api/player/competition/:competition_id/rankingが遅いことが分かります。
- pprof結果
tenantDB.SelectContextが4.89秒、retrievePlayerが3.14秒かかっていて、retrievePlayerはいわゆる「N+1問題」になっていることが分かります
2. 「2 Ranking APIが重いのでひとまずループクエリをなくす」を試す
mysqlがちょっと落ち着いたら、alpでリクエストごとの総レスポンスタイム(SUM)を見てみると、rankingが重いことが分かります。flockしているのも気になりますが、ロック区間内でループクエリが発生しているのがマズいので、まずはplayer_scoreを取るところにplayerをJOINして、retrievePlayerせずともdisplay_nameを取れるようにします。
解説ではSQLiteのロックは一旦そのまま放置して、N+1問題の解決をしています。
- 変更後のソースコード
+type PlayerScoreJoinPlayerRow struct {
+ TenantID int64 `db:"tenant_id"`
+ ID string `db:"id"`
+ PlayerID string `db:"player_id"`
+ CompetitionID string `db:"competition_id"`
+ Score int64 `db:"score"`
+ RowNum int64 `db:"row_num"`
+ CreatedAt int64 `db:"created_at"`
+ UpdatedAt int64 `db:"updated_at"`
+ DisplayName string `db:"display_name"`
+}
- "SELECT * FROM player_score WHERE tenant_id = ? AND competition_id = ? ORDER BY row_num DESC",
+ "SELECT player_score.*, player.display_name FROM player_score JOIN player ON player.id = player_score.player_id WHERE player_score.tenant_id = ? AND competition_id = ? ORDER BY row_num DESC",
/*
p, err := retrievePlayer(ctx, tenantDB, ps.PlayerID)
if err != nil {
return fmt.Errorf("error retrievePlayer: %w", err)
}
*/
ranks = append(ranks, CompetitionRank{
Score: ps.Score,
PlayerID: ps.PlayerID,
PlayerDisplayName: ps.DisplayName,
RowNum: ps.RowNum,
})
- 変更後のpprof結果
N+1問題は解決しました。しかしスコアは2972と改善していません。解説にあるとおりflockを解決しないとスコア改善しないようです。
感想
今見ると分かりやすいN+1問題ですが、予選当日は対応できませんでした。アプリやコードの仕様理解をさくっとできるようになる必要があります。
また、対応できたとしてもスコアが改善しないので、「それはそれとして、改善を重ねていこう」というゆるい気持ちが必要そうです。
