記事の一覧

PostgreSQL の EXPLAIN ANALYZE の読み方と実行計画の見方

PostgreSQL の EXPLAIN / EXPLAIN ANALYZE の読み方を解説します。cost・actual time・loops の意味、Seq Scan と Index Scan、BUFFERS、見積もりがずれたときの対処までまとめました。

PostgreSQL で遅いクエリを見つけたら、次に EXPLAIN で実行計画を確かめます。ただ、出力には cost、rows、actual time、loops、Buffers と数字が多く、どこを見ればよいか迷いがちです。この記事では実際の出力の形に沿って各項目の意味を説明し、遅い原因を見つけるための読み方の順番をまとめます。出力例は PostgreSQL 18 の形式です。

EXPLAIN と EXPLAIN ANALYZE の違い

PostgreSQL は SQL を受け取ると、プランナと呼ばれる部分がテーブルの読み方や結合の方法を決めてから実行します。この段取りが実行計画です。

EXPLAIN はクエリを実行せず、プランナが選んだ計画と見積もりだけを表示します。EXPLAIN ANALYZE はクエリを実際に実行し、見積もりに加えて、実際にかかった時間と返した行数を表示します。

-- 見積もりだけ (実行しない)
EXPLAIN SELECT id, total FROM orders WHERE customer_id = 81723;

-- 実際に実行して計測する
EXPLAIN ANALYZE SELECT id, total FROM orders WHERE customer_id = 81723;

遅い原因を調べるときは、見積もりと実際を比べられる EXPLAIN ANALYZE が基本です。PostgreSQL 18 からは ANALYZE を付けると BUFFERS (読んだブロックの数) も自動で表示されます。17 以前では EXPLAIN (ANALYZE, BUFFERS) と明示してください。

更新系のクエリに使うときの注意

EXPLAIN ANALYZE は本当に実行するので、UPDATE や DELETE にかけるとデータが変わります。更新系のクエリを調べるときは、トランザクションで囲んで取り消します。

BEGIN;
EXPLAIN ANALYZE UPDATE orders SET status = 'shipped' WHERE id = 1001;
ROLLBACK;

実行に 10 分かかるクエリなら、EXPLAIN ANALYZE も 10 分かかります。本番で長いクエリを試すときは、まず EXPLAIN だけで計画を確かめるのが無難です。

実行計画の出力の読み方

例として、注文テーブル (約 200 万行) から、ある顧客の最新の注文を 20 件取り出すクエリを使います。customer_id にはまだインデックスがありません。数値は説明のための例です。

EXPLAIN ANALYZE
SELECT id, total, created_at
FROM orders
WHERE customer_id = 81723
ORDER BY created_at DESC
LIMIT 20;
 Limit  (cost=41671.62..41671.67 rows=20 width=24) (actual time=287.641..287.646 rows=20.00 loops=1)
   Buffers: shared hit=1932 read=14735
   ->  Sort  (cost=41671.62..41672.08 rows=182 width=24) (actual time=287.639..287.642 rows=20.00 loops=1)
         Sort Key: created_at DESC
         Sort Method: top-N heapsort  Memory: 27kB
         Buffers: shared hit=1932 read=14735
         ->  Seq Scan on orders  (cost=0.00..41667.00 rows=182 width=24) (actual time=0.412..287.512 rows=196.00 loops=1)
               Filter: (customer_id = 81723)
               Rows Removed by Filter: 1999804
               Buffers: shared hit=1932 read=14735
 Planning Time: 0.118 ms
 Execution Time: 287.689 ms

木の形で読む

実行計画は木の形をしています。-> が付いて字下げされた行は、1 段上の行の子 (入力) です。字下げの深いものから動き、その結果を上の段が受け取ります。この例を下から読むと、次の流れになります。

  1. Seq Scan: orders テーブルを先頭から全部読み、customer_id = 81723 に合う行だけを残す
  2. Sort: 残った行を created_at の新しい順に並べる
  3. Limit: 先頭の 20 件だけを返す

cost (見積もりのコスト)

cost=41671.62..41671.67 は、プランナが見積もったコストです。左が最初の 1 行を出すまでのコスト、右が最後まで出し切るまでのコストです。

