Bad choice of query plan from PG 7.3.6 to PG 7.3.9 part 2 - Mailing list pgsql-performance

From Jona
Subject Bad choice of query plan from PG 7.3.6 to PG 7.3.9 part 2
Date
Msg-id 4277B7D1.6060204@oismail.com
Whole thread Raw
List pgsql-performance
Please refer to part 1 for question and query 1

Cheers
Jona
-----------------------------------------------------------------------------------------------------------------------


Query 2:
EXPLAIN ANALYZE
SELECT DISTINCT CatType_Tbl.id, CatType_Tbl.url, Category_Tbl.name,
Min(SubCatType_Tbl.id) AS subcatid
FROM (CatType_Tbl
INNER JOIN Category_Tbl ON CatType_Tbl.id = Category_Tbl.cattpid AND
Category_Tbl.enabled = true
INNER JOIN Language_Tbl ON Language_Tbl.id = Category_Tbl.langid AND
Language_Tbl.sysnm = UPPER('us') AND Language_Tbl.enabled = true
INNER JOIN SubCatType_Tbl ON CatType_Tbl.id = SubCatType_Tbl.cattpid AND
SubCatType_Tbl.enabled = true
INNER JOIN SCT2SubCatType_Tbl ON SubCatType_Tbl.id =
SCT2SubCatType_Tbl.subcattpid
INNER JOIN Price_Tbl ON SCT2SubCatType_Tbl.sctid = Price_Tbl.sctid AND
Price_Tbl.affid = 8)
WHERE CatType_Tbl.spcattpid = 1 AND CatType_Tbl.enabled = true
GROUP BY CatType_Tbl.id, CatType_Tbl.url, Category_Tbl.name
ORDER BY CatType_Tbl.id ASC

Plan on PostGre 7.3.6 on Red Hat Linux 3.2.3-39
"Unique  (cost=94.57..94.58 rows=1 width=147) (actual
time=134.85..134.86 rows=4 loops=1)"
"  ->  Sort  (cost=94.57..94.57 rows=1 width=147) (actual
time=134.85..134.85 rows=4 loops=1)"
"        Sort Key: cattype_tbl.id, cattype_tbl.url, category_tbl.name,
min(subcattype_tbl.id)"
"        ->  Aggregate  (cost=94.54..94.56 rows=1 width=147) (actual
time=127.49..134.77 rows=4 loops=1)"
"              ->  Group  (cost=94.54..94.55 rows=1 width=147) (actual
time=114.85..132.44 rows=2117 loops=1)"
"                    ->  Sort  (cost=94.54..94.55 rows=1 width=147)
(actual time=114.84..116.10 rows=2117 loops=1)"
"                          Sort Key: cattype_tbl.id, cattype_tbl.url,
category_tbl.name"
"                          ->  Nested Loop  (cost=4.54..94.53 rows=1
width=147) (actual time=0.64..52.65 rows=2117 loops=1)"
"                                ->  Nested Loop  (cost=4.54..88.51
rows=1 width=143) (actual time=0.55..18.23 rows=2838 loops=1)"
"                                      ->  Hash Join  (cost=4.54..8.93
rows=1 width=135) (actual time=0.44..1.34 rows=48 loops=1)"
"                                            Hash Cond: ("outer".langid
= "inner".id)"
"                                            ->  Hash Join
(cost=3.47..7.84 rows=1 width=131) (actual time=0.35..1.05 rows=96
loops=1)"
"                                                  Hash Cond:
("outer".cattpid = "inner".id)"
"                                                  ->  Seq Scan on
subcattype_tbl  (cost=0.00..3.98 rows=79 width=8) (actual
time=0.03..0.37 rows=156 loops=1)"
"                                                        Filter:
(enabled = true)"
"                                                  ->  Hash
(cost=3.46..3.46 rows=1 width=123) (actual time=0.30..0.30 rows=0 loops=1)"
"                                                        ->  Hash Join
(cost=1.50..3.46 rows=1 width=123) (actual time=0.12..0.29 rows=10
loops=1)"
"                                                              Hash
Cond: ("outer".cattpid = "inner".id)"
"                                                              ->  Seq
Scan on category_tbl  (cost=0.00..1.80 rows=32 width=51) (actual
time=0.03..0.13 rows=64 loops=1)"
"
Filter: (enabled = true)"
"                                                              ->  Hash
(cost=1.50..1.50 rows=1 width=72) (actual time=0.07..0.07 rows=0 loops=1)"
"                                                                    ->
Seq Scan on cattype_tbl  (cost=0.00..1.50 rows=1 width=72) (actual
time=0.04..0.06 rows=5 loops=1)"
"
Filter: ((spcattpid = 1) AND (enabled = true))"
"                                            ->  Hash  (cost=1.07..1.07
rows=1 width=4) (actual time=0.05..0.05 rows=0 loops=1)"
"                                                  ->  Seq Scan on
language_tbl  (cost=0.00..1.07 rows=1 width=4) (actual time=0.05..0.05
rows=1 loops=1)"
"                                                        Filter:
(((sysnm)::text = 'US'::text) AND (enabled = true))"
"                                      ->  Index Scan using subcat_uq on
sct2subcattype_tbl  (cost=0.00..79.26 rows=26 width=8) (actual
time=0.01..0.17 rows=59 loops=48)"
"                                            Index Cond: ("outer".id =
sct2subcattype_tbl.subcattpid)"
"                                ->  Index Scan using aff_price_uq on
price_tbl  (cost=0.00..6.01 rows=1 width=4) (actual time=0.01..0.01
rows=1 loops=2838)"
"                                      Index Cond: ((price_tbl.affid =
8) AND ("outer".sctid = price_tbl.sctid))"
"Total runtime: 135.39 msec"

