問題:再帰クエリの実行計画が短くみえる謎
『SQL緊急救命室』第7章を元に、WITH RECURSIVE句を使用したときの実行計画が短くみえる理由を解明する。
SQLのWITH RECURSIVE句を使うと、再帰的にSQLが実行されるため、実行計画に実行回数が反映されるはずである。しかし、実際の実行計画を確認すると、明らかに実行回数が少ないようにみえる。
具体例
第7章p.262の例を使って、会社の組織階層を隣接リストモデルで表したテーブル(OrgChartテーブル)から、ノードの深さを取得するクエリの実行計画を取得する。
- OrgChartテーブル
emp | boss | role |
---|---|---|
上田 | 足立 | 部長 |
加藤 | 上田 | 課長 |
大神 | 上田 | 課長 |
木島 | 江崎 | ヒラ |
江崎 | 上田 | 課長 |
猪狩 | 足立 | 部長 |
足立 | 社長 |
- クエリ
WITH RECURSIVE Traversal (emp, boss, depth) AS
(SELECT O1.emp, O1.boss, 1 AS depth /* 開始点となるクエリ */
FROM OrgChart O1
WHERE boss IS NULL
UNION ALL
SELECT O2.emp, O2.boss, (T.depth + 1) AS depth /* 再帰的に繰り返されるクエリ */
FROM OrgChart O2, Traversal T
WHERE T.emp = O2.boss)
SELECT emp, boss, depth FROM Traversal;
- クエリの実行結果
emp | boss | depth |
---|---|---|
足立 | 1 | |
上田 | 足立 | 2 |
猪狩 | 足立 | 2 |
加藤 | 上田 | 3 |
大神 | 上田 | 3 |
江崎 | 上田 | 3 |
木島 | 江崎 | 4 |
- クエリの実行計画(PostgreSQL)
QUERY PLAN
CTE Scan on traversal (cost=159.19..162.00 rows=141 width=168)
CTE traversal
-> Recursive Union (cost=0.00..159.19 rows=141 width=168)
-> Seq Scan on orgchart o1 (cost=0.00..12.90 rows=1 width=168)
Filter: (boss IS NULL)
-> Hash Join (cost=0.33..14.49 rows=14 width=168)
Hash Cond: ((o2.boss)::text = (t.emp)::text)
-> Seq Scan on orgchart o2 (cost=0.00..12.90 rows=290 width=164)
-> Hash (cost=0.20..0.20 rows=10 width=86)
-> WorkTable Scan on traversal t (cost=0.00..0.20 rows=10 width=86)
「クエリの実行結果」のdepth列は最大が4なので、「クエリ」の /* 再帰的に繰り返されるクエリ */ の部分は少なくとも3回は実行されている。そして再帰的に繰り返されるクエリでは、OrgChartのフルスキャンとJoinを行っているようにみえるから、実行計画でもSeq ScanやHash Joinは確実に3回以上実行しているはず。それなのに、「クエリの実行計画」に表れているHash Joinは1回だけで、Seq Scanの回数も明らかに少ない。なぜなのか...?
答え:実行計画は簡略化されている
調べたところ、通常の実行計画では、再帰的な実行回数や各ステップの詳細な繰り返しをすべて表示するのではなく、Recursive Unionとしてまとめて表示されているらしい。勝手に逐次ステップを全て表示するものだと思い込んでいたが、構造化されていた。これによって、実行計画が少なく見えるが、実際には再帰的に複数回実行されていることが理解できる。
詳細な実行計画を取得する
クエリの先頭に EXPLAIN ANALYZE をつけて、詳細な実行計画を取得する。
- クエリ実行計画(PostgreSQL、explain analyze)
QUERY PLAN
CTE Scan on traversal (cost=159.19..162.00 rows=141 width=168) (actual time=0.264..0.339 rows=7 loops=1)
CTE traversal
-> Recursive Union (cost=0.00..159.19 rows=141 width=168) (actual time=0.262..0.335 rows=7 loops=1)
-> Seq Scan on orgchart o1 (cost=0.00..12.90 rows=1 width=168) (actual time=0.260..0.261 rows=1 loops=1)
Filter: (boss IS NULL)
Rows Removed by Filter: 6
-> Hash Join (cost=0.33..14.49 rows=14 width=168) (actual time=0.014..0.015 rows=2 loops=4)
Hash Cond: ((o2.boss)::text = (t.emp)::text)
-> Seq Scan on orgchart o2 (cost=0.00..12.90 rows=290 width=164) (actual time=0.006..0.007 rows=7 loops=4)
-> Hash (cost=0.20..0.20 rows=10 width=86) (actual time=0.003..0.003 rows=2 loops=4)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
-> WorkTable Scan on traversal t (cost=0.00..0.20 rows=10 width=86) (actual time=0.001..0.001 rows=2 loops=4)
Planning Time: 4.603 ms
Execution Time: 0.375 ms
Hash Joinの行の一番最後を見ると、loops=4となっており、ループしていることが読み取れる。同様に、2行後のSeq Scanもloops=4であり、再帰的なクエリがちゃんと再帰的に実行されていることがわかった。
結論
EXPLAIN ANALYZEを使用することで、実行回数や各ステップの実行時間を確認できる。
見えざるものを見よ(『賭博堕天録カイジ』)