単位はミリ秒ではありません。ディスクのページを順番に 1 つ読むコストを 1.0 とした、相対的な値です。異なる計画のどちらが安いかを比べるための数字なので、実際の時間と直接比べても意味はありません。上の段のコストには、子の段のコストが含まれます。

rows と width (見積もりの行数と幅)

1 つ目のかっこの rows は、そのノードが出力すると見積もった行数です。読んだ行数ではない点に注意してください。Seq Scan は 200 万行を読みますが、条件で絞った後に出力する 182 行を rows=182 と見積もっています。width は 1 行の平均の大きさ (バイト) の見積もりです。

actual time・rows・loops (実際の値)

2 つ目のかっこが実際に実行した結果です。

  • actual time=0.412..287.512: 最初の 1 行を出すまでの時間と、最後の行を出すまでの時間 (ミリ秒)
  • rows=196.00: 実際に出力した行数
  • loops=1: このノードが実行された回数

loops が 2 以上のとき、actual time と rows は 1 回あたりの平均です。合計を知るには loops を掛けます。PostgreSQL 18 からは、平均が小数になる場合を考えて、実際の行数が 196.00 のように小数 2 桁で表示されるようになりました。

Filter と Rows Removed by Filter

Filter は、読んだ行に後から当てた条件です。Rows Removed by Filter: 1999804 は、条件で捨てた行の数です。196 行を返すために約 200 万行を読んで捨てていることになり、この計画の無駄がはっきり分かります。捨てた行が返した行より桁違いに多ければ、インデックスで先に絞り込めないかを考えます。

Buffers (読んだブロックの数)

Buffers: shared hit=1932 read=14735 は、データを読んだブロック (8kB 単位のページ) の数です。

  • shared hit: PostgreSQL の共有バッファ (メモリ) にあったブロック数
  • shared read: 共有バッファになく、OS から読み込んだブロック数

read は OS のキャッシュから読めた場合も含むので、すべてがディスクの読み込みとは限りません。ただ、read が多いほど遅くなりやすく、同じクエリを 2 回続けて実行すると 2 回目は hit が増えて速くなる、ということがよくあります。計測するときは 1 回目と 2 回目を分けて見てください。

temp read や temp written が出ている場合は、ソートやハッシュがメモリに収まらず、一時ファイルを使っています。

Planning Time と Execution Time

Planning Time は計画を立てるのにかかった時間、Execution Time は実行にかかった時間です。この例では実行に 288 ミリ秒かかっています。結果をクライアントに送る時間は含まれません。

インデックスを追加すると計画はどう変わるか

条件と並び順に合わせて、複合インデックスを作ります。

CREATE INDEX CONCURRENTLY orders_customer_created_idx
  ON orders (customer_id, created_at);

本番の大きなテーブルでは CONCURRENTLY を付けると書き込みを止めずにインデックスを作れます (そのぶん作成には時間がかかります)。同じクエリの計画は次のように変わります。

 Limit  (cost=0.43..76.12 rows=20 width=24) (actual time=0.031..0.074 rows=20.00 loops=1)
   Buffers: shared hit=23
   ->  Index Scan Backward using orders_customer_created_idx on orders  (cost=0.43..689.21 rows=182 width=24) (actual time=0.030..0.071 rows=20.00 loops=1)
         Index Cond: (customer_id = 81723)
         Index Searches: 1
         Buffers: shared hit=23
 Planning Time: 0.201 ms
 Execution Time: 0.093 ms

Seq Scan が Index Scan Backward に変わり、Sort のノードが消えました。インデックスの中では同じ customer_id の行が created_at の順に並んでいるので、後ろから 20 件読めば並べ替えが要らないからです。読んだブロックは 16,667 から 23 に、実行時間は 288 ミリ秒から 0.09 ミリ秒に減っています。

Index Cond はインデックスで絞り込んだ条件です。Filter と違い、条件に合わない行をそもそも読みません。Index Searches は PostgreSQL 18 で加わった行で、インデックスを何回たどったかを表します。

見積もりの rows=182 に対して実際は 20 行ですが、これは問題ではありません。Limit の下のノードは最後まで読んだと仮定して見積もられるからです。Limit が 20 件で読むのをやめさせています。

スキャン方式の種類

テーブルの読み方 (スキャン方式) には主に次の種類があります。

