ISUCON 12 初参戦レポート

概要

言わずとしれたエンジニアの祭典， ISUCON に今回初参戦してきました！今まで全く関心が無かったのですが，友人に半ば無理やり誘われて…という流れで勢いで参加してしまいました

既に「要件把握時間かかる人間だからこういうの向いてないなぁ」という不安が頭によぎっていて，予選当日には実力不足を痛感することになってはしまったのですが，とても学びがあったので，来年のリベンジ（？）に生かすために振り返っておきたいと思います。

以下メンバーです。自分以外の 2 人はいずれも以前までの職場の知り合いです。

メンバー	主なロール
joe @joe_yuzupi	インフラ
mpyw @mpyw	バックエンド
chaba @Tea_Server	マネジメント

全体の流れは以下の chaba 氏のブログに超絶親切にまとめられているので（本当にありがとう！），こちらではそれを引用しながら

• 技術面（主にバックエンド改修）での詳細
• 私視点からの感想

をメインに書かせていただこうと思います。

タイムライン

時刻	概算スコア	施策
開催前	-	事前練習
9:30 - 10:00		開会式
10:00 - 11:00	3000	環境構築・計測・方針決定
	2000	New Relic 導入
11:00 - 11:30		player_score にインデックス追加
11:30 - 12:00		ランクのページネーション処理を SQL に移行
		スロークエリログ有効化
		Makefile 作成
12:00 - 13:00		retrievePlayer の N+1 問題の解消
	3000	ランク参照時の visit_history への書き込みを非同期に
13:00 - 15:00		player_score 挿入処理を DELETE+INSERT から UPSERT に
	5000	player_score 挿入をバルク UPSERT に
	7000	RDB 周りのインフラ構成を最適化
15:00 - 15:30		ファイルロック処理削除
	9000	システム全体の ID 採番に ULID を使用するよう変更
		オンライン予選ライブ中継にチーム名が載る
15:30 - 16:30	0	テナントの課金計算を最適化
16:30 - 17:30	0	ログ削除・インフラ最適化
17:30 - 18:00	7000	壊れたインフラの復旧

詳細

環境構築・方針決定

joe が CloudFormation を立ち上げてサーバーにアクセス、mpyw がコードをローカルにコピーしてリポジトリを作成、私がマニュアルを読んでサービスにアクセスできる状態にしました。一通りの環境再現が終わると joe は初回計測と New Relic の導入および Makefile の作成、mpyw はコードの流し読み、私はスコア計算方式を読解とそれぞれの作業に取りかかりました。

スコア計算方式や New Relic の計測結果、開会式でのヒントを元にランキング API の改修から取り掛かる方針で合意し開発を開始しました。

と，あっさり書いてあるんですが，実は初っ端からトラブルが発生していました。

結局最後までレギュレーション違反のセキュリティグループ変更をやらないと SSH で入れなかった理由は不明のままなんですが，次回からは「さすがにこれおかしくない？」と感じたことは遠慮なく問い合わせる方針にしていこうかなと思います。

そんなこんなで無事サーバには入れたので，とりあえず scp コマンドでローカルにソースをコピーしてきて， GitHub リポジトリに載せた上で開発を進めていくことにしました。

デプロイ方式は古き良き git clone からの git pull です。なんだかんだ便利だよね！

そして言語には Go を選定し，ローカルでの開発には JetBrains IDE の Goland を利用しました。日頃から PhpStorm も含めてかなりお世話になっており，この圧倒的強力な補完・整形性能に乗っからないわけがありません。

PHP は実家に置いてきました

New Relic 導入

コンテスト開催前から入念に計画しておいた内容。 ISUCON 11 過去問の事前演習で，エンジニアの直感的に

「これはコストかかりそうだけどさすがに直しておきたいなー」

と感じた部分が計測したら殆どボトルネックになっていなかったということがあり，　

「推測するな，計測せよ」

の至言が頭によぎりました。

今回は同じ轍を踏まないよう，プロジェクト開始直後は現 New Relic 社員である（すごい！） joe による New Relic APM 導入作業を待ちながら，ソースコードの読解を進めていきました。

APM 導入直後の初期スコアは 2000 で，初期状態の 3000 よりも少し下がってしまっていました。後から APM は抜く前提で，ここから改修を進めていきます。

要件の把握

ISUCON 11 の題材よりはまだ理解しやすかったんですが，今回もやや苦戦しました。ソースを見ての初っ端の感想が

「え？なんで MySQL と SQLite 両方あるの？」

でした。度肝を抜かれて頭が真っ白になってしまい，

• SaaS 全体管理は MySQL
• テナントごとに独立した SQLite DB が作られる

ということに気づくのにさえ少し時間がかかってしまいました。

また，至るところに存在している古典的ファイルロックによる排他制御。

こちらの記事でも参考程度に取り上げていましたが，まさか現代で再び見ることになるとは（笑）
とはいえ迂闊に剥がすと不整合を起こしまくりそうなので，どうやってこれを剥がすのかがネックになるのかなーと眺めていました。

ランキング取得処理のチューニング