Plan on PostGre 7.3.9 on Red Hat Linux 3.2.3-49
"Unique  (cost=1046.36..1046.54 rows=1 width=75) (actual
time=279.67..279.69 rows=4 loops=1)"
"  ->  Sort  (cost=1046.36..1046.40 rows=15 width=75) (actual
time=279.67..279.67 rows=4 loops=1)"
"        Sort Key: cattype_tbl.id, cattype_tbl.url, category_tbl.name,
min(subcattype_tbl.id)"
"        ->  Aggregate  (cost=1044.22..1046.07 rows=15 width=75) (actual
time=266.85..279.20 rows=4 loops=1)"
"              ->  Group  (cost=1044.22..1045.70 rows=148 width=75)
(actual time=245.28..275.37 rows=2555 loops=1)"
"                    ->  Sort  (cost=1044.22..1044.59 rows=148 width=75)
(actual time=245.27..248.35 rows=2555 loops=1)"
"                          Sort Key: cattype_tbl.id, cattype_tbl.url,
category_tbl.name"
"                          ->  Hash Join  (cost=141.39..1038.89 rows=148
width=75) (actual time=67.81..153.45 rows=2555 loops=1)"
"                                Hash Cond: ("outer".sctid =
"inner".sctid)"
------------------- Bad idea, price_tbl hold 38.5k records
"                                ->  Seq Scan on price_tbl
(cost=0.00..883.48 rows=2434 width=4) (actual time=0.86..67.25 rows=4570
loops=1)"
"                                      Filter: (affid = 8)"
"                                ->  Hash  (cost=140.62..140.62 rows=309
width=71) (actual time=66.85..66.85 rows=0 loops=1)"
"                                      ->  Hash Join  (cost=9.87..140.62
rows=309 width=71) (actual time=9.08..60.17 rows=3214 loops=1)"
"                                            Hash Cond:
("outer".subcattpid = "inner".id)"
------------------- Bad idea, sct2subcattype_tbl hold 5.5k records
"                                            ->  Seq Scan on
sct2subcattype_tbl  (cost=0.00..99.26 rows=5526 width=8) (actual
time=0.01..30.16 rows=5526 loops=1)"
"                                            ->  Hash  (cost=9.85..9.85
rows=9 width=63) (actual time=8.97..8.97 rows=0 loops=1)"
"                                                  ->  Hash Join
(cost=4.99..9.85 rows=9 width=63) (actual time=7.96..8.87 rows=48 loops=1)"
"                                                        Hash Cond:
("outer".cattpid = "inner".cattpid)"
"                                                        ->  Seq Scan on
subcattype_tbl  (cost=0.00..3.98 rows=156 width=8) (actual
time=0.02..0.50 rows=156 loops=1)"
"                                                              Filter:
(enabled = true)"
"                                                        ->  Hash
(cost=4.98..4.98 rows=2 width=55) (actual time=7.83..7.83 rows=0 loops=1)"
"                                                              ->  Hash
Join  (cost=2.58..4.98 rows=2 width=55) (actual time=7.34..7.81 rows=5
loops=1)"
"
Hash Cond: ("outer".cattpid = "inner".id)"
"                                                                    ->
Hash Join  (cost=1.08..3.36 rows=13 width=27) (actual time=0.32..0.73
rows=32 loops=1)"
"
Hash Cond: ("outer".langid = "inner".id)"
"
->  Seq Scan on category_tbl  (cost=0.00..1.80 rows=64 width=23) (actual
time=0.02..0.24 rows=64 loops=1)"
"
Filter: (enabled = true)"
"
->  Hash  (cost=1.07..1.07 rows=1 width=4) (actual time=0.10..0.10
rows=0 loops=1)"
"
->  Seq Scan on language_tbl  (cost=0.00..1.07 rows=1 width=4) (actual
time=0.09..0.10 rows=1 loops=1)"
"
Filter: (((sysnm)::text = 'US'::text) AND (enabled = true))"
"                                                                    ->
Hash  (cost=1.50..1.50 rows=5 width=28) (actual time=6.87..6.87 rows=0
loops=1)"
"
->  Seq Scan on cattype_tbl  (cost=0.00..1.50 rows=5 width=28) (actual
time=6.81..6.86 rows=5 loops=1)"
"
Filter: ((spcattpid = 1) AND (enabled = true))"
"Total runtime: 297.35 msec"
-----------------------------------------------------------------------------------------------------------------------



