【課題 4】1 行ずつ書いている

読了目安約3分

CSV の 1 行ごとに MySQL へ書きに行っていた処理をまとめて、スコアが 3.5 倍になった回です。

この章の目次

計測がずっと指していた REPLACE INTO id_generator を見ます。

手がかり

スロークエリログでは 17914 回、合計 49 秒でした。サーバーの資源の使われ方はこうなっています。

テキスト

--- CPU (all, 平均) ---
avg%usr=26.8 avg%sys=16.8 avg%iowait=20.6 avg%busy=64.2
--- Disk IO (vda) ---
avg_tps=5998 avg_wr=57232kB/s

%iowait は、CPU がディスクの応答を待って何もしていない時間の割合です。 2 割が待ち時間で、毎秒 57 MB を書いています。

課題

スコアの CSV 入稿ハンドラです。

Go
var rowNum int64
playerScoreRows := []PlayerScoreRow{}
for {
	rowNum++
	row, err := r.Read()
	if err != nil {
		if err == io.EOF {
			break
		}
		return fmt.Errorf("error r.Read at rows: %w", err)
	}
	playerID, scoreStr := row[0], row[1]
	if _, err := retrievePlayer(ctx, tenantDB, playerID); err != nil {
		if errors.Is(err, sql.ErrNoRows) {
			return echo.NewHTTPError(http.StatusBadRequest, "player not found")
		}
		return fmt.Errorf("error retrievePlayer: %w", err)
	}
	var score int64
	if score, err = strconv.ParseInt(scoreStr, 10, 64); err != nil {
		return echo.NewHTTPError(http.StatusBadRequest, "invalid score")
	}
	id, err := dispenseID(ctx)
	if err != nil {
		return fmt.Errorf("error dispenseID: %w", err)
	}
	now := time.Now().Unix()
	playerScoreRows = append(playerScoreRows, PlayerScoreRow{
		ID: id, TenantID: v.tenantID, PlayerID: playerID,
		CompetitionID: competitionID, Score: score, RowNum: rowNum,
		CreatedAt: now, UpdatedAt: now,
	})
}

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: %w", err)
	}
}

dispenseID は ID を 1 つ作る関数です。

Go
ret, err := adminDB.ExecContext(ctx, "REPLACE INTO id_generator (stub) VALUES (?);", "a")

CSV 1 行につき何回、どこへ書き込みが起きるか数えてください。そのうえで、減らせるものを 3 つ挙げてください。

解答例

CSV の 1 行につき、次の 3 つが起きています。

retrievePlayer で SQLite に 1 クエリ
dispenseID で MySQL に 1 回書き込み
INSERT で SQLite に 1 回書き込み

2 番が重大です。 ID を 1 つもらうためだけに、別プロセスの MySQL へ行って書き込んでいます。書き込みはディスクへの記録を伴うので、読み取りよりずっと高くつきます。

ID の採番を 1 回にする

ID に必要なのは一意であることだけです。 1 回だけ採番して、行番号を付ければ一意になります。

Go
baseID, err := dispenseID(ctx)
if err != nil {
	return fmt.Errorf("error dispenseID: %w", err)
}
// ループの中で
ID: fmt.Sprintf("%s_%d", baseID, rowNum),

player_score.id はどの API のレスポンスにも現れません。形式を変えてよいと判断できるのは、それを確認したからです。

存在確認をまとめる

参加者の一覧を先に引いて、map で照合します。

Go
playerIDs := []string{}
if err := tenantDB.SelectContext(
	ctx, &playerIDs, "SELECT id FROM player WHERE tenant_id = ?", v.tenantID,
); err != nil {
	return fmt.Errorf("error Select player: %w", err)
}
playerIDSet := make(map[string]struct{}, len(playerIDs))
for _, id := range playerIDs {
	playerIDSet[id] = struct{}{}
}

CSV を読むループでは、この map を見るだけで済みます。

Go
if _, ok := playerIDSet[playerID]; !ok {
	return echo.NewHTTPError(http.StatusBadRequest, "player not found")
}

クエリを消すときに、応答の約束まで一緒に消さないようにします。元の実装は、存在しない参加者 ID に 400 を返していました。

INSERT を 1 文にまとめる

sqlx は構造体のスライスを渡すと、複数行ぶんの VALUES を 1 文で組み立てます。 1 文に詰め込める値の数には上限があるので、区切って渡します。

Go
const chunkSize = 100
for start := 0; start < len(playerScoreRows); start += chunkSize {
	end := start + chunkSize
	if end > len(playerScoreRows) {
		end = len(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)",
		playerScoreRows[start:end],
	); err != nil {
		return fmt.Errorf("error Insert player_score: %w", err)
	}
}

効果

	スコア
参加者詳細の N+1 を消した	10105
CSV 入稿をまとめた	35888

3.5 倍になりました。資源の使われ方も変わっています。

	直す前	直したあと
`%iowait`	20.6	4.5
ディスク書き込み	57 MB/s	26 MB/s
アプリの CPU 使用率	43.5	81.9

ディスク待ちが消えて、CPU が仕事をするようになりました。 Part 7 の言い方をすれば、先に限界へ来る資源がディスクから CPU へ移りました。

犯人は移動する

同じ 60 秒で捌けたリクエストは、参加者詳細が 3260 件から 18343 件に増えました。速くなったぶん、ベンチマーカーが参加者を増やして押し込んできます。

ここから先は、次にどこが限界なのかを測り直すところからです。