ゲストカレンダー 48 秒 → 33ms — 計測ファースト運用で 1,467 倍高速化した TypeORM + MySQL 8 の罠
Phase 0 計測基盤 (slow_query_log + fingerprint 集計) を昨日入れたら、わずか 24 時間で衝撃の発見: ゲストアプリの予約カレンダーが最大 48 秒かかっていた。index 追加では解決せず、8 段 leftJoinAndSelect が引き起こす MySQL 8 の BNL 罠と、2 段階クエリ化での処方箋を共有します。
昨日 (DB パフォーマンス改善 Phase 1) で告白した「部分最適からの脱却」。その翌日、計測ファースト運用が早速仕事をしました。
昨日: Phase 0 計測基盤 (slow_query_log + fingerprint 集計) を本番 RDS に導入
今日: 日中稼働 24 時間で溜まったデータから 最大 48 秒かかっていたクエリ を発見、1,467 倍高速化で決着
1. 何が起きていたか
tasteck のゲストモバイル (guest.no-tel.com) には、お気に入りキャストの空きカレンダーを表示する画面があります。これが「日付を変えると読み込み中のまま」という報告が運営から上がってきました。
実機で測ってみると確かに:
- 初回表示: 3.5 秒
- 日付変更: 45 秒超、スピナー永遠
Phase 0 で入れた slow_query_log を集計するとビンゴ:
24h で 1,437 件のスロークエリ、19 fingerprint
#1: SUM(CASE WHEN status <> 'cancel') ... (474 回、最大 24 秒)
#2: SELECT orders.* LEFT JOIN ... 8 段 JOIN (403 回、最大 47 秒)
#3: DATE(DATE_ADD) GROUP BY day (352 回、最大 4 秒)
Top 3 だけで 1 日 647 秒 (約 11 分) を DB が浪費 していました。
2. 第 1 ラウンド: Phase 1.6 で index 追加
#1 の SUM(CASE WHEN ...) は ダッシュボードの「今日の受注件数・売上」集計。条件は company_id + plan_in_time でしたが、既存 index は全て status を 2 番目に置いており、status で絞らないこのクエリは index が効かない。
CREATE INDEX IDX_order_company_plan_in_time ON orders (company_id, plan_in_time);
130 万行の orders に ALGORITHM=INPLACE で 22 秒で無停止追加。結果:
| クエリ | Before | After |
|---|---|---|
| #1 ダッシュボード集計 | 24 秒 | 33 ms (約 700 倍) |
| #3 日別件数集計 | 4 秒 | 2 ms (約 2000 倍) |
これで #1 と #3 は片付きました。でも #2 が残ります。
3. 第 2 ラウンド: index では解決しない #2 の謎
#2 のフィンガープリントを full SQL で掘り起こすと、ゲスト予約カレンダーの findOrderCalendar:
SELECT orders.*
FROM orders
INNER JOIN shops ON ...
LEFT JOIN orders_options ON ...
LEFT JOIN options ON ...
LEFT JOIN orders_discounts ON ...
LEFT JOIN discounts ON ...
INNER JOIN cast_names ON ...
INNER JOIN nominations ON ...
INNER JOIN courses ON ...
LEFT JOIN additional_time_orders ON ...
WHERE plan_in_time BETWEEN ...
AND status IN (...)
AND cast_name_id IN (2468, 22419, 23471, 24598, 24739)
AND deleted_at IS NULL
ORDER BY plan_in_time DESC
TypeORM の leftJoinAndSelect で 8 段 JOIN。WHERE の条件からすると IDX_order_cast_name_status_plan_in_time (既存 index) が完璧にマッチするはずです。実際 QA で EXPLAIN すると:
type=range key=IDX_order_cast_name_status_plan_in_time rows=20
きれいに効いてる。なのに本番では 47 秒、1,296,211 行スキャン。1 件しか返さないクエリが全表 (142 万行) をなめている。
4. 犯人は MySQL 8 optimizer の BNL 落とし穴
本番で EXPLAIN すると全く違う景色が見えました:
id=1 table=castName type=range key=PRIMARY rows=5
id=1 table=orders type=ALL key=NULL rows=1424194 Extra=Using join buffer
type=ALL + Using join buffer = Block Nested Loop 発動。
MySQL 8 の optimizer は JOIN 順序を勝手に再編します。このクエリでは:
cast_namesを先に絞る (cast_name_id IN (5 値)で 5 行)- その結果を使って
ordersを nested loop で舐める
…のつもりが、コスト計算を誤って orders を full scan + join buffer に突っ込む 決断をしていました。1.4M 行のテーブルに対しこれは致命的。
ANALYZE TABLE orders で統計更新しても plan は変わらず。根本的に optimizer の判断を信用できない状態です。
5. 処方箋: 2 段階クエリ化
optimizer が判断を誤るなら、判断する余地を与えない のが最速の処方箋。クエリを 2 つに分けます:
// Step 1: 条件に合致する order_id のみ抽出 (index 効果確定の軽量クエリ)
const idRows = await qb
.select("orders.order_id", "order_id")
.where("orders.plan_in_time BETWEEN :start AND :end", ...)
.andWhere("orders.status IN (:...status)", ...)
.andWhere("orders.cast_name_id IN (:...castNameIds)", ...)
.getRawMany();
const ids = idRows.map(r => r.order_id);
if (ids.length === 0) return [];
// Step 2: 確定した ID で JOIN 込み fetch (すべて PK = eq_ref)
return await qb2
.innerJoinAndSelect("orders.shop", "shop")
.leftJoinAndSelect("orders.options", "options", "options.is_guest_show = true")
.leftJoinAndSelect("orders.discounts", "discounts")
.innerJoinAndSelect("orders.castName", "castName")
.innerJoinAndSelect("orders.nomination", "nomination")
.innerJoinAndSelect("orders.course", "course")
.leftJoinAndSelect("orders.additionalTimeOrders", "additionalTimeOrders")
.where("orders.order_id IN (:...ids)", { ids })
.orderBy("orders.plan_in_time", "DESC")
.getMany();
Step 1 は IDX_order_cast_name_status_plan_in_time で range scan できる軽い WHERE。orderId だけ取るので JOIN も不要。optimizer に選択肢がないので index を使うしかありません。
Step 2 は order_id IN (確定 ID 配列)。PK 条件なので optimizer は躊躇なく eq_ref で各 JOIN を処理します。
本番で直接計測:
| 実行方法 | 時間 | 結果 |
|---|---|---|
| OLD (従来 8 段 JOIN 直 WHERE) | 48,425 ms | 1 行 |
| NEW Step 1 (orderId 抽出) | 25 ms | 1 件 |
| NEW Step 2 (JOIN 付き fetch) | 8 ms | 1 行 |
| NEW 合計 | 33 ms | 1 行 |
1,467 倍高速化。同じ 1 件の結果を返すのに、従来は 48 秒かかっていたものが 33ms になりました。
6. ついでに castShift も 850 倍
同じ画面で実行される castShift/findByDateAndShop (キャストシフト取得) も常時 3.5 秒かかっていました。こっちは plan_work_start BETWEEN OR plan_work_end BETWEEN の OR 条件が index を無効化していた別系統の問題。
OR を overlap predicate (重なり判定) に書き換え:
// OLD (遅い、OR で index 無効)
.where(new Brackets(qb => {
qb.where("plan_work_start BETWEEN :s AND :e")
.orWhere("plan_work_end BETWEEN :s AND :e");
}))
// NEW (速い、plan_work_start index で range scan)
.where("plan_work_start BETWEEN :earliestStart AND :dayEnd")
.andWhere("plan_work_end > :dayStart")
数学的には「重なり判定」 = starts_before_end AND ends_after_start で表現でき、片方が range scan 可能な形になります。
本番実測: 2,545ms → 3ms (約 850 倍)。
7. 計測ファーストの威力
今回の発見プロセスを整理するとこうなります:
昨日 23:00 Phase 0 計測基盤 (slow_query_log) を本番に投入
今日 夕方 24 時間データで Top 5 fingerprint 取得 → 48 秒クエリ発見
今日 19:00 Phase 1.6 index 追加 (24 秒集計が 33ms に)
今日 19:30 #2 を調査 → optimizer BNL 罠を特定
今日 20:00 2 段階クエリ化 + overlap predicate を実装
今日 20:30 本番デプロイ → ユーザー体感 "爆速" 報告
24 時間の観察と 1 時間の構造修正で 1,467 倍。 場当たりに index を足し続けていた過去半年では絶対に辿り着けなかった診断です。
今回の学び
- 大きなテーブル (1M+ 行) で 7 段以上の
leftJoinAndSelectは危険信号。MySQL 8 の optimizer が BNL を発動しやすい - EXPLAIN で
type=ALL+Using join bufferが BNL のサイン。即 2 段階化を検討 - 日付範囲 OR は overlap predicate に書き換え。「
start <= E AND end >= S」で重なりを表現 - 統計情報を疑うより構造を疑う。
ANALYZE TABLEで直らない optimizer の判断ミスは、クエリ構造で回避する方が確実
まとめ
- 本番ゲストカレンダー体感「読み込み中のまま」→ 「一瞬で表示」
- サーバー DB の 1 日 278 秒 (#2 合計 269 秒 + #castShift 関連 8 秒) の負荷を削除
- 新 index 追加は Phase 1.6 の 1 本のみ、残りは構造修正だけで解決
- 計測ファーストが初日で成果 = 「見えないから直せない」状態から脱却
tasteck はこれからも「地味な健全化」を積み上げていきます。次は Phase 2 (Read Replica) と革財布戦略 (マスター自動生成) が見えてきました。続報をお楽しみに。