New Relic による計測により，（競技上のスコア重み付けを無視すれば）ランキング表示が一番アクセス頻度が多くてかつ非常に重いという検討はついていたので，まず GET /api/player/competition/:competition_id/ranking に対応する部分のソースを読みました。

player_score にインデックス追加

if err := tenantDB.SelectContext(
	ctx,
	&pss,
	"SELECT * FROM player_score WHERE tenant_id = ? AND competition_id = ? ORDER BY row_num DESC",
	tenant.ID,
	competitionID,
); err != nil {
	return fmt.Errorf("error Select player_score: tenantID=%d, competitionID=%s, %w", tenant.ID, competitionID, err)
}

player_score には大量のレコードがインサートされることが分かっていたので，あからさまにこのクエリが重そうだという検討はつきます。まずここにインデックスを張ることから始めました。

 CREATE TABLE player_score (
   id VARCHAR(255) NOT NULL PRIMARY KEY,
   tenant_id BIGINT NOT NULL,
   player_id VARCHAR(255) NOT NULL,
   competition_id VARCHAR(255) NOT NULL,
   score BIGINT NOT NULL,
   row_num BIGINT NOT NULL,
   created_at BIGINT NOT NULL,
   updated_at BIGINT NOT NULL
 );
+CREATE INDEX player_score_competition_tenant_score_idx ON player_score(competition_id, tenant_id, score);

クエリのまま素直に書けば tenant_id competition_id score の順に張りたくなりますが，カーディナリティを考えると competition_id を前に持ってくるべきだと判断し，この順序にしました。

（SQLite データベースがテナントごとに分かれてるんだから tenant_id カラム自体いらねーじゃん！と突っ込みたくなりますが，気づけませんでした しかし MySQL へのデータ移行を行う場合は必要になるので，敢えて消さなくても良かったかなとは思います）

ランキングのページネーション処理を SQL に移行

少し長くてわかりにくいのですが，ランキング取得の全体像はこうなっています。

ランキング取得の全体処理

pss := []PlayerScoreRow{}
if err := tenantDB.SelectContext(
	ctx,
	&pss,
	"SELECT * FROM player_score WHERE tenant_id = ? AND competition_id = ? ORDER BY row_num DESC",
	tenant.ID,
	competitionID,
); err != nil {
	return fmt.Errorf("error Select player_score: tenantID=%d, competitionID=%s, %w", tenant.ID, competitionID, err)
}
ranks := make([]CompetitionRank, 0, len(pss))
scoredPlayerSet := make(map[string]struct{}, len(pss))
for _, ps := range pss {
	// player_scoreが同一player_id内ではrow_numの降順でソートされているので
	// 現れたのが2回目以降のplayer_idはより大きいrow_numでスコアが出ているとみなせる
	if _, ok := scoredPlayerSet[ps.PlayerID]; ok {
		continue
	}
	scoredPlayerSet[ps.PlayerID] = struct{}{}
	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:          p.ID,
		PlayerDisplayName: p.DisplayName,
		RowNum:            ps.RowNum,
	})
}
sort.Slice(ranks, func(i, j int) bool {
	if ranks[i].Score == ranks[j].Score {
		return ranks[i].RowNum < ranks[j].RowNum
	}
	return ranks[i].Score > ranks[j].Score
})
pagedRanks := make([]CompetitionRank, 0, 100)
for i, rank := range ranks {
	if int64(i) < rankAfter {
		continue
	}
	pagedRanks = append(pagedRanks, CompetitionRank{
		Rank:              int64(i + 1),
		Score:             rank.Score,
		PlayerID:          rank.PlayerID,
		PlayerDisplayName: rank.PlayerDisplayName,
	})
	if len(pagedRanks) >= 100 {
		break
	}
}

SQL レベルでソートせず，全件取得後にアプリケーション側でソートをしている， ISUCON 名物おバカコードです。このへんまでは，バックエンドエンジニアであればまず気づいておきたい。

以下のように直します。

 pss := []PlayerScoreRow{}
 if err := tenantDB.SelectContext(
 	ctx,
 	&pss,
-	"SELECT * FROM player_score WHERE tenant_id = ? AND competition_id = ? ORDER BY row_num DESC",
+	"SELECT * FROM player_score WHERE tenant_id = ? AND competition_id = ? ORDER BY score DESC, row_num ASC LIMIT 100 OFFSET ? ",
 	tenant.ID,
 	competitionID,
 	rankAfter,
 ); err != nil {
 	return fmt.Errorf("error Select player_score: tenantID=%d, competitionID=%s, %w", tenant.ID, competitionID, err)
 }
 
 ranks := make([]CompetitionRank, 0, len(pss))
 scoredPlayerSet := make(map[string]struct{}, len(pss))