Query 3:
EXPLAIN ANALYZE
SELECT Count(DISTINCT SCT2SubCatType_Tbl.id) AS num
FROM (SCT2SubCatType_Tbl
INNER JOIN StatConTrans_Tbl ON SCT2SubCatType_Tbl.sctid =
StatConTrans_Tbl.id AND StatConTrans_Tbl.enabled = true
INNER JOIN SCT2Lang_Tbl ON StatConTrans_Tbl.id = SCT2Lang_Tbl.sctid
INNER JOIN Info_Tbl ON StatConTrans_Tbl.id = Info_Tbl.sctid
INNER JOIN Language_Tbl ON SCT2Lang_Tbl.langid = Language_Tbl.id AND
Info_Tbl.langid = Language_Tbl.id AND Language_Tbl.sysnm = UPPER('us')
AND Language_Tbl.enabled = true
INNER JOIN Price_Tbl ON StatConTrans_Tbl.id = Price_Tbl.sctid AND
Price_Tbl.affid = 8
INNER JOIN StatCon_Tbl ON StatConTrans_Tbl.id = StatCon_Tbl.sctid AND
StatCon_Tbl.ctpid = 1
INNER JOIN B2SC_Tbl ON StatCon_Tbl.id = B2SC_Tbl.scid AND B2SC_Tbl.bid = 80
INNER JOIN B2M_Tbl ON StatCon_Tbl.mtpid = B2M_Tbl.mtpid AND B2M_Tbl.bid
= 80
INNER JOIN SMSC2MimeType_Tbl ON StatCon_Tbl.mtpid =
SMSC2MimeType_Tbl.mtpid AND SMSC2MimeType_Tbl.smscid = 3)
WHERE SCT2SubCatType_Tbl.subcattpid = 138

