目次を表示する

RDB内部構造完全ガイド

EXPLAIN ANALYZE 完全ガイド ── 実行計画を読みこなす

EXPLAIN ANALYZE 完全ガイド ── 実行計画を読みこなす

このスキルの役割:「なぜこのクエリが遅いのか」を特定する最も重要なツール。


EXPLAIN ANALYZE — 実行計画の読み方・ボトルネック特定

この章で何ができるようになるか:EXPLAIN ANALYZE の出力を上から下まで読み解き、ボトルネックを特定して改善策を提案できるようになる。


EXPLAIN vs EXPLAIN ANALYZE

-- EXPLAIN: 実行計画を表示(実行しない。推定値のみ)
EXPLAIN SELECT * FROM users WHERE age > 30;

-- EXPLAIN ANALYZE: 実際に実行して、実測値を表示
EXPLAIN ANALYZE SELECT * FROM users WHERE age > 30;

-- EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT): バッファアクセスも表示
EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM users WHERE age > 30;

出力の読み方

EXPLAIN (ANALYZE, BUFFERS) 
SELECT u.name, COUNT(o.id)
FROM users u
JOIN orders o ON u.id = o.user_id
WHERE u.status = 'active'
GROUP BY u.name
ORDER BY count DESC
LIMIT 10;
Limit  (cost=1500.00..1500.03 rows=10 width=40) (actual time=45.2..45.3 rows=10 loops=1)
  ->  Sort  (cost=1500.00..1502.50 rows=1000 width=40) (actual time=45.2..45.2 rows=10 loops=1)
        Sort Key: (count(o.id)) DESC
        Sort Method: top-N heapsort  Memory: 26kB
        ->  HashAggregate  (cost=1450.00..1460.00 rows=1000 width=40) (actual time=44.5..44.8 rows=1000 loops=1)
              Group Key: u.name
              Batches: 1  Memory Usage: 200kB
              ->  Hash Join  (cost=125.00..1300.00 rows=30000 width=36) (actual time=5.2..35.0 rows=30000 loops=1)
                    Hash Cond: (o.user_id = u.id)
                    ->  Seq Scan on orders o  (cost=0.00..800.00 rows=50000 width=8) (actual time=0.01..10.0 rows=50000 loops=1)
                          Buffers: shared hit=500 read=150
                    ->  Hash  (cost=100.00..100.00 rows=2000 width=36) (actual time=5.0..5.0 rows=2000 loops=1)
                          Buckets: 4096  Batches: 1  Memory Usage: 150kB
                          ->  Seq Scan on users u  (cost=0.00..100.00 rows=2000 width=36) (actual time=0.01..3.0 rows=2000 loops=1)
                                Filter: (status = 'active'::text)
                                Rows Removed by Filter: 8000
                                Buffers: shared hit=80
Planning Time: 0.5 ms
Execution Time: 45.5 ms

各項目の意味

cost=125.00..1300.00:
  125.00 = startup cost(最初の行を返すまでの推定コスト)
  1300.00 = total cost(全行を返すまでの推定コスト)

rows=30000:
  推定返却行数

actual time=5.2..35.0:
  5.2ms = 最初の行を返した実測時間
  35.0ms = 全行を返した実測時間

rows=30000:
  実際の返却行数

loops=1:
  このノードが何回実行されたか(Nested Loop の内側は外側の行数分ループ)

Buffers: shared hit=500 read=150:
  shared hit: バッファキャッシュから読んだページ数(高速)
  read: ディスクから読んだページ数(低速)
  → hit 率 = 500 / (500+150) ≈ 77%

よくあるボトルネックパターン

パターン1: 推定行数と実際の行数の大きなずれ

->  Index Scan using idx_users_status on users
      (cost=0.43..8.45 rows=1 width=64)
      (actual time=0.05..150.00 rows=50000 loops=1)
      ★ rows=1(推定)vs rows=50000(実測)→ 50000倍のずれ!

原因:統計情報が古い。対策ANALYZE users;

パターン2: Seq Scan がインデックスがあるのに使われる

->  Seq Scan on users  (cost=0.00..20000.00 rows=90000 width=64)
      Filter: (status = 'active'::text)
      Rows Removed by Filter: 10000

原因の候補

  • 返却行数がテーブルの大部分(90%)→ Seq Scan が正しい判断
  • random_page_cost が高すぎる(SSD なのに HDD 設定)
  • 統計情報の不正確

パターン3: Nested Loop が大量にループ

->  Nested Loop  (cost=0.43..50000.00 rows=100 width=64)
      (actual time=0.1..5000.0 rows=100 loops=1)
      ->  Seq Scan on orders  (actual time=0.01..10.0 rows=10000 loops=1)
      ->  Index Scan on users  (actual time=0.05..0.05 rows=1 loops=10000)
                                                              ★ loops=10000

内側のノードが10000回ループ → 合計で 10000 × Index Scan。1回は速くても合計で遅い。

対策:Hash Join に切り替えるか、内側のインデックスを確認。

パターン4: ディスク読み込みが多い

Buffers: shared hit=100 read=9000

hit 率 ≈ 1%。ほぼ全てがディスク読み込み。

対策shared_buffers を増やす。頻繁にアクセスするテーブルが小さければ、pg_prewarm でキャッシュに載せる。


EXPLAIN のベストプラクティス

-- 本番環境で安全に EXPLAIN ANALYZE する(書き込みクエリの場合)
BEGIN;
EXPLAIN (ANALYZE, BUFFERS) UPDATE orders SET status = 'shipped' WHERE id = 123;
ROLLBACK;  -- 実際の更新は取り消す(ANALYZE の結果は取得できる)

-- 複数回実行して安定した結果を得る(キャッシュの影響を排除)
-- 1回目: ディスクから読み込み(cold cache)
-- 2回目以降: バッファキャッシュから読み込み(warm cache)

auto_explain:遅いクエリを自動で記録

-- postgresql.conf
shared_preload_libraries = 'auto_explain'
auto_explain.log_min_duration = '1s'  -- 1秒以上のクエリの実行計画を自動記録
auto_explain.log_analyze = on
auto_explain.log_buffers = on
auto_explain.log_format = 'json'  -- JSON 形式で記録(解析しやすい)

まとめ:EXPLAIN チェックリスト

□ 推定行数と実際の行数が大きくずれていないか → ANALYZE
□ Seq Scan が不適切に選ばれていないか → インデックスと統計情報を確認
□ Nested Loop の loops が異常に多くないか → JOIN 戦略の見直し
□ Sort が disk sort になっていないか → work_mem を増やす
□ Buffers の read が hit に対して多すぎないか → shared_buffers の調整
□ Planning Time が異常に長くないか → pg_stat_statements でクエリ識別