While adding schema support to the JDBC Driver, I came across a query
which occasionally generates some spectacularly bad plans. I have
attached the query and explain analyze outputs against today's cvs head
for queries that take between 9 and 845941 msec. In the JDBC Driver I
will specify a reasonable join order using explicit JOINs, but I thought
someone might be interested in a test case for the optimizer.
Kris Jurka
The query tries to determine what foreign keys exists between the
following tables.
create table people (id int4 primary key, name text);
create table policy (id int4 primary key, name text);
create table users (id int4 primary key, people_id int4,
policy_id int4,
CONSTRAINT people FOREIGN KEY (people_id) references people(id),
constraint policy FOREIGN KEY (policy_id) references policy(id));
SELECT DISTINCT n.nspname as pnspname, n2.nspname as fnspname,
c.relname as prelname, c2.relname as frelname,
t.tgconstrname, a.attnum as keyseq, ic.relname as fkeyname,
t.tgdeferrable, t.tginitdeferred, t.tgnargs,t.tgargs,
p1.proname as updaterule, p2.proname as deleterule
FROM pg_catalog.pg_namespace n,
pg_catalog.pg_namespace n2,
pg_catalog.pg_trigger t,
pg_catalog.pg_trigger t1,
pg_catalog.pg_class c,
pg_catalog.pg_class c2,
pg_catalog.pg_class ic,
pg_catalog.pg_proc p1,
pg_catalog.pg_proc p2,
pg_catalog.pg_index i,
pg_catalog.pg_attribute a
WHERE
(t.tgrelid=c.oid AND t.tgisconstraint AND t.tgconstrrelid=c2.oid
AND t.tgfoid=p1.oid and p1.proname like 'RI\_FKey\_%\_upd')
AND
(t1.tgrelid=c.oid and t1.tgisconstraint and t1.tgconstrrelid=c2.oid
AND t1.tgfoid=p2.oid and p2.proname like 'RI\_FKey\_%\_del')
AND i.indrelid=c.oid
AND i.indexrelid=ic.oid
AND ic.oid=a.attrelid
AND i.indisprimary
AND c.relnamespace = n.oid
AND c2.relnamespace=n2.oid
AND c2.relname='users'
ORDER BY prelname,keyseq
;
Unique (cost=1.06..1.10 rows=1 width=594) (actual time=845786.00..845786.00 rows=2
loops=1)
-> Sort (cost=1.06..1.07 rows=1 width=594) (actual time=845786.00..845786.00
rows=2 loops=1)
Sort Key: c.relname, a.attnum, n.nspname, n2.nspname, c2.relname,
t.tgconstrname, ic.relname, t.tgdeferrable, t.tginitdeferred, t.tgnargs, t.tgargs,
p1.proname, p2.proname
-> Merge Join (cost=1.03..1.05 rows=1 width=594) (actual time=844522.
00..845786.00 rows=2 loops=1)
Merge Cond: ("outer".tgconstrrelid = "inner".tgconstrrelid)
Join Filter: (("inner".tgfoid = "outer".oid) AND ("inner".tgrelid =
"outer".oid))
-> Nested Loop (cost=0.00..27709.41 rows=1 width=510) (actual
time=844522.00..845786.00 rows=12 loops=1)
Join Filter: (("inner".indexrelid = "outer".oid) AND
("inner".indrelid = "outer".oid))
-> Nested Loop (cost=0.00..27706.67 rows=1 width=502) (actual
time=843375.00..843954.00 rows=10620 loops=1)
Join Filter: (("inner".tgconstrrelid = "outer".oid) AND
("outer".relnamespace = "inner".oid))
-> Index Scan using pg_class_oid_index on pg_class c2
(cost=0.00..15.67 rows=1 width=72) (actual time=1.00..1.00 rows=1 loops=1)
Filter: (relname = 'users'::name)
-> Materialize (cost=27690.93..27690.93 rows=4 width=430)
(actual time=843374.00..843781.00 rows=42480 loops=1)
-> Nested Loop (cost=0.00..27690.93 rows=4
width=430) (actual time=614674.00..843125.00 rows=42480 loops=1)
-> Nested Loop (cost=0.00..27689.85 rows=1
width=362) (actual time=614674.00..842368.00 rows=10620 loops=1)
Join Filter: (("outer".tgfoid =
"inner".oid) AND ("outer".tgrelid = "inner".oid))
-> Seq Scan on pg_trigger t1
(cost=0.00..1.02 rows=1 width=12) (actual time=0.00..1.00 rows=6 loops=1)
Filter: tgisconstraint
-> Materialize (cost=26180.37..26180.37
rows=100564 width=350) (actual time=83492.50..135359.33 rows=3637350 loops=6)
-> Nested Loop
(cost=0.00..26180.37 rows=100564 width=350) (actual time=68978.00..481414.00
rows=3637350 loops=1)
Join Filter:
("inner".relnamespace = "outer".oid)
-> Seq Scan on pg_namespace
n (cost=0.00..1.04 rows=4 width=68) (actual time=0.00..0.00 rows=4 loops=1)
-> Materialize
(cost=5287.78..5287.78 rows=100564 width=282) (actual time=17273.75..110243.25
rows=3637350 loops=4)
-> Nested Loop
(cost=0.00..5287.78 rows=100564 width=282) (actual time=106.00..45489.00 rows=3637350
loops=1)
-> Nested Loop
(cost=0.00..843.50 rows=811 width=210) (actual time=106.00..557.00 rows=26550 loops=1)
-> Index
Scan using pg_proc_proname_args_nsp_index on pg_proc p2 (cost=0.00..5.97 rows=1
width=68) (actual time=0.00..1.00 rows=5 loops=1)
Index
Cond: ((proname >= 'RI'::name) AND (proname < 'RJ'::name))
Filter: (proname ~~ 'RI_FKey_%_del'::text)
->
Materialize (cost=829.42..829.42 rows=811 width=142) (actual time=21.20..58.60
rows=5310 loops=5)
->
Merge Join (cost=0.00..829.42 rows=811 width=142) (actual time=0.00..87.00 rows=5310
loops=1)
Merge Cond: ("outer".oid = "inner".attrelid)
-> Nested Loop (cost=0.00..757.44 rows=124 width=136) (actual time=0.00..27.00
rows=822 loops=1)
-> Index Scan using pg_class_oid_index on pg_class ic (cost=0.00..15.36
rows=124 width=68) (actual time=0.00..1.00 rows=137 loops=1)
-> Index Scan using pg_proc_proname_args_nsp_index on pg_proc p1
(cost=0.00..5.97 rows=1 width=68) (actual time=0.00..0.17 rows=6 loops=137)
Index Cond: ((proname >= 'RI'::name) AND (proname < 'RJ'::name))
Filter: (proname ~~ 'RI_FKey_%_upd'::text)
-> Index Scan using pg_attribute_relid_attnum_index on pg_attribute a
(cost=0.00..59.51 rows=811 width=6) (actual time=0.00..32.00 rows=5305 loops=1)
-> Seq Scan on
pg_class c (cost=0.00..4.24 rows=124 width=72) (actual time=0.01..0.96 rows=137
loops=26550)
-> Seq Scan on pg_namespace n2
(cost=0.00..1.04 rows=4 width=68) (actual time=0.01..0.02 rows=4 loops=10620)
-> Seq Scan on pg_index i (cost=0.00..2.61 rows=9 width=8)
(actual time=0.06..0.14 rows=15 loops=10620)
Filter: indisprimary
-> Sort (cost=1.03..1.03 rows=1 width=84) (actual time=0.00..0.00
rows=39 loops=1)
Sort Key: t.tgconstrrelid
-> Seq Scan on pg_trigger t (cost=0.00..1.02 rows=1 width=84)
(actual time=0.00..0.00 rows=6 loops=1)
Filter: tgisconstraint
Total runtime: 845941.00 msec
(46 rows)
Unique (cost=1.06..1.10 rows=1 width=594) (actual time=7.00..7.00 rows=2 loops=1)
-> Sort (cost=1.06..1.07 rows=1 width=594) (actual time=7.00..7.00 rows=2 loops=1)
Sort Key: c.relname, a.attnum, n.nspname, n2.nspname, c2.relname,
t.tgconstrname, ic.relname, t.tgdeferrable, t.tginitdeferred, t.tgnargs, t.tgargs,
p1.proname, p2.proname
-> Merge Join (cost=1.03..1.05 rows=1 width=594) (actual time=5.00..6.00
rows=2 loops=1)
Merge Cond: ("outer".tgconstrrelid = "inner".tgconstrrelid)
Join Filter: (("outer".indrelid = "inner".tgrelid) AND ("inner".tgfoid
= "outer".oid))
-> Nested Loop (cost=0.00..85.31 rows=1 width=510) (actual
time=4.00..6.00 rows=12 loops=1)
Join Filter: ("inner".relnamespace = "outer".oid)
-> Nested Loop (cost=0.00..63.49 rows=4 width=438) (actual
time=3.00..4.00 rows=48 loops=1)
-> Nested Loop (cost=0.00..62.41 rows=1 width=370)
(actual time=3.00..3.00 rows=12 loops=1)
Join Filter: (("inner".tgconstrrelid = "outer".oid)
AND ("outer".relnamespace = "inner".oid))
-> Index Scan using pg_class_oid_index on pg_class
c2 (cost=0.00..15.67 rows=1 width=72) (actual time=1.00..1.00 rows=1 loops=1)
Filter: (relname = 'users'::name)
-> Materialize (cost=46.67..46.67 rows=4 width=298)
(actual time=2.00..2.00 rows=48 loops=1)
-> Nested Loop (cost=0.00..46.67 rows=4
width=298) (actual time=1.00..2.00 rows=48 loops=1)
-> Nested Loop (cost=0.00..45.59 rows=1
width=230) (actual time=1.00..1.00 rows=12 loops=1)
Join Filter: ("inner".tgfoid =
"outer".oid)
-> Index Scan using
pg_proc_proname_args_nsp_index on pg_proc p2 (cost=0.00..5.97 rows=1 width=68)
(actual time=0.00..0.00 rows=5 loops=1)
Index Cond: ((proname > =
'RI'::name) AND (proname < 'RJ'::name))
Filter: (proname ~~ 'RI
_FKey_%_del'::text)
-> Materialize (cost=39.54..39.54
rows=7 width=162) (actual time=0.20..0.20 rows=36 loops=5)
-> Nested Loop
(cost=0.00..39.54 rows=7 width=162) (actual time=1.00..1.00 rows=36 loops=1)
-> Index Scan using
pg_proc_proname_args_nsp_index on pg_proc p1 (cost=0.00..5.97 rows=1 width=68)
(actual time=0.00..0.00 rows=6 loops=1)
Index Cond:
((proname >= 'RI'::name) AND (proname < 'RJ'::name))
Filter: (proname
~~ 'RI_FKey_%_upd'::text)
-> Materialize
(cost=33.50..33.50 rows=7 width=94) (actual time=0.17..0.17 rows=6 loops=6)
-> Nested Loop
(cost=0.00..33.50 rows=7 width=94) (actual time=1.00..1.00 rows=6 loops=1)
Join
Filter: ("outer".oid = "inner".attrelid)
-> Merge
Join (cost=0.00..15.13 rows=1 width=88) (actual time=0.00..0.00 rows=6 loops=1)
Merge
Cond: ("outer".indrelid = "inner".tgrelid)
->
Nested Loop (cost=0.00..58.89 rows=9 width=76) (actual time=0.00..0.00 rows=15
loops=1)
-> Index Scan using pg_index_indrelid_index on pg_index i (cost=0.00..9.80 rows=9
width=8) (actual time=0.00..0.00 rows=15 loops=1)
Filter: indisprimary
-> Index Scan using pg_class_oid_index on pg_class ic (cost=0.00..5.44 rows=1
width=68) (actual time=0.00..0.00 rows=1 loops=15)
Index Cond: ("outer".indexrelid = ic.oid)
->
Index Scan using pg_trigger_tgrelid_tgname_index on pg_trigger t1 (cost=0.00..5.27
rows=1 width=12) (actual time=0.00..0.00 rows=6 loops=1)
Filter: tgisconstraint
-> Index
Scan using pg_attribute_relid_attnum_index on pg_attribute a (cost=0.00..18.29 rows=7
width=6) (actual time=0.00..0.00 rows=1 loops=6)
Index
Cond: (a.attrelid = "outer".indexrelid)
-> Seq Scan on pg_namespace n2
(cost=0.00..1.04 rows=4 width=68) (actual time=0.00..0.00 rows=4 loops=12)
-> Seq Scan on pg_namespace n (cost=0.00..1.04 rows=4
width=68) (actual time=0.08..0.08 rows=4 loops=12)
-> Index Scan using pg_class_oid_index on pg_class c
(cost=0.00..5.44 rows=1 width=72) (actual time=0.02..0.04 rows=1 loops=48)
Index Cond: ("outer".indrelid = c.oid)
-> Sort (cost=1.03..1.03 rows=1 width=84) (actual time=0.00..0.00
rows=39 loops=1)
Sort Key: t.tgconstrrelid
-> Seq Scan on pg_trigger t (cost=0.00..1.02 rows=1 width=84)
(actual time=0.00..0.00 rows=6 loops=1)
Filter: tgisconstraint
Total runtime: 9.00 msec
(48 rows)
---------------------------(end of broadcast)---------------------------
TIP 6: Have you searched our list archives?
http://archives.postgresql.org
