はじめに

こんにちは、yuhiです。
こちらはアドベントカレンダー11日目の記事です。

本記事では、ISUCON14の素振りとしてISUCON12本戦の問題を公式解説ブログなどを参照せず、自力で解いていきます。

ちなみにこんな記事を書いているので読んでいただけると幸いです。

想定読者

ISUCON初心者
private-isuを一通り解き終えた方
レポジトリはこちらです。

環境構築

以下のAMIを使用しました。
ベンチマーカー1台、サーバー5台を c5.large で起動しています。
https://github.com/matsuu/aws-isucon

ベンチマーカーの実行は以下のコマンドで行います。

export ISUXBENCH_TARGET={対象のサーバーアドレス}
./bin/benchmarker --stage=prod --request-timeout=10s --initialize-request-timeout=60s

初回ベンチ (51点)

mysqlのCPU利用率が高めの170%~190%程度で推移していました。

alp、スロークエリ解析、interpolateParams=true の設定 (0点)

ツールセットアップやgit管理をした
find . -type f -size +50M で容量が大きいファイルを特定して.gitignoreに入れる

複合インデックス追加 (11528点)

pt-query-digest で user_present_all_received_history テーブルへの SELECT クエリの負荷が高いことが判明しました。
複合インデックスを追加しました。

# Rank Query ID                      Response time  Calls R/Call  V/M   It
# ==== ============================= ============== ===== ======= ===== ==
#    1 0x8267197805BC46534E450B65... 517.5881 80.4%  1160  0.4462  0.17 SELECT user_present_all_received_history


SELECT * FROM user_present_all_received_history WHERE user_id=5372 AND present_all_id=14\G

ALTER TABLE user_present_all_received_history ADD INDEX idx_user_id_present_all_id(user_id, present_all_id);

ユニークIDの生成方法を変更 (12888点)

id_generator テーブルへの負荷が高かったため、タイムスタンプを利用してユニークIDを生成するように変更しました。

# Rank Query ID                     Response time  Calls R/Call  V/M   Ite
# ==== ============================ ============== ===== ======= ===== ===
#    1 0xC23B03A4AE16C514BBC64AA... 781.1528 64.9% 27970  0.0279  0.17 UPDATE id_generator

UPDATE id_generator SET id=LAST_INSERT_ID(id+1)\G

