ISUCON 12 初参戦レポート

# 概要

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

https://isucon.net/archives/56571716.html

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

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

| メンバー | 主なロール |
|:---|:---|
| joe [@joe_yuzupi](https://twitter.com/joe_yuzupi) | インフラ |
| mpyw [@mpyw](https://twitter.com/mpyw) | バックエンド |
| chaba [@Tea_Server](https://twitter.com/Tea_Server) | マネジメント |

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

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

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

https://sekolog.netlify.app/6_isucon12/

# タイムライン

| 時刻 | 概算スコア | 施策 |
|:---|:---|:---|
| 開催前 | - | 事前練習 |
| 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 の改修から取り掛かる方針で合意し開発を開始しました。

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

https://twitter.com/mpyw/status/1551182827722797057

https://twitter.com/mpyw/status/1551183185643700224

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

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

https://github.com/mpyw-yattemita/isucon12-webapp

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

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

https://twitter.com/mpyw/status/1550786222007525376

https://twitter.com/mpyw/status/1551079742132355073

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

## New Relic 導入

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

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

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

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

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

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

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

## 要件の把握

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

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

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

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

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

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

https://zenn.dev/mpyw/articles/rdb-advisory-locks

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

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

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

### `player_score` にインデックス追加

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

```diff_sql
 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` カラム自体いらねーじゃん！と突っ込みたくなりますが，気づけませんでした:cry: しかし MySQL へのデータ移行を行う場合は必要になるので，敢えて消さなくても良かったかなとは思います）

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

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

<details>
<summary>ランキング取得の全体処理</summary>

```go
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
	}
}
```
</details>

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

以下のように直します。

```diff_go
 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` に書き換えてしまいました…:cry:

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

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/25060/e052c595-1975-eee7-ba2d-4a1e78adf349.png)

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

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

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

```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 でも馴染みがあったものの，またテンパってしまいました:cry:

```diff_go
+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
+}
```

```diff_go
 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")
	}
```

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

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

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

https://blog.tokumaru.org/2017/03/sqlite-strange-quoting.html

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

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

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

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

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

https://igatea.hatenablog.com/entry/2020/12/22/200000

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

> 決まった手続きなので以下のようなラッパー関数を作ってもいいかもしれない
> ```go
> 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 的にはベターかもしれないけど。

https://github.com/jmoiron/sqlx/blob/e6cd7aeb37fdc1f55832e59aec8c376e43658c8b/bind.go#L179-L181

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

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

```diff_go
-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レコードだけで十分だった模様。唯一の利用箇所がこうなっていました。

```go
// ランキングにアクセスした参加者の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` に

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

```go
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 でよくない？」*

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

```diff_sql
 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);
```

…からの，これ！

```diff_go
-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 なのに:cry::cry::cry::cry::cry:

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

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

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

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

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

という条件と，

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

という事実から，

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

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

### `player_score` 挿入処理をバルク `UPSERT` に

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

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

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

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

```diff_go
+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 を主キーとしてインサートすると，単調増加でないためインデックス性能が劣化する**ことが分かっています。

https://zenn.dev/mpyw/articles/rdb-ids-and-timestamps-best-practices

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

ライブラリとしては [oklog/ulid](https://github.com/oklog/ulid) を使用しています。

```diff_go
 // システム全体で一意な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 位**をつけていました :tada:

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/25060/c5a86061-be70-0d0b-53d3-05abb2a57c5b.png)

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

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

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

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

<details>
<summary>レポート発行の全体処理</summary>

```go
// テナントごとに
//   大会ごとに
//     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
	}
}
```
</details>

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

```diff_go
 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 を使って並列実行にする意味が大いにあると思ったので，ここは頑張って対応させてみました。

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

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

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

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

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

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

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

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

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

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

```go
// 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)
	}

	// ...

}
```

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

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

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

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

https://twitter.com/mpyw/status/1550835960304537602

https://twitter.com/joe_yuzupi/status/1550845886103965702

https://twitter.com/joe_yuzupi/status/1550771354936680448

## 回復作業

https://twitter.com/Tea_Server/status/1550774113899544576

## そして失格

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

# 感想・反省

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

# その他

https://matsuu.hatenablog.com/entry/2022/07/24/153403

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

https://twitter.com/mpyw/status/1550870768845987845

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

----

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

https://blog.p1ass.com/posts/isucon12/

https://twitter.com/mpyw/status/1551475880480088064

----

https://isucon.net/archives/56842718.html

公式解説出てました！

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

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