-for _, ps := range pss {
+for i, ps := range pss {
 	// player_scoreが同一player_id内ではrow_numの降順でソートされているので
 	// 現れたのが2回目以降のplayer_idはより大きいrow_numでスコアが出ているとみなせる
 	if _, ok := scoredPlayerSet[ps.PlayerID]; ok {
 		continue
 	}
 	scoredPlayerSet[ps.PlayerID] = struct{}{}
 	p, err := retrievePlayer(ctx, tenantDB, ps.PlayerID)
 	if err != nil {
 		return fmt.Errorf("error retrievePlayer: %w", err)
 	}
 	ranks = append(ranks, CompetitionRank{
+		Rank:              rankAfter + int64(i) + 1,
 		Score:             ps.Score,
 		PlayerID:          p.ID,
 		PlayerDisplayName: p.DisplayName,
 		RowNum:            ps.RowNum,
 	})
 }
-sort.Slice(ranks, func(i, j int) bool {
-	if ranks[i].Score == ranks[j].Score {
-		return ranks[i].RowNum < ranks[j].RowNum
-	}
-	return ranks[i].Score > ranks[j].Score
-})
-pagedRanks := make([]CompetitionRank, 0, 100)
-for i, rank := range ranks {
-	if int64(i) < rankAfter {
-		continue
-	}
-	pagedRanks = append(pagedRanks, CompetitionRank{
-		Rank:              int64(i + 1),
-		Score:             rank.Score,
-		PlayerID:          rank.PlayerID,
-		PlayerDisplayName: rank.PlayerDisplayName,
-	})
-	if len(pagedRanks) >= 100 {
-		break
-	}
-}

順当に ORDER BY に score DESC も入れてアプリケーション側のソート処理を消すだけではあるんですが，何とタイブレーク処理のため元から存在していた row_num DESC を row_num ASC に書き換えてしまいました…

chaba 「タイブレーク処理消しちゃってるよ」
mpyw 「あ，まじ！？本当だ， score DESC だけだとあかんわ。レビューありがとう」
mpyw 「で， row_num って ASC だっけ？ DESC だっけ？」
chaba 「ASC だと思う！」
mpyw 「おｋ！」

実はこれだけの問題では済みませんでした。

• 同一プレイヤーに関しては，大きい row_num を 1 つ残す
• 異なるプレイヤーに関しては，小さい row_num から優先して並べる

ゆえに単なる ORDER BY では解決できなくなっており，ウィンドウ関数を使わないと捌けないようになっていました。後々のリファクタリングで row_num を排除すればそこまでしなくても良くなりそうですが，少なくともここを素直に書き換えるだけでは以下のような SQL が必要でした。本当に悪意のある問題や…

もう少し高速化できそうだけど例えばこんな感じ

SELECT
  DISTINCT
  FIRST_VALUE(row_num) OVER (
    PARTITION BY player_id ORDER BY score DESC, row_num DESC -- こっちは DESC
  ) AS row_num,
  FIRST_VALUE(score) OVER (
    PARTITION BY player_id ORDER BY score DESC, row_num DESC -- こっちは DESC
  ) AS score,
  player_id
FROM player_score
WHERE tenant_id = ? AND competition_id = ?
GROUP BY player_id
ORDER BY score DESC, row_num ASC; -- こっちは ASC

一方で，こちらのミスに関しては完全に助けられました。

chaba 「Rank フィールド作り忘れてるよ！」
mpyw 「本当だ，前のコードではソートが終わったタイミングで入れてるけど書き換え後は最初からソートが完了してるからすぐ入れておかないといけないんだ」

Go ではポインタではないすべての値が自動ゼロ埋めされるがゆえに，構造体のフィールドを埋め忘れるミスが人為的バグとして起こりやすいので， Linter を入れないとなかなかミスに気づけないかなーと改めて反省。 Goland のルールにあったらいいんだけどなぁ…あったかなぁ…無かったらなにかサードパーティのやつ今度から入れよう…

そして，アプリケーション側のタイブレーク処理を消すのは（消さなくてもいいけど）忘れてしまっていました。本当にどれだけテンパってるんだ…

retrievePlayer の N+1 問題の解消

続いてこれもバックエンドエンジニアなら定番の問題。先程の処理ではループ中に N+1 クエリが存在していたので，これも潰しにかかります。このあたりの処理は Laravel でも馴染みがあったものの，またテンパってしまいました

+type PlayerRowHash map[string]PlayerRow
+
+func retrievePlayersHash(ctx context.Context, tenantDB dbOrTx, ids []string) (PlayerRowHash, error) {
+	hash := make(map[string]PlayerRow, len(ids))
+	var ps []PlayerRow
+	originalSql := "SELECT * FROM player WHERE id IN (\"\"," // 空になるときの対策
+	currentSql := originalSql
+	args := make([]interface{}, 0, len(ids))
+	for _, id := range ids {
+		currentSql += "?,"
+		args = append(args, id)
+	}
+	currentSql = strings.TrimSuffix(currentSql, ",")
+	currentSql += ")"
+	if err := tenantDB.SelectContext(ctx, &ps, currentSql, args...); err != nil {
+		return nil, fmt.Errorf("error Select mulitple players: ids={%s}, %w", ids, err)
+	}
+	for _, row := range ps {
+		hash[row.ID] = row
+	}
+	return hash, nil
+}

 ranks := make([]CompetitionRank, 0, len(pss))
 scoredPlayerSet := make(map[string]struct{}, len(pss))
 
+idArgs := make([]string, 0, len(pss))
+for _, ps := range pss {
+	idArgs = append(idArgs, ps.PlayerID)
+}
+playersHash, err := retrievePlayersHash(ctx, tenantDB, idArgs)
+if err != nil {
+	return fmt.Errorf("error retrievePlayersHash: %w", err)
+}
 
 for i, ps := range pss {
 	// player_scoreが同一player_id内ではrow_numの降順でソートされているので
 	// 現れたのが2回目以降のplayer_idはより大きいrow_numでスコアが出ているとみなせる
 	if _, ok := scoredPlayerSet[ps.PlayerID]; ok {
 		continue
 	}
 	scoredPlayerSet[ps.PlayerID] = struct{}{}
-	p, err := retrievePlayer(ctx, tenantDB, ps.PlayerID)
-	if err != nil {
-		return fmt.Errorf("error retrievePlayer: %w", err)
+	p, ok := playersHash[ps.PlayerID]
+	if !ok {
+		return fmt.Errorf("error player not found in playersHash")
	}

…と終わらせたいんですが，またここで怪しいコードが。本当はこうしたかった。

-originalSql := "SELECT * FROM player WHERE id IN (\"\","
+originalSql := "SELECT * FROM player WHERE id IN ('',"

どうやら， SQLite に忖度動作によってたまたま動いていたようです。マジかよ。

また，以下の部分で正解にたどり着くまでに時間がかかりました。 -過去 → +最終形

-currentSql += strings.TrimSuffix(currentSql, ",")
+currentSql = strings.TrimSuffix(currentSql, ",")

-var hash PlayerRowHash
+hash := make(map[string]PlayerRow, len(ids))

アッアッ… 1個目はしょうがないとして2個目は Linter 入れていれば防げたのに
過去問で事前にほとんど同じような N+1 対応やってたのに本番テンパりすぎて酷すぎる

そして，後で知ったんですが

sqlx くん WHERE IN 対応してるんかーい！
ごめんなさい…リサーチ不足でした

決まった手続きなので以下のようなラッパー関数を作ってもいいかもしれない

func NamedInSql(db sqlx.DB, query string, arg interface{}) (string, []interface{}, error) {
	query, args, err := sqlx.Named(query, arg)
	if err != nil {
		return "", nil, err
	}

	query, args, err = sqlx.In(query, args...)
	if err != nil {
		return "", nil, err
	}
	query = db.Rebind(query)
 
	return query, args, err
}

今度から絶対用意しておこう…
（正直これぐらいはライブラリビルトインで対応してほしい）

Laravel と違って空スライスでよしなに対応してくれない点だけ注意。無駄なクエリ発行回数が減ると考えれば ISUCON 的にはベターかもしれないけど。

ランク参照時の visit_history への書き込みを非同期に

アクセスログ的なやつ。ランキング表示リクエストを飛ばすだけで INSERT が実行されているのは如何なものかと思い，とりあえず Goroutine に雑に押込み。

-if _, err := adminDB.ExecContext(
-	ctx,
-	"INSERT INTO visit_history (player_id, tenant_id, competition_id, created_at, updated_at) VALUES (?, ?, ?, ?, ?)",
-	v.playerID, tenant.ID, competitionID, now, now,
-); err != nil {
-	return fmt.Errorf(
-		"error Insert visit_history: playerID=%s, tenantID=%d, competitionID=%s, createdAt=%d, updatedAt=%d, %w",
-		v.playerID, tenant.ID, competitionID, now, now, err,
-	)
-}
+go func(playerId string, tenantId int64, competitionID string, now int64) {
+	if _, err := adminDB.ExecContext(
+		context.Background(),
+		"INSERT INTO visit_history (player_id, tenant_id, competition_id, created_at, updated_at) VALUES (?, ?, ?, ?, ?)",
+		playerId, tenantId, competitionID, now, now,
+	); err != nil {
+		log.Errorf(
+			"error Insert visit_history: playerID=%s, tenantID=%d, competitionID=%s, createdAt=%d, updatedAt=%d, %w\n",
+			playerId, tenantId, competitionID, now, now, err,
+		)
+	}
+}(v.playerID, tenant.ID, competitionID, now)

Golang を使うべき最大の理由， Goroutine。この時点で APM ありでもスコアが 2000 → 3000 に回復していました。

ちなみにこれは後で知ったんですが，このアクセスログは1人1レコードだけで十分だった模様。唯一の利用箇所がこうなっていました。

// ランキングにアクセスした参加者のIDを取得する
vhs := []VisitHistorySummaryRow{}
if err := adminDB.SelectContext(
	ctx,
	&vhs,
	"SELECT player_id, MIN(created_at) AS min_created_at FROM visit_history WHERE tenant_id = ? AND competition_id = ? GROUP BY player_id",
	tenantID,
	comp.ID,
); err != nil && err != sql.ErrNoRows {
	return nil, fmt.Errorf("error Select visit_history: tenantID=%d, competitionID=%s, %w", tenantID, comp.ID, err)
}

そりゃ GROUP BY player_id MIN(created_at) とかやってたらいらん罠。気づきたかった…

プレイヤースコア挿入処理のチューニング

取得系だけでそれなりに時間を食ってしまいましたが，ようやく挿入処理にもメスを入れます。 POST /api/organizer/competition/:competition_id/score を見ていきます。

player_score 挿入処理を DELETE+INSERT から UPSERT に

真っ先に気づいたのがこれ。おそらく今回の予選における，前半最大の要所。

if _, err := tenantDB.ExecContext(
	ctx,
	"DELETE FROM player_score WHERE tenant_id = ? AND competition_id = ?",
	v.tenantID,
	competitionID,
); err != nil {
	return fmt.Errorf("error Delete player_score: tenantID=%d, competitionID=%s, %w", v.tenantID, competitionID, err)
}
for _, ps := range playerScoreRows {
	if _, err := tenantDB.NamedExecContext(
		ctx,
		"INSERT INTO player_score (id, tenant_id, player_id, competition_id, score, row_num, created_at, updated_at) VALUES (:id, :tenant_id, :player_id, :competition_id, :score, :row_num, :created_at, :updated_at)",
		ps,
	); err != nil {
		return fmt.Errorf(
			"error Insert player_score: id=%s, tenant_id=%d, playerID=%s, competitionID=%s, score=%d, rowNum=%d, createdAt=%d, updatedAt=%d, %w",
			ps.ID, ps.TenantID, ps.PlayerID, ps.CompetitionID, ps.Score, ps.RowNum, ps.CreatedAt, ps.UpdatedAt, err,
		)

	}
}

私「あれ？消してインサートしてるんだったらこれ UPSERT でよくない？」

まず，重複判定にユニークインデックスが正しく張られている必要があるので，インデックスを見直します。前のインデックスは別の用途で必要なので，残したまま新しくユニークインデックスを設けます。ここでも念のためカーディナリティを意識した順番に。

 CREATE TABLE player_score (
   id VARCHAR(255) NOT NULL PRIMARY KEY,
   tenant_id BIGINT NOT NULL,
   player_id VARCHAR(255) NOT NULL,
   competition_id VARCHAR(255) NOT NULL,
   score BIGINT NOT NULL,
   row_num BIGINT NOT NULL,
   created_at BIGINT NOT NULL,
-  updated_at BIGINT NOT NULL,
+  updated_at BIGINT NOT NULL,
+  UNIQUE(player_id, competition_id, tenant_id)
 );
 CREATE INDEX player_score_competition_tenant_score_idx ON player_score(competition_id, tenant_id, score);

…からの，これ！

-if _, err := tenantDB.ExecContext(
-	ctx,
-	"DELETE FROM player_score WHERE tenant_id = ? AND competition_id = ?",
-	v.tenantID,
-	competitionID,
-); err != nil {
-	return fmt.Errorf("error Delete player_score: tenantID=%d, competitionID=%s, %w", v.tenantID, competitionID, err)
-}

 for _, ps := range playerScoreRows {
 	if _, err := tenantDB.NamedExecContext(
 		ctx,
-       "INSERT INTO player_score (id, tenant_id, player_id, competition_id, score, row_num, created_at, updated_at) VALUES (:id, :tenant_id, :player_id, :competition_id, :score, :row_num, :created_at, :updated_at)",
+		"INSERT INTO player_score(id, tenant_id, player_id, competition_id, score, row_num, created_at, updated_at) "+
+			"VALUES (:id, :tenant_id, :player_id, :competition_id, :score, :row_num, :created_at, :updated_at) "+
+			"ON CONFLICT(player_id, competition_id, tenant_id) DO UPDATE SET score=EXCLUDED.score, row_num=EXCLUDED.row_num, updated_at=EXCLUDED.updated_at",
 		ps,
 	); err != nil {
 		return fmt.Errorf(
 			"error Insert player_score: id=%s, tenant_id=%d, playerID=%s, competitionID=%s, score=%d, rowNum=%d, createdAt=%d, updatedAt=%d, %w",
 			ps.ID, ps.TenantID, ps.PlayerID, ps.CompetitionID, ps.Score, ps.RowNum, ps.CreatedAt, ps.UpdatedAt, err,
 		)
 	}
 }

気づいた瞬間，脳汁ドバドバ！…かと思いきや，ここでもまた泥沼に。実は最初は INSERT ... ON CONFLICT ではなく INSERT ... ON DUPLICATE KEY 構文を使ってしまっていました。 MySQL の方言のやつ。これは SQLite なのに

ある程度開発が進んだ段階で mpyw から「このテーブルって MySQL だっけ？」という質問を受けました。これに対して私はろくに確認もせずに「多分そうだと思う」という返答を返してしまい、彼は SQLite に存在しないクエリを発行して Syntax Error に頭を悩ませていました。そこに昼食から帰宅した joe が「そのテーブル SQLite だよ」と一言つぶやいたことで状況は一気に解消しました（本当にすみませんでした）。

うあああああああああああああ
自分も気づけなくてごめんなさい

これで1時間ぐらい浪費してしまった気がするので本当に勿体ない

実は，ここでようやく row_num を捨てていいことが確定します。最初に出てきていた

• 同一プレイヤーに関しては，大きい row_num を 1 つ残す

という条件と，

• CSV のデータは row_num の昇順にソートされている

という事実から，

同一プレイヤーに関してユニークキー制約を張って，重複したデータは新しいものを優先すればいい

ということになるんですね。そこまで熟考せずにテキトーにやっていましたが，たまたま救われていました…

player_score 挿入処理をバルク UPSERT に

↑の後，そのままこれをバルク処理にしたら速くなるだろ〜という推測のもとに置き換え。

（後で聞いてみたら， SQLite は必ずしもバルクにしなくても，トランザクションを張ってフラッシュ処理をまとめるだけで十分速くなるらしい。へぇ…）

そんなことは知らず，とりあえず脳死で置き換え。いやーもうゴリ押しっすね。

（一応 Goroutine 化もやったけど， MySQL じゃなくて SQLite なのでここはあんまり意味なかったかもしれない…）

+chunkSize := 1000
+originalSql := "INSERT INTO player_score(id, tenant_id, player_id, competition_id, score, row_num, created_at, updated_at) VALUES"
+currentSql := originalSql
+args := make([]interface{}, 0, len(playerScoreRows)*8)
 for _, ps := range playerScoreRows {
-	if _, err := tenantDB.ExecContext(
-		ctx,
-		"INSERT INTO player_score(id, tenant_id, player_id, competition_id, score, row_num, created_at, updated_at) "+
-			"VALUES (?, ?, ?, ?, ?, ?, ?, ?) "+
-			"ON CONFLICT(player_id, competition_id, tenant_id) DO UPDATE SET score=EXCLUDED.score, row_num=EXCLUDED.row_num, updated_at=EXCLUDED.updated_at",
-		ps,
-	); err != nil {
-		return fmt.Errorf(
-			"error Insert player_score: id=%s, tenant_id=%d, playerID=%s, competitionID=%s, score=%d, rowNum=%d, createdAt=%d, updatedAt=%d, %w",
-			ps.ID, ps.TenantID, ps.PlayerID, ps.CompetitionID, ps.Score, ps.RowNum, ps.CreatedAt, ps.UpdatedAt, err,
-		)
-	
-	}
+	currentSql += "(?, ?, ?, ?, ?, ?, ?, ?),"
+	args = append(args, ps.ID, ps.TenantID, ps.PlayerID, ps.CompetitionID, ps.Score, ps.RowNum, ps.CreatedAt, ps.UpdatedAt)
+
+	if len(args) >= chunkSize*8 {
+		currentSql = strings.TrimSuffix(currentSql, ",")
+		currentSql += " ON CONFLICT(player_id, competition_id, tenant_id) DO UPDATE SET score=EXCLUDED.score, row_num=EXCLUDED.row_num, updated_at=EXCLUDED.updated_at"
+		go func(currentSql string, ps []interface{}) {
+			_, err := tenantDB.Exec(currentSql, args...)
+			if err != nil {
+				log.Errorf("Async insert error: %w\n", err)
+			}
+		}(currentSql, args)
+		currentSql = originalSql
+		args = make([]interface{}, 0, chunkSize*8)
+	}
+}
+if len(args) >= 0 {
+	currentSql = strings.TrimSuffix(currentSql, ",")
+	currentSql += " ON CONFLICT(player_id, competition_id, tenant_id) DO UPDATE SET score=EXCLUDED.score, row_num=EXCLUDED.row_num, updated_at=EXCLUDED.updated_at"
+	go func(currentSql string, ps []interface{}) {
+		_, err := tenantDB.Exec(currentSql, args...)
+		if err != nil {
+			log.Errorf("Async insert error: %w\n", err)
+		}
+	}(currentSql, args)
 }

この時点で 3000 → 5000 まで大きくスコアが上昇しました。この後のインフラ最適化を含めると更に 5000 → 7000 に。この時点で確認したときは，全体で 40 位程度まで上がってきていました。

ファイルロック処理の削除

このあたりから少し動作が怪しくなってきます。

mpyw「DELETE 処理消え去ったからもうトランザクション張らなくても大丈夫っしょｗ」
chaba「消しちゃえ！」

悩みのタネだったファイルロックですが，流石にもう要らないだろうと高をくくり消してしまいます。

採番処理を ULID に

採番用のオートインクリメントなテーブルを設け，それを 16 進数文字列に直しているいかにもレガシーなコードが存在していたので，最近流行りの UUID 等への乗り換えを検討しました。しかし， MySQL は UUID v4 を主キーとしてインサートすると，単調増加でないためインデックス性能が劣化することが分かっています。

そこで UUID v7 を検討しましたが， バイナリ化せずに雑に文字列としてそのまま 16 進数表記の UUID v7 を入れると空間効率が悪いし，変にバイナリ文字列を入れても他への影響を考慮するリスクがあったため，敢えて UUID v7 の前身とも言える ULID を採用しました。

ライブラリとしては oklog/ulid を使用しています。

 // システム全体で一意なIDを生成する
 func dispenseID(ctx context.Context) (string, error) {
+	id := ulid.Make()
+	return id.String(), nil
-	var id int64
-	var lastErr error
-	for i := 0; i < 100; i++ {
-		var ret sql.Result
-		ret, err := adminDB.ExecContext(ctx, "REPLACE INTO id_generator (stub) VALUES (?);", "a")
-		if err != nil {
-			if merr, ok := err.(*mysql.MySQLError); ok && merr.Number == 1213 { // deadlock
-				lastErr = fmt.Errorf("error REPLACE INTO id_generator: %w", err)
-				continue
-			}
-			return "", fmt.Errorf("error REPLACE INTO id_generator: %w", err)
-		}
-		id, err = ret.LastInsertId()
-		if err != nil {
-			return "", fmt.Errorf("error ret.LastInsertId: %w", err)
-		}
-		break
-	}
-	if id != 0 {
-		return fmt.Sprintf("%x", id), nil
-	}
-	return "", lastErr
 }

ここでスコアが大きく跳ね上がり， 7000 → 9000 に到達しました。最高得点が 9880 で，なんとこのとき本選参加できる 18 位をつけていました

しかし，喜びもつかの間。ここから没落の一途をたどります。

実はこのとき，パフォーマンス面だけを見た本来のスコアは 13000 に到達していました。しかし，ファイルロック処理を消してしまったため，データ不整合で大幅な減点が発生しており，結果的に 9000 代となっていたのでした。ここでこのまま突っ走る意思決定をしてしまったのですが，これが原因で（？）さらに苦しむことに。

管理画面の課金レポート発行処理のチューニング

ここで，リクエスト頻度はそこまで多くはないものの，配点が他のエンドポイントに対して 10 倍という重み付けが行われていた管理画面にもメスを入れることに。 GET /api/admin/tenants/billing を見ていきます。

レポート発行の全体処理

// テナントごとに
//   大会ごとに
//     scoreが登録されているplayer * 100
//     scoreが登録されていないplayerでアクセスした人 * 10
//   を合計したものを
// テナントの課金とする
ts := []TenantRow{}
if err := adminDB.SelectContext(ctx, &ts, "SELECT * FROM tenant ORDER BY id DESC"); err != nil {
	return fmt.Errorf("error Select tenant: %w", err)
}
tenantBillings := make([]TenantWithBilling, 0, len(ts))
for _, t := range ts {
	if beforeID != 0 && beforeID <= t.ID {
		continue
	}
	err := func(t TenantRow) error {
		tb := TenantWithBilling{
			ID:          strconv.FormatInt(t.ID, 10),
			Name:        t.Name,
			DisplayName: t.DisplayName,
		}
		tenantDB, err := connectToTenantDB(t.ID)
		if err != nil {
			return fmt.Errorf("failed to connectToTenantDB: %w", err)
		}
		defer tenantDB.Close()
		cs := []CompetitionRow{}
		if err := tenantDB.SelectContext(
			ctx,
			&cs,
			"SELECT * FROM competition WHERE tenant_id=?",
			t.ID,
		); err != nil {
			return fmt.Errorf("failed to Select competition: %w", err)
		}
		for _, comp := range cs {
			report, err := billingReportByCompetition(ctx, tenantDB, t.ID, comp.ID)
			if err != nil {
				return fmt.Errorf("failed to billingReportByCompetition: %w", err)
			}
			tb.BillingYen += report.BillingYen
		}
		tenantBillings = append(tenantBillings, tb)
		return nil
	}(t)
	if err != nil {
		return err
	}
	if len(tenantBillings) >= 10 {
		break
	}
}

またいかにも ISUCON らしいコードを発見。アプリケーション側でのページネーション。潰しにかかります。

 ts := []TenantRow{}
-if err := adminDB.SelectContext(ctx, &ts, "SELECT * FROM tenant ORDER BY id DESC"); err != nil {
-	return fmt.Errorf("error Select tenant: %w", err)
-}
+if beforeID == 0 {
+	if err := adminDB.SelectContext(ctx, &ts, "SELECT * FROM tenant ORDER BY id DESC LIMIT 10"); err != nil {
+		return fmt.Errorf("error Select tenant (first): %w", err)
+	}
+} else {
+	if err := adminDB.SelectContext(ctx, &ts, "SELECT * FROM tenant WHERE id < ? ORDER BY id DESC LIMIT 10", beforeID); err != nil {
+		return fmt.Errorf("error Select tenant (paginated): %w", err)
+	}
+}
+
+wg := &sync.WaitGroup{}
-tenantBillings := make([]TenantWithBilling, 0, len(ts))
+tenantBillings := make([]TenantWithBilling, len(ts), len(ts))
+
+for i, t := range ts {
-	if beforeID != 0 && beforeID <= t.ID {
-		continue
-	}
+	wg.Add(1)
+	go func(i int, t TenantRow, ctx context.Context) {
+		defer wg.Done()
-		err := func(t TenantRow) error {
+		err := func(i int, t TenantRow, ctx context.Context) error {
 			tb := TenantWithBilling{
 				ID:          strconv.FormatInt(t.ID, 10),
 				Name:        t.Name,
 				DisplayName: t.DisplayName,
 			}
 			tenantDB, err := connectToTenantDB(t.ID)
 			if err != nil {
 
 				return fmt.Errorf("failed to connectToTenantDB: %w", err)
 			}
 			defer tenantDB.Close()
 			cs := []CompetitionRow{}
 			if err := tenantDB.SelectContext(
 				ctx,
 				&cs,
 				"SELECT * FROM competition WHERE tenant_id=?",
 				t.ID,
 			); err != nil {
 				return fmt.Errorf("failed to Select competition: %w", err)
 			}
 			for _, comp := range cs {
 				report, err := billingReportByCompetition(ctx, tenantDB, t.ID, comp.ID)
 				if err != nil {
 					return fmt.Errorf("failed to billingReportByCompetition: %w", err)
 				}
 				tb.BillingYen += report.BillingYen
 			}
-           tenantBillings = append(tenantBillings, tb)
+			tenantBillings[i] = tb
 			return nil
-       }(t)
+		}(i, t, ctx)
+		if err != nil {
+			log.Errorf("tenant go func error: %w\n", err)
+		}
+	}(i, t, ctx)
-	if err != nil {
-		return err
-	}
-	if i >= 10 {
-		break
-	}
}
+wg.Wait()

取得処理に関しては Goroutine を使って並列実行にする意味が大いにあると思ったので，ここは頑張って対応させてみました。

かなり気をつける必要があると思ったのがここです。

-tenantBillings := make([]TenantWithBilling, 0, len(ts))
+tenantBillings := make([]TenantWithBilling, len(ts), len(ts))

-tenantBillings = append(tenantBillings, tb)
+tenantBillings[i] = tb

Goroutine にして順番を維持するためには，スライスのキャパシティだけでなく中身まで最初から埋めて置かなければならないという点です。 make() の第2引数は必ず len(ts) でなければなりません。これを怠ると，範囲外アクセスで実行時エラーになってしまいます。

さて，これで確認…となったところ，データ不整合で何故か 0 点になってしまう状況が続いていました。症状としては Admin に存在しているテナントの SQLite ファイルが存在しないというものでした。Goroutine が原因かな？と思い直列実行にしてみても一切改善されず。

• 変更したブランチの先頭に元のブランチのクエリと同じクエリを入れてログをとっても不整合データが取得される
• なぜか全体を元のブランチに戻すと改善される

もう目が？？？でしたね。

私「おかしい。論理的に絶対それは起こり得ない。」

躍起になってしまった私はここで無限に時間を使わされ，バックエンド担当としてもう力を失ってしまいました。最終的にここからほとんど何の成果も出せていません

結局元のブランチで動いた理由は最後まで謎ではあったんですが，少なくともデータ不整合が起こっていた原因は後から分かりました。この部分です。

// SasS管理者用API
// テナントを追加する
// POST /api/admin/tenants/add
func tenantsAddHandler(c echo.Context) error {

	// ... 

	id, err := insertRes.LastInsertId()
	if err != nil {
		return fmt.Errorf("error get LastInsertId: %w", err)
	}
	// NOTE: 先にadminDBに書き込まれることでこのAPIの処理中に
	//       /api/admin/tenants/billingにアクセスされるとエラーになりそう
	//       ロックなどで対処したほうが良さそう
	if err := createTenantDB(id); err != nil {
		return fmt.Errorf("error createTenantDB: id=%d name=%s %w", id, name, err)
	}

	// ...

}

// NOTE: 先にadminDBに書き込まれることでこのAPIの処理中に
//       /api/admin/tenants/billingにアクセスされるとエラーになりそう
//       ロックなどで対処したほうが良さそう

アアアアアアアアアアアアアアアアアアアアアアアアア

ここで MySQL 側にトランザクション1個でも張っておけば防げたかもしれないと思うと本当に悲しみが深い

インフラが全体的にぶっ壊れる

回復作業

そして失格

• セキュリティグループ改変
• 再起動試験で 502 エラー， 0点

感想・反省

• 事前準備が足りないのもあるけど，本当にまず落ち付け。
• チームメイトをアテにしすぎない。自分がいじってるコードぐらい自分でも最低限確認しよう。
• Go の Linter を入れる
• sqlx の可変長パラメータ機能は賢く使用する
  • 複数件 SELECT も，バルクインサートも，全部できるんだよ
  • 最悪これが使えないような技術選定でもなんとかなるように，よく使うスニペットは準備してコピペだけでいいようにしておく
• コミットメッセージをもう少しマシに
  • といいつつも，プルリクのタイトルだけちゃんとしてたら本来は OK だったはず
  • master に wip の直プッシュを始めたのが諸悪の根源（どこの PHP フレームワーク作者だよ…）
• NewRelic，APM 入れたところまではよかったけどログの監視が整備できていなかった
  • 不整合データなどを素早く検知するきっかけになるはず
• NewRelic 入れたり抜いたりするのを，もう少しコード変更少なく済むように抽象化したい
• 根本的なところで困ったら運営に質問する！
• 再起動試験はサボらずに絶対にやる（開幕直後にもやる）

その他

予選2位の方のレポートがとても参考になりました。

さすがに今回のやつは難しすぎなんじゃないかなー，予選の難易度じゃないｗ

---

こちらは 7 位の方ですが，なんと SQLite のままここまで達成出来た模様。惜しい…これになりたかった！

---

公式解説出てました！

• 初期データの圧縮を考える
• /initialize エンドポイントの初期化処理を適宜書く

このへんは次回強く意識したい