Thread: Optimizer generates bad plans.
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=10620loops=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)
(actualtime=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.00rows=42480 loops=1)
-> Nested Loop (cost=0.00..27690.93 rows=4 width=430) (actual
time=614674.00..843125.00rows=42480 loops=1)
-> Nested Loop (cost=0.00..27689.85 rows=1 width=362) (actual
time=614674.00..842368.00rows=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.00rows=6 loops=1)
Filter: tgisconstraint
-> Materialize (cost=26180.37..26180.37 rows=100564 width=350) (actual
time=83492.50..135359.33rows=3637350 loops=6)
-> Nested Loop (cost=0.00..26180.37 rows=100564 width=350) (actual
time=68978.00..481414.00rows=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)
(actualtime=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_indexon 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=811width=142) (actual time=21.20..58.60 rows=5310 loops=5)
-> Merge Join (cost=0.00..829.42
rows=811width=142) (actual time=0.00..87.00 rows=5310 loops=1)
Merge Cond: ("outer".oid =
"inner".attrelid)
-> Nested Loop
(cost=0.00..757.44rows=124 width=136) (actual time=0.00..27.00 rows=822 loops=1)
-> Index Scan using
pg_class_oid_indexon 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_indexon 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_indexon pg_attribute a (cost=0.00..59.51 rows=811 width=6) (actual time=0.00..32.00
rows=5305loops=1)
-> Seq Scan on pg_class c (cost=0.00..4.24
rows=124width=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.02rows=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=48loops=1)
-> Nested Loop (cost=0.00..45.59 rows=1 width=230) (actual
time=1.00..1.00rows=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.97rows=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.20rows=36 loops=5)
-> Nested Loop (cost=0.00..39.54 rows=7 width=162) (actual
time=1.00..1.00rows=36 loops=1)
-> Index Scan using pg_proc_proname_args_nsp_index on
pg_procp1 (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)
(actualtime=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=9width=76) (actual time=0.00..0.00 rows=15 loops=1)
-> Index Scan using
pg_index_indrelid_indexon 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_indexon 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_indexon 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_indexon 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.00rows=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=4loops=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.04rows=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)
Congratulations. That is the largest plan I have ever seen. ;-) --------------------------------------------------------------------------- Kris Jurka wrote: > 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. -- Bruce Momjian | http://candle.pha.pa.us pgman@candle.pha.pa.us | (610) 359-1001+ If your life is a hard drive, | 13 Roberts Road + Christ can be your backup. | Newtown Square, Pennsylvania19073
Well I was really hoping pg_constraint would solve all my problems, but since contrib/array is not installed by default the conkeys and confkeys columns aren't terribly useful because they can't be joined to pg_attribute. Also there is not a column to tell you the unique constraint that supports a given foreign key constraint. See my post to bugs: http://fts.postgresql.org/db/mw/msg.html?mid=1074855 Kris Jurka On Thu, 19 Sep 2002, Bruce Momjian wrote: > > Congratulations. That is the largest plan I have ever seen. ;-) > > --------------------------------------------------------------------------- > > Kris Jurka wrote: > > 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. > > -- > Bruce Momjian | http://candle.pha.pa.us > pgman@candle.pha.pa.us | (610) 359-1001 > + If your life is a hard drive, | 13 Roberts Road > + Christ can be your backup. | Newtown Square, Pennsylvania 19073 > > ---------------------------(end of broadcast)--------------------------- > TIP 2: you can get off all lists at once with the unregister command > (send "unregister YourEmailAddressHere" to majordomo@postgresql.org) >
Kris Jurka <jurka@ejurka.com> writes:
> While adding schema support to the JDBC Driver, I came across a query
> which occasionally generates some spectacularly bad plans.
Hm, does an ANALYZE help?
regards, tom lane
Maybe not nice, but there's only 32 (64 now?) of them... JOIN pg_attribute WHERE attnum IN (conkeys[1], conkeys[2], conkeys[3], ..., conkeys[32]) Great fun... On Thu, 2002-09-19 at 18:31, Kris Jurka wrote: > > Well I was really hoping pg_constraint would solve all my problems, but > since contrib/array is not installed by default the conkeys and confkeys > columns aren't terribly useful because they can't be joined to > pg_attribute. > > Also there is not a column to tell you the unique constraint that > supports a given foreign key constraint. > > See my post to bugs: > > http://fts.postgresql.org/db/mw/msg.html?mid=1074855 > > Kris Jurka > > > On Thu, 19 Sep 2002, Bruce Momjian wrote: > > > > > Congratulations. That is the largest plan I have ever seen. ;-) > > > > --------------------------------------------------------------------------- > > > > Kris Jurka wrote: > > > 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. > > > > -- > > Bruce Momjian | http://candle.pha.pa.us > > pgman@candle.pha.pa.us | (610) 359-1001 > > + If your life is a hard drive, | 13 Roberts Road > > + Christ can be your backup. | Newtown Square, Pennsylvania 19073 > > > > ---------------------------(end of broadcast)--------------------------- > > TIP 2: you can get off all lists at once with the unregister command > > (send "unregister YourEmailAddressHere" to majordomo@postgresql.org) > > > > > ---------------------------(end of broadcast)--------------------------- > TIP 3: if posting/reading through Usenet, please send an appropriate > subscribe-nomail command to majordomo@postgresql.org so that your > message can get through to the mailing list cleanly > -- Rod Taylor
Kris Jurka <jurka@ejurka.com> writes: > While adding schema support to the JDBC Driver, I came across a > query which occasionally generates some spectacularly bad plans. Interesting. The inconsistency you're seeing is a result of GEQO. I would have hoped that it would have produced a better quality plan more often, but apparently not. On my system, the regular query optimizer handily beats GEQO for this query: it produces more efficienty query plans 100% of the time and takes less time to do so. For *this* query at least, raising geqo_threshold would be a good idea, but that may not be true universally. > I thought someone might be interested in a test case for the > optimizer. Thanks, it's a useful query -- I've been meaning to take a look at GEQO for a while now... Cheers, Neil -- Neil Conway <neilc@samurai.com> || PGP Key ID: DB3C29FC
On Thu, 19 Sep 2002, Tom Lane wrote: > Kris Jurka <jurka@ejurka.com> writes: > > While adding schema support to the JDBC Driver, I came across a query > > which occasionally generates some spectacularly bad plans. > > Hm, does an ANALYZE help? > Yes, it does, but I don't understand why. The query is entirely against pg_catalog tables which have had all of three tables added to them. How can the new ANALYZE stats be significantly different than what came from the ANALYZED template1. Kris Jurka
Neil Conway <neilc@samurai.com> writes:
> Interesting. The inconsistency you're seeing is a result of GEQO. I
> would have hoped that it would have produced a better quality plan
> more often, but apparently not. On my system, the regular query
> optimizer handily beats GEQO for this query: it produces more
> efficienty query plans 100% of the time and takes less time to do so.
> For *this* query at least, raising geqo_threshold would be a good
> idea, but that may not be true universally.
The current GEQO threshold was set some time ago; since then, the
regular optimizer has been improved while the GEQO code hasn't been
touched. It might well be time to ratchet up the threshold.
Anyone care to do some additional experiments?
regards, tom lane
On Thu, 19 Sep 2002, Kris Jurka wrote: > > On Thu, 19 Sep 2002, Tom Lane wrote: > > > Kris Jurka <jurka@ejurka.com> writes: > > > While adding schema support to the JDBC Driver, I came across a query > > > which occasionally generates some spectacularly bad plans. > > > > Hm, does an ANALYZE help? > > > > Yes, it does, but I don't understand why. The query is entirely against > pg_catalog tables which have had all of three tables added to them. How > can the new ANALYZE stats be significantly different than what came from > the ANALYZED template1. > > Kris Jurka > Looking at the differences in statistics before and after the ANALYZE the only differences are in correlation. This comes from initdb around line 1046... "$PGPATH"/postgres $PGSQL_OPT template1 >/dev/null <<EOF ANALYZE; VACUUM FULL FREEZE; EOF Could this be done better in the one step VACUUM FULL FREEZE ANALYZE or ANALYZING after the VACUUM FULL? Kris Jurka
Kris Jurka <books@ejurka.com> writes:
> Looking at the differences in statistics before and after the ANALYZE the
> only differences are in correlation. This comes from initdb around line
> 1046...
> "$PGPATH"/postgres $PGSQL_OPT template1 >/dev/null <<EOF
> ANALYZE;
> VACUUM FULL FREEZE;
> EOF
> Could this be done better in the one step VACUUM FULL FREEZE ANALYZE or
> ANALYZING after the VACUUM FULL?
Hm. We can't do it like that, because that would leave the pg_statistic
rows unfrozen. I suppose we could do
VACUUM FULL;
ANALYZE;
VACUUM FREEZE;
regards, tom lane
Tom Lane wrote: > Neil Conway <neilc@samurai.com> writes: > > Interesting. The inconsistency you're seeing is a result of GEQO. I > > would have hoped that it would have produced a better quality plan > > more often, but apparently not. On my system, the regular query > > optimizer handily beats GEQO for this query: it produces more > > efficienty query plans 100% of the time and takes less time to do so. > > For *this* query at least, raising geqo_threshold would be a good > > idea, but that may not be true universally. > > The current GEQO threshold was set some time ago; since then, the > regular optimizer has been improved while the GEQO code hasn't been > touched. It might well be time to ratchet up the threshold. > > Anyone care to do some additional experiments? Added to TODO: * Check GUC geqo_threshold to see if it is still accurate -- Bruce Momjian | http://candle.pha.pa.us pgman@candle.pha.pa.us | (610) 359-1001+ If your life is a hard drive, | 13 Roberts Road + Christ can be your backup. | Newtown Square, Pennsylvania19073