Plan on PostGre 7.3.6 on Red Hat Linux 3.2.3-39
"Aggregate  (cost=495.96..495.96 rows=1 width=60) (actual
time=62.36..62.36 rows=1 loops=1)"
"  ->  Nested Loop  (cost=80.40..495.96 rows=1 width=60) (actual
time=62.30..62.30 rows=0 loops=1)"
"        Join Filter: ("outer".mtpid = "inner".mtpid)"
"        ->  Nested Loop  (cost=80.40..489.99 rows=1 width=56) (actual
time=62.30..62.30 rows=0 loops=1)"
"              ->  Nested Loop  (cost=80.40..484.07 rows=1 width=52)
(actual time=62.29..62.29 rows=0 loops=1)"
"                    ->  Nested Loop  (cost=80.40..478.05 rows=1
width=44) (actual time=62.29..62.29 rows=0 loops=1)"
"                          Join Filter: ("inner".sctid = "outer".sctid)"
"                          ->  Nested Loop  (cost=80.40..472.03 rows=1
width=40) (actual time=62.29..62.29 rows=0 loops=1)"
"                                ->  Nested Loop  (cost=80.40..315.17
rows=1 width=36) (actual time=1.01..27.62 rows=69 loops=1)"
"                                      Join Filter: ("outer".id =
"inner".sctid)"
"                                      ->  Nested Loop
(cost=80.40..309.14 rows=1 width=24) (actual time=0.91..26.31 rows=69
loops=1)"
"                                            ->  Hash Join
(cost=80.40..275.63 rows=6 width=20) (actual time=0.80..25.18 rows=69
loops=1)"
"                                                  Hash Cond:
("outer".sctid = "inner".sctid)"
"                                                  ->  Hash Join
(cost=1.08..195.80 rows=43 width=12) (actual time=0.15..21.75 rows=3947
loops=1)"
"                                                        Hash Cond:
("outer".langid = "inner".id)"
----------------- Bad idea, sct2lang_tbl has 8.6k records, but the query
is still faster than the one below where it uses its index?
"                                                        ->  Seq Scan on
sct2lang_tbl  (cost=0.00..150.79 rows=8679 width=8) (actual
time=0.03..10.70 rows=8679 loops=1)"
"                                                        ->  Hash
(cost=1.07..1.07 rows=1 width=4) (actual time=0.05..0.05 rows=0 loops=1)"
"                                                              ->  Seq
Scan on language_tbl  (cost=0.00..1.07 rows=1 width=4) (actual
time=0.04..0.05 rows=1 loops=1)"
"
Filter: (((sysnm)::text = 'US'::text) AND (enabled = true))"
"                                                  ->  Hash
(cost=79.26..79.26 rows=26 width=8) (actual time=0.39..0.39 rows=0
loops=1)"
"                                                        ->  Index Scan
using subcat_uq on sct2subcattype_tbl  (cost=0.00..79.26 rows=26
width=8) (actual time=0.10..0.33 rows=69 loops=1)"
"                                                              Index
Cond: (subcattpid = 138)"
"                                            ->  Index Scan using
statcontrans_pk on statcontrans_tbl  (cost=0.00..5.99 rows=1 width=4)
(actual time=0.01..0.01 rows=1 loops=69)"
"                                                  Index Cond:
(statcontrans_tbl.id = "outer".sctid)"
"                                                  Filter: (enabled =
true)"
"                                      ->  Index Scan using ctp_statcon
on statcon_tbl  (cost=0.00..6.01 rows=1 width=12) (actual
time=0.01..0.01 rows=1 loops=69)"
"                                            Index Cond:
((statcon_tbl.sctid = "outer".sctid) AND (statcon_tbl.ctpid = 1))"
"                                ->  Index Scan using b2sc_uq on
b2sc_tbl  (cost=0.00..156.38 rows=38 width=4) (actual time=0.50..0.50
rows=0 loops=69)"
"                                      Index Cond: ((b2sc_tbl.bid = 80)
AND ("outer".id = b2sc_tbl.scid))"
"                          ->  Index Scan using aff_price_uq on
price_tbl  (cost=0.00..6.01 rows=1 width=4) (never executed)"
"                                Index Cond: ((price_tbl.affid = 8) AND
(price_tbl.sctid = "outer".sctid))"
"                    ->  Index Scan using info_uq on info_tbl
(cost=0.00..6.00 rows=1 width=8) (never executed)"
"                          Index Cond: ((info_tbl.sctid = "outer".sctid)
AND (info_tbl.langid = "outer".langid))"
"              ->  Index Scan using b2m_uq on b2m_tbl  (cost=0.00..5.91
rows=1 width=4) (never executed)"
"                    Index Cond: ((b2m_tbl.bid = 80) AND ("outer".mtpid
= b2m_tbl.mtpid))"
"        ->  Index Scan using smsc2mimetype_uq on smsc2mimetype_tbl
(cost=0.00..5.95 rows=1 width=4) (never executed)"
"              Index Cond: ((smsc2mimetype_tbl.smscid = 3) AND
(smsc2mimetype_tbl.mtpid = "outer".mtpid))"
"Total runtime: 62.98 msec"