ノード 読み方 向いている場面
Seq Scan テーブルを先頭から全部読む 小さいテーブル、条件に合う行が多いとき
Index Scan インデックスで行の場所を探し、テーブルから 1 行ずつ読む 条件に合う行が少ないとき
Index Only Scan インデックスだけで答え、テーブルをほとんど読まない 必要な列がすべてインデックスにあるとき
Bitmap Index Scan + Bitmap Heap Scan インデックスで行の場所をまとめて集め、ページの順に読む 条件に合う行がほどほどに多いとき

Seq Scan が出たら必ず悪い、というわけではありません。テーブルの大半の行を返すクエリなら、インデックスを使うより全部読むほうが速いので、プランナは Seq Scan を選びます。問題になるのは、大きなテーブルを Seq Scan で読み、Rows Removed by Filter が大きいときです。

Bitmap Heap Scan の下に出る Recheck Cond は、ビットマップがページ単位に粗くなった場合に、行ごとに条件を確かめ直すためのものです。Rows Removed by Index Recheck が大きいときは、work_mem が足りずビットマップが粗くなっている可能性があります。

Index Only Scan では Heap Fetches の行に注目します。テーブル本体を読みに行った回数で、本来は 0 に近いのが理想です。大きい場合は、可視性マップ (どのページの行が全トランザクションから見えるかの記録) が古くなっています。VACUUM が追いついているかを確かめてください。VACUUM については PostgreSQL の VACUUM の記事 で説明しています。

結合のノードと loops の読み方

結合には Nested Loop、Hash Join、Merge Join の 3 つの方式があります。

Nested Loop は、外側の 1 行ごとに内側を探す方式です。外側の行が少なく、内側をインデックスで引けるときは速いですが、外側の行が多いと内側の処理がその回数だけ繰り返されます。Hash Join は片方のテーブルからハッシュ表を作って突き合わせる方式で、大量の行どうしの結合に向いています。Merge Join は両方を結合キーの順に並べて突き合わせます。

loops の掛け算が重要になるのは Nested Loop の内側です。次の例を見てください。

 Nested Loop  (cost=0.86..25.12 rows=3 width=40) (actual time=0.052..1843.214 rows=48210.00 loops=1)
   ->  Index Scan using orders_status_idx on orders o  (cost=0.43..12.46 rows=3 width=16) (actual time=0.031..92.104 rows=48210.00 loops=1)
         Index Cond: (status = 'pending'::text)
         Filter: (shop_id = 42)
   ->  Index Scan using customers_pkey on customers c  (cost=0.43..4.21 rows=1 width=32) (actual time=0.035..0.035 rows=1.00 loops=48210)
         Index Cond: (id = o.customer_id)

内側の Index Scan は 1 回あたり 0.035 ミリ秒ですが、loops=48210 なので、合計は約 1,690 ミリ秒です。この結合が時間の大半を使っています。

原因は外側の見積もりです。プランナは orders から 3 行しか出ないと見積もったので Nested Loop を選びましたが、実際には 48,210 行出ました。最初から 4 万行と分かっていれば、Hash Join を選んでいた可能性が高い場面です。このように、見積もりと実際の行数のずれは計画の選び間違いの原因になります。

見積もりと実際の行数がずれるときの対処

rows の見積もりと実際が 10 倍、100 倍とずれているノードがあれば、まず統計情報を疑います。プランナはテーブルから抜き出した統計情報 (値の分布など) をもとに行数を見積もっているからです。

最初に試すのは、統計情報の更新です。

ANALYZE orders;

大量のデータを入れた直後や、値の分布が大きく変わった直後は、自動の ANALYZE が追いついていないことがあります。

偏りの大きい列で見積もりが外れる場合は、その列で集める統計の細かさを上げます。既定は default_statistics_target の 100 です。

ALTER TABLE orders ALTER COLUMN status SET STATISTICS 1000;
ANALYZE orders;

上の例のように、2 つの列の条件を組み合わせると外れる場合は、列どうしの相関が原因のことがあります。プランナは通常、列どうしは独立していると仮定して見積もります。たとえば「status = 'pending' の注文は特定の店舗に偏っている」といった関係は反映されません。この場合は拡張統計を作ると改善することがあります。

CREATE STATISTICS orders_status_shop_stats (dependencies, mcv)
  ON status, shop_id FROM orders;