CREATE TABLE `id_generator` (
  `id` bigint NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin;

プレゼント受け取り処理のバルク更新 (13642点)

/user/:userId/present/receive の処理でループ内で UPDATE を実行していた箇所を、バルク更新に変更しました。

どうでも良いがゲームのプレゼント処理は論理削除にするんだーと感心。でも論理削除はインデックスが効きづらくなるので削除テーブルを作成するかもと思った。

user_presents に複合インデックス追加 (13147点)

# Profile
# Rank Query ID                     Response time  Calls R/Call  V/M   Ite
# ==== ============================ ============== ===== ======= ===== ===
#    1 0x611363ACBD1690538F13775... 100.1236 20.6%  1261  0.0794  0.19 SELECT user_presents

SELECT * FROM user_presents 
    WHERE user_id = 9903364419 AND deleted_at IS NULL
    ORDER BY created_at DESC, id
    LIMIT 100 OFFSET 0\G

削除テーブルを作成してuser_presentsは受け取られていないプレゼントのみを管理しようと考えたが、適用範囲が広く一旦断念しました。
とりあえず雑に複合インデックスを貼りました。

ALTER TABLE user_presents DROP INDEX userid_idx;
ALTER TABLE user_presents ADD INDEX idx_user_id_deleted_at(`user_id`, `deleted_at`)

点数は変わりませんが、スロークエリからいなくなったので良しとしました。

obtainPresentにてIN句でユーザーが取得済みのプレゼントを取得 (13211点)

スロークエリ2位のクエリではN+1が発生したので修正しました。

#    2 0x8267197805BC46534E450B6... 15.1814  8.3% 26413  0.0006  0.00 SELECT user_present_all_received_history

ここら辺のGo周りの凡ミス多いので気をつけたいですね
https://github.com/Yuhi-Sato/isucon12-f-2/pull/2/commits/71873f1212f09461686e3edc41cef939c3248583

obtainPresentにてバルクインサート　 (15383点)

INSERTを叩く回数が多かったのでバルクインサートをしました。

#    3 0x03FFA53B9AEA23779E51FE7... 11.4648  5.9% 21420  0.0005  0.01 INSERT user_presents

notReceivedNormalPresentsが空の場合のエラーハンドリングが必要で40分くらい沼りました。
https://github.com/Yuhi-Sato/isucon12-f-2/pull/3/commits/0e2c4d82f2484c2587e521aa64951aefcdfe14a5

item_mastersをキャッシュ (13591点)

^/user/\d+/present/receive$が以前として重いのです。そこで
item_mastersはベンチ終了後でも30レコードほどなのでキャッシュしました。admin側でインサートする処理があったのですが、一度しか叩かれてないので効くはずと思いきやスコアが下がりました。しかし、^/user/\d+/present/receive$のレスポンスのAVGが速くなっていたので良しとしました。

^/user/\d+/present/receive$のobtainItemにてN+1が発生していますが、item_typeによって分岐があり結構ややこしいので、後回しとすることにしました。

obtainPresentにてバルクインサート再び (15077点)

#    3 0x03FFA53B9AEA23779E51FE7... 12.7485  6.5% 21842  0.0006  0.01 INSERT user_presents

drawGachaのバルクインサート　　(15473点)

#    7 0x03FFA53B9AEA23779E51FE7... 10.9307  5.0% 11969  0.0009  0.01 INSERT user_presents

mysqlを2台目のサーバーに切り離した　(13594点)

なぜか点数が下がっているが、全体的にレスポンス速度が上がったので良しとしました。

|  1271 |   1 |   8 |   0 | POST   | ^/user/\d+/present/receive$    |  0.020 |  0.424 | 134.824 |  0.106 |  0.332 |
|   954 |  49 |  85 |   0 | POST   | /login                         |  0.012 |  0.224 |  53.752 |  0.056 |  0.176 |

ファイルディスクリプタ調整　(39932点)

DBのコネクションプール上げたら、POST /loginが500レスポンスしてベンチが中断され点数が下がったので、nginxのエラーログを確認してみたらToo many open filesと怒られていた。ファイルディスクリプタを調整した。初手でnginxの秘伝のタレは流してもいいのかもしれないです。

Read Committed分離へ変更　(38556点)

ロック待ちが多くなっていたのでギャップロックが発生してそうでした。なので特に何も調査せずエイと分離レベルを変更しました（絶対に良くない）。

# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0    3300
# Exec time     43    382s   121us   706ms   116ms   412ms   139ms    48ms
# Lock time     98    291s       0   681ms    88ms   339ms   118ms    23ms

改善後

# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count          0    3182
# Exec time     51    550s   146us      1s   173ms   640ms   215ms    75ms
# Lock time      8    49ms       0    20ms    15us     1us   442us     1us

2台目に切り離したMySQLがCPU利用率200%でぱつってたのでそろそろ3台目以降を使っていきたいのです。

おそらく、userIDでシャーディングをするという問題なのですが、シャーディングの実装をしたことがないので必要なことを考えてみます。

初期データの対応
- ベンチを叩く前に各DBを初期状態に直す
- ただし、POST /initializeに時間制限があるので、各ホストでsql/init.shを叩く必要がある
DBクライアントをホスト個数分作成
- IPv4アドレスを指定してインスタンスを立ち上げる
各クエリにおいて参照・書き込むDB先を動的に決定
- userIDのmod {DBホストの個数}をとれば良さそう

user_one_time_tokensを2つのDBへシャーディング　(46561点)

シャーディングは以下のように実装しました。

// DBホストを定義
dbHosts = []string{"52.194.37.96", "35.79.6.218"}

// ハンドラーにシャード化されたDBクライアントを定義
type Handler struct {
  DB          *sql.DB
  ShardedDBs []*sql.DB
}

// シャード化されたDBクライアントを作成する関数
func NewShardedDBs(shardCount int) ([]*sqlx.DB, error) {
	dbs := make([]*sqlx.DB, shardCount)

	for i := 0; i < shardCount; i++ {
		db, err := connectDB(false, i)
		if err != nil {
			return nil, fmt.Errorf("failed to connect to shard %d: %w", i, err)
		}
		dbs[i] = db
	}

	return dbs, nil
}

// シャード化されたDBに接続する関数
func connectDB(batch bool, shardIndex int) (*sqlx.DB, error) {
	dsn := fmt.Sprintf(
		...
		dbHosts[shardIndex],
		...
	)
	...

	return dbx, nil
}

// userIDのmodでDBホストを決定する関数
func (h *Handler) GetDB(userID int64) *sqlx.DB {
	shardIndex := int(userID) % len(dbHosts)

	return h.ShardedDBs[shardIndex]
}

// シャード化されたDBを動的に決定する
db := h.GetDB(userID)

user_sessionsにインデックス　(57756点)

# Rank Query ID                     Response time  Calls  R/Call V/M   Ite
# ==== ============================ ============== ====== ====== ===== ===
#    1 0x8CA5C26DA1F53D285B58FE4... 461.2995 52.9%  21696 0.0213  0.05 SELECT user_sessions

SELECT * FROM user_sessions WHERE session_id='5f1abf43-4a15-46cd-8d3c-119e952d563d' AND deleted_at IS NULL\G

DB4台でシャーディング　(61764点)

user_presentsをシャーディング　(71901点)

# Rank Query ID                     Response time Calls  R/Call V/M   Item
# ==== ============================ ============= ====== ====== ===== ====
#    1 0x6E790EE92EFF4755B6E0FA8... 74.3873 19.9%   5139 0.0145  0.04 UPDATE user_presents
#    2 0x03FFA53B9AEA23779E51FE7... 33.0966  8.8%   7826 0.0042  0.03 INSERT user_presents
#    3 0xE89B4FB5E77ED142BEAF8C3... 25.6172  6.8%   5139 0.0050  0.03 SELECT user_presents
#    4 0x611363ACBD1690538F13775... 22.5625  6.0%   5159 0.0044  0.03 SELECT user_presents

user_present_all_received_historyのバルクインサートとuser_itemsのキャッシュ　(78673点)

以下のクエリが多く呼ばれているのでバルクインサートとキャッシュをしました。

#    4 0x41CEDDDAFB6289B60E5F30D... 17.1698  6.6%  51885 0.0003  0.02 INSERT user_present_all_received_history
#    5 0xC20D9D224412E78025DDB69... 15.6412  6.0%  67462 0.0002  0.01 SELECT user_items

残りは地道にuserIDで振り分けていく作業になり、学びが少なそうなのでここでフィニッシュ

最後に

本記事では、ISUCON12本戦を通して得られた知見をまとめました。途中からシャーディング作業が中心となり、やったことのない実装だったのでワクワクしました。残り数日ですが、ISUCON14に向けてまだまだ精進していきます。