Plan on PostGre 7.3.9 on Red Hat Linux 3.2.3-49
"Aggregate  (cost=538.89..538.89 rows=1 width=60) (actual
time=1699.01..1699.01 rows=1 loops=1)"
"  ->  Nested Loop  (cost=1.08..538.89 rows=1 width=60) (actual
time=1698.94..1698.94 rows=0 loops=1)"
"        Join Filter: ("outer".mtpid = "inner".mtpid)"
"        ->  Nested Loop  (cost=1.08..533.21 rows=1 width=56) (actual
time=1698.94..1698.94 rows=0 loops=1)"
"              ->  Nested Loop  (cost=1.08..526.96 rows=1 width=52)
(actual time=1698.93..1698.93 rows=0 loops=1)"
"                    ->  Nested Loop  (cost=1.08..518.61 rows=1
width=44) (actual time=1698.93..1698.93 rows=0 loops=1)"
"                          ->  Nested Loop  (cost=1.08..501.22 rows=3
width=40) (actual time=6.98..466.52 rows=69 loops=1)"
"                                Join Filter: ("inner".sctid =
"outer".sctid)"
"                                ->  Nested Loop  (cost=1.08..440.65
rows=3 width=28) (actual time=6.92..331.23 rows=69 loops=1)"
"                                      Join Filter: ("inner".id =
"outer".sctid)"
"                                      ->  Hash Join  (cost=1.08..418.73
rows=4 width=24) (actual time=3.59..172.15 rows=69 loops=1)"
"                                            Hash Cond: ("outer".langid
= "inner".id)"
"                                            ->  Nested Loop
(cost=0.00..417.51 rows=19 width=20) (actual time=3.20..171.27 rows=138
loops=1)"
"                                                  ->  Nested Loop
(cost=0.00..287.97 rows=16 width=12) (actual time=3.15..5.27 rows=69
loops=1)"
"                                                        ->  Index Scan
using subcat_uq on sct2subcattype_tbl  (cost=0.00..92.56 rows=33
width=8) (actual time=3.06..3.45 rows=69 loops=1)"
"                                                              Index
Cond: (subcattpid = 138)"
"                                                        ->  Index Scan
using aff_price_uq on price_tbl  (cost=0.00..5.88 rows=1 width=4)
(actual time=0.02..0.02 rows=1 loops=69)"
"                                                              Index
Cond: ((price_tbl.affid = 8) AND (price_tbl.sctid = "outer".sctid))"
"                                                  ->  Index Scan using
sct2lang_uq on sct2lang_tbl  (cost=0.00..8.13 rows=2 width=8) (actual
time=1.10..2.39 rows=2 loops=69)"
"                                                        Index Cond:
(sct2lang_tbl.sctid = "outer".sctid)"
"                                            ->  Hash  (cost=1.07..1.07
rows=1 width=4) (actual time=0.20..0.20 rows=0 loops=1)"
"                                                  ->  Seq Scan on
language_tbl  (cost=0.00..1.07 rows=1 width=4) (actual time=0.18..0.19
rows=1 loops=1)"
"                                                        Filter:
(((sysnm)::text = 'US'::text) AND (enabled = true))"
"                                      ->  Index Scan using
statcontrans_pk on statcontrans_tbl  (cost=0.00..5.88 rows=1 width=4)
(actual time=2.29..2.30 rows=1 loops=69)"
"                                            Index Cond:
(statcontrans_tbl.id = "outer".sctid)"
"                                            Filter: (enabled = true)"
"                                ->  Index Scan using ctp_statcon on
statcon_tbl  (cost=0.00..20.40 rows=5 width=12) (actual time=1.95..1.95
rows=1 loops=69)"
"                                      Index Cond: ((statcon_tbl.sctid =
"outer".sctid) AND (statcon_tbl.ctpid = 1))"
"                          ->  Index Scan using sc2b on b2sc_tbl
(cost=0.00..5.96 rows=1 width=4) (actual time=17.86..17.86 rows=0
loops=69)"
"                                Index Cond: (("outer".id =
b2sc_tbl.scid) AND (b2sc_tbl.bid = 80))"
"                    ->  Index Scan using info_uq on info_tbl
(cost=0.00..5.93 rows=1 width=8) (never executed)"
"                          Index Cond: ((info_tbl.sctid = "outer".sctid)
AND (info_tbl.langid = "outer".langid))"
"              ->  Index Scan using b2m_uq on b2m_tbl  (cost=0.00..5.59
rows=1 width=4) (never executed)"
"                    Index Cond: ((b2m_tbl.bid = 80) AND ("outer".mtpid
= b2m_tbl.mtpid))"
"        ->  Index Scan using smsc2mimetype_uq on smsc2mimetype_tbl
(cost=0.00..5.67 rows=1 width=4) (never executed)"
"              Index Cond: ((smsc2mimetype_tbl.smscid = 3) AND
(smsc2mimetype_tbl.mtpid = "outer".mtpid))"
"Total runtime: 1710.07 msec"


pgsql-performance by date:

Previous
From: Jona
Date:
Subject: Testing list access
Next
From: Tim Terlegård
Date:
Subject: Re: batch inserts are "slow"