ANALYZE orders;

メモリが足りないときの出力

並べ替えやハッシュがメモリに収まらないと、出力に表れます。

         Sort Method: external merge  Disk: 51200kB

external merge Disk: は、並べ替えがメモリに収まらず、一時ファイルを使ったことを示します。quicksort Memory: や top-N heapsort Memory: ならメモリ上で終わっています。Hash のノードで Batches が 2 以上なら、ハッシュ表も一時ファイルに分けて作られています。

対処は扱う行数を減らす (条件で先に絞る、必要な列だけを選ぶ) か、work_mem を増やすかです。work_mem は 1 つのソートやハッシュごとに使われる上限なので、全体で一律に大きくするとメモリが足りなくなるおそれがあります。特定のクエリだけなら、そのトランザクションの中で SET LOCAL work_mem = '64MB'; のように変える方法が安全です。

並列実行のノード

大きなテーブルでは、Gather や Gather Merge の下に Parallel Seq Scan が出ることがあります。複数のワーカーで分担して読んでいるという意味です。

 Gather  (cost=1000.00..30123.45 rows=190 width=24) (actual time=1.2..98.7 rows=196.00 loops=1)
   Workers Planned: 2
   Workers Launched: 2
   ->  Parallel Seq Scan on orders  (cost=0.00..29104.45 rows=79 width=24) (actual time=0.9..95.3 rows=65.33 loops=3)

loops=3 は、2 つのワーカーと、取りまとめ役のプロセスを合わせた 3 つで実行したという意味です。rows=65.33 は 1 つあたりの平均で、3 を掛けると全体の 196 行になります。Workers Launched が Workers Planned より少ない場合は、ワーカーの上限に達して予定どおりに並列化できていません。

pg_stat_statements のクエリを EXPLAIN にかける

pg_stat_statements で見つけた遅いクエリは、WHERE customer_id = $1 のように値が記号に置き換わっています。PostgreSQL 16 以降なら、GENERIC_PLAN を付けると、値がないまま計画を確かめられます。

EXPLAIN (GENERIC_PLAN)
SELECT id, total, created_at
FROM orders
WHERE customer_id = $1
ORDER BY created_at DESC
LIMIT 20;

値を使わない汎用の計画なので、実際の値で選ばれる計画とは違うことがあります。また ANALYZE とは同時に使えません。実際の値はログから拾うのが確実です。遅いクエリの見つけ方とログの設定は PostgreSQL で遅いクエリを見つける方法 で説明しています。

実行計画を読む順番

最後に、EXPLAIN ANALYZE の出力を読む順番をまとめます。

  1. 一番下の Execution Time で全体の時間を確かめる。
  2. actual time (の右の値) × loops が大きいノードを探す。そこが時間を使っている場所。
  3. そのノードの見積もりの rows と実際の rows を比べ、大きくずれていないか。ずれていれば統計情報を疑う。
  4. Seq Scan で Rows Removed by Filter が大きくないか。大きければインデックスを検討する。
  5. Buffers の read や temp が多くないか。Sort Method が external merge になっていないか。
  6. Nested Loop の内側で loops が大きくないか。

木の上のノードの時間には子の時間が含まれる点にも注意してください。あるノードが自分で使った時間は、自分の時間から子の時間を引いた値です。MySQL を使っている場合は MySQL の EXPLAIN の記事 をご覧ください。

この確認を続けるには

実行計画は、データの量や分布が変わると入れ替わります。インデックスを足して速くなったクエリが、数か月後に統計情報のずれで別の計画を選び、遅くなることもあります。手作業で続けるなら、pg_stat_statements の上位を定期的に確かめ、順位が上がったクエリだけを EXPLAIN ANALYZE にかけるのが現実的です。auto_explain を入れておけば、遅かったときの計画がログに残ります。

AI に任せる方法もあります。Scandock は AI がデータベースを監視するサービスで、PostgreSQL の接続文字列を登録すると、AI がテーブルの構成と実データを読んで監視する項目を決めます。注文数やジョブの滞留のような事業の数字を、固定の閾値ではなく推移や過去の経緯を踏まえて判断し、異常があれば読み取り専用のクエリで原因を調べて、根拠と対処案をつけて通知します。

参考

関連する記事