0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

【DB用語の歯がゆさ 第7回】実行計画 ― EXPLAINの出力、どこを見る?

0
Posted at

株式会社Good Labでエンジニアをしている コータロー です。
日々、Java・SQL・Gitなどの技術情報や、新人エンジニア向けの学習ノウハウ、
AI活用についての情報を発信しています。

Good Labについて気になった方は、コーポレートサイトもぜひご覧ください。
コーポレートサイト

このシリーズについて

「知ってはいる。けど、人に説明しろと言われると詰まる」——そんな歯がゆいDB用語を、1記事1用語・図解中心で解消していくシリーズです。

前回の宿題

第6回では EXPLAIN の出力を何度も貼りました。Seq ScanIndex Scan かは見分けられたと思います。でも、こういう部分は素通りしていたはずです。

Index Scan using idx_status on users  (cost=0.42..30.83 rows=517 width=62)
  • cost=0.42..30.832つの数字は何? 秒?
  • rows=517 は何の数字? 実際は500件だったのに、なぜ517?
  • Bitmap Heap Scan って結局どういう動き?

今回はここを片付けます。実測はすべて PostgreSQL 16.14(Docker postgres:16 です。

そもそも実行計画とは何か

大前提として、SQLは「どう取るか」を書きません。

SELECT * FROM users WHERE status = 'banned';

これは「banned な人が欲しい」としか言っていません。インデックスを使うのか、全部読むのか、どのテーブルから先に読むのか——手順は一切書かれていない。SQLがこういう「宣言型」の言語だからです。

では誰が決めるのか。プランナ(オプティマイザ) です。

EXPLAIN は、このプランナの決定を見せてもらうコマンドです。そして図のとおり、プランナの判断材料は統計情報。ここが後半の伏線になります。

読み順:内側から外側へ

出力は平坦なログではなくツリーです。JOINを含む実測出力を見ます。

EXPLAIN ANALYZE
SELECT u.name, o.amount FROM users u JOIN orders o ON o.user_id = u.id
 WHERE u.status = 'banned';
Nested Loop  (cost=0.71..1573.15 rows=321 width=13) (actual time=0.039..2.928 rows=300 loops=1)
  ->  Index Scan using idx_users_status on users u  (cost=0.29..12.32 rows=107 width=13) (actual time=0.017..0.570 rows=100 loops=1)
        Index Cond: (status = 'banned'::text)
  ->  Index Scan using idx_orders_user on orders o  (cost=0.42..14.56 rows=3 width=8) (actual time=0.014..0.022 rows=3 loops=100)
        Index Cond: (user_id = u.id)
Planning Time: 0.938 ms
Execution Time: 2.988 ms

-> とインデントが階層を表します。実行は内側(下・深い方)から始まり、結果が外側(上)へ渡っていきます。

読むときは一番下から。上から読むと「Nested Loopって何だ」で止まりますが、下から読めば「usersを引いて、ordersを引いて、繋げる」と素直に追えます。

ここで loops=100 に注目してください。内側のIndex Scanは100回実行されたという意味です。外側が100行返したので、その1行ごとに内側が動いた。Nested Loopの動作がそのまま数字に出ています。

なお内側の rows=3 は「3行しか返っていない」という意味ではありません。loops が2以上のとき、actual 側の rows と時間は1回あたりの平均値です。つまり3行 × 100回 = 300行で、一番上の rows=300 と一致します。数字が合わないと感じたら × loops を疑う、と覚えておくと迷いません。

数字の意味

1行を分解します。EXPLAIN だけの場合と、EXPLAIN ANALYZE の場合で情報量が違います。

Index Scan ...  (cost=0.29..12.32 rows=107 width=26) (actual time=0.027..0.282 rows=100 loops=1)
                 └────── プランナの推定 ──────┘ └────────── 実際の測定値 ──────────┘
表記 意味
cost=0.29..12.32 推定コスト。左=最初の1行が出るまで、右=全部出し終わるまで
rows=107 推定行数。プランナが「たぶんこれくらい返る」と考えた数
width=26 1行あたりの推定バイト数
actual time=0.027..0.282 実測時間(ミリ秒)。左=1行目まで、右=完了まで
rows=100(actual側) 実際に返った行数loops が2以上なら1回あたりの平均
loops=1 このノードが実行された回数。2以上のときは上の actual timerows が1回あたりの平均値になるので、総数は × loops で求める

いちばん誤解されるのが cost です。単位は秒でもミリ秒でもありません。 「ディスクを1ページ順に読む処理」を1.0とした相対値で、プラン同士を比較するための内部的な点数です。だから cost=12.32 を見て「12秒かかる」と読むのは誤りです。

EXPLAIN は実行しません(計画を立てるだけ)。EXPLAIN ANALYZE本当にクエリを実行しますUPDATEDELETE に付けると実際にデータが変わるので、実務ではトランザクションで囲んでロールバックするのが安全です。

どこを見る? 答えは「推定と実測のズレ」

ここが本題です。実行計画を見るとき、最初に見るべきは実行時間ではありません。

rows の推定値と実測値が、大きくズレていないか。

なぜか。プランナは統計情報をもとに手順を決めているので、推定が外れているなら、その判断は間違った前提の上に成り立っているからです。

実測:統計が古いとどうなるか

50万行のテーブルを作り、ANALYZE を実行しないまま問い合わせます(自動統計取得は無効にして検証)。

CREATE TABLE big (id int, category text) WITH (autovacuum_enabled = false);
CREATE INDEX idx_big_cat ON big(category);
INSERT INTO big SELECT g, CASE WHEN g%10000=0 THEN 'rare' ELSE 'common' END
  FROM generate_series(1,500000) g;

EXPLAIN ANALYZE SELECT * FROM big WHERE category = 'common';
Bitmap Heap Scan on big  (cost=21.72..2541.14 rows=1716 width=36) (actual time=10.570..59.677 rows=499950 loops=1)
  Recheck Cond: (category = 'common'::text)
  Heap Blocks: exact=2703
  ->  Bitmap Index Scan on idx_big_cat  (cost=0.00..21.29 rows=1716 width=0) (actual time=10.296..10.296 rows=499950 loops=1)
        Index Cond: (category = 'common'::text)
Execution Time: 71.857 ms

推定 rows=1716 に対し、実測 rows=499950。約291倍のズレです。

プランナは「1716行しか返らない」と信じたので、インデックス経由で拾う計画(Bitmap Scan)を選びました。実際は50万行――ほぼ全部です。統計を取り直します。

ANALYZE big;
EXPLAIN ANALYZE SELECT * FROM big WHERE category = 'common';
Seq Scan on big  (cost=0.00..8953.00 rows=499983 width=10) (actual time=0.011..56.891 rows=499950 loops=1)
  Filter: (category = 'common'::text)
  Rows Removed by Filter: 50
Execution Time: 69.926 ms

推定 rows=499983 と実測 rows=499950 がほぼ一致し、選ばれる計画がSeq Scanに変わりました(第6回で見たとおり、大半がヒットするならこちらが正解)。

正直に書くと、この例では実行時間そのものはほとんど変わっていません(71.857 ms → 69.926 ms)。それでもこの乖離は危険信号です。テーブル1つの単純な検索なら選択肢が少なく傷は浅いですが、JOINが増えるほど、間違った行数推定は「どのテーブルから読むか」「どの結合方式を使うか」の判断を連鎖的に狂わせます。だから乖離そのものを異常として扱います。

前回の宿題を回収:ノードの意味

第6回で登場した3つのスキャン方法です。

ノード 動き 向いている場面
Seq Scan 表を先頭から全部読む 大半の行がヒットする
Index Scan インデックスを辿り、都度その行を取りに行く ごく少数がヒットする
Bitmap Index Scan + Bitmap Heap Scan まず該当行の位置をビットマップに集め、そのあとまとめて表を読む その中間

Bitmap Scanが2行ペアで出てくるのはこのためです。Bitmap Index Scan で位置を集め、Bitmap Heap Scan で実際の行を読む。インデックスの拾い読みと全表走査の中間にある方式だと理解しておけば十分です。

なお結合方式にも Nested Loop / Hash Join / Merge Join の3種類があります(今回の出力にも Nested Loop が出ていました)。それぞれ得意な状況が違いますが、まずは名前と「3種類ある」ことだけ押さえておけば読めます。

エンジン差の注記:MySQLの EXPLAIN は表形式で、typekey の列を見る形です(第6回で使ったのがこれ)。MySQL 8.0.18以降は EXPLAIN ANALYZE が使え、こちらはPostgreSQLに近いツリー形式で実測値も出ます。

まとめ:1行で説明するなら

「SQLは『何が欲しいか』しか書かないので、『どう取るか』はプランナが統計情報をもとに決めます。EXPLAIN はその決定の開示で、出力はツリーなので下から上へ読みます。cost は秒ではなく比較用の相対値、rows は推定行数。まず見るべきは推定 rows と実測 rows の乖離で、桁違いにズレていたら統計が古いサイン。ANALYZE で直ります」

EXPLAIN を開いていきなり実行時間を探すのではなく、「プランナの予想は当たっていたか」から見る。これが実行計画の読み方の入口です。

もっと深く知りたい方へ

インデックス設計の観点から EXPLAIN を読み解く記事も書いています。B-treeの仕組みや複合インデックスの列順を、実行計画と結びつけて理解したい方はこちらへ。

【新人向け】インデックス設計の基本:B-treeの仕組み・複合インデックス・カバリングインデックスをEXPLAINで読み解く(PostgreSQL 17)

次回

実行計画が読めるようになると、次に気になるのが「そもそもクエリが何回飛んでいるか」です。1回のはずが1000回飛んでいる——そんな状態があります。

第8回:N+1問題 ——「なぜ『1回』で済まないのか」を図解します。

(シリーズ全11回の予定は第1回に掲載しています)

参考


@kotaro_ai_lab
AI活用や開発効率化について発信しています。フォローお気軽にどうぞ!

0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?