Re: possible wrong query plan on pg 8.3.5,

From: zz_11(at)mail(dot)bg
To: Scott Marlowe <scott(dot)marlowe(at)gmail(dot)com>
Cc: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, pgsql-performance(at)postgresql(dot)org
Subject: Re: possible wrong query plan on pg 8.3.5,
Date: 2009-09-14 16:07:09
Message-ID: 20090914190709.xavpio9q6lcggssg@mail.bg
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Цитат от Scott Marlowe <scott(dot)marlowe(at)gmail(dot)com>:

> 2009/9/14 <zz_11(at)mail(dot)bg>:
>> Also I waited to the end of this query to gather info for explain analyze..
>> It is it:
>>
>>  explain analyze  select d.ids from a_doc d  join a_sklad s on
>> (d.ids=s.ids_doc)  join a_nomen n on (n.ids=s.ids_num)  join a_nom_gr nmgr
>> on (nmgr.ids=n.ids_grupa)  join a_gar_prod_r gr on (gr.ids_a_sklad=s.ids and
>> gr.sernum!='ok')  join a_location l on (l.ids=s.ids_sklad)  join a_klienti
>> kl on (kl.ids=d.ids_ko)  left outer join a_slujiteli sl on
>> (sl.ids=d.ids_slu_ka)  left outer join a_slujiteli slu on
>> (slu.ids=d.ids_slu_targ)  where d.op=1  AND d.date_op >= 12320 AND d.date_op
>> <= 12362 and n.num like '191%';
>>
>>             QUERY PLAN
>> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>  Nested Loop Left Join  (cost=63.64..133732.47 rows=4 width=64) (actual
>> time=616059.833..1314396.823 rows=91 loops=1)
>>   ->  Nested Loop  (cost=63.64..133699.35 rows=4 width=128) (actual
>> time=616033.205..1313991.756 rows=91 loops=1)
>>         ->  Nested Loop  (cost=63.64..133688.22 rows=4 width=192) (actual
>> time=616033.194..1313991.058 rows=91 loops=1)
>>               ->  Nested Loop Left Join  (cost=63.64...133687.10 rows=4
>> width=256) (actual time=616033.183..1313936.577 rows=91 loops=1)
>>                     ->  Nested Loop  (cost=63.64..133685.78 rows=4
>> width=320) (actual time=616033.177..1313929.258 rows=91 loops=1)
>>                           ->  Nested Loop  (cost=63.64..133646.56 rows=6
>> width=384) (actual time=616007.069..1313008.701 rows=91 loops=1)
>>                                 ->  Nested Loop  (cost=63.64..127886.54
>> rows=2833 width=192) (actual time=376.309..559763.450 rows=211357 loops=1)
>>                                       ->  Nested Loop
>>  (cost=63.64..107934.83 rows=13709 width=256) (actual
>> time=224.058..148475.499 rows=370803 loops=1)
>>                                             ->  Index Scan using i_nomen_num
>
> This nested loop looks like the big problem, although it could also be
> that it's running an index scan earlier that should be a seq scan
> given the amount the estimate is off on rows.
>
> For grins, try running your query after issuing this command:
>
> set enable_nestloop=off;
>
> and see what the run time looks like.
>
>

Hi Scott,

alter set enable_nestloop=off, it is new new plan ( and the speed is
relative good):

Hash Left Join (cost=647541.56..804574.64 rows=4 width=64) (actual
time=40535.547..40554.502 rows=91 loops=1)
Hash Cond: (d.ids_slu_targ = slu.ids)
-> Hash Join (cost=647442.94..804475.96 rows=4 width=128)
(actual time=40533.886..40552.729 rows=91 loops=1)
Hash Cond: (n.ids_grupa = nmgr.ids)
-> Hash Join (cost=647425.37..804458.34 rows=4 width=192)
(actual time=40533.354..40552.112 rows=91 loops=1)
Hash Cond: (s.ids_sklad = l.ids)
-> Hash Left Join (cost=647401.65..804434.56 rows=4
width=256) (actual time=40532.880..40551.540 rows=91 loops=1)
Hash Cond: (d.ids_slu_ka = sl.ids)
-> Hash Join (cost=647303.03..804335.91 rows=4
width=320) (actual time=40530.704..40549.279 rows=91 loops=1)
Hash Cond: (d.ids_ko = kl.ids)
-> Hash Join (cost=592217.17..749249.95
rows=6 width=384) (actual time=37874.787..37893.110 rows=91 loops=1)
Hash Cond: (gr.ids_a_sklad = s.ids)
-> Seq Scan on a_gar_prod_r gr
(cost=0.00..152866.95 rows=1110870 width=64) (actual
time=8.596..5839.771 rows=1112081 loops=1)
Filter: (sernum <> 'ok'::text)
-> Hash (cost=592216.84..592216.84
rows=27 width=448) (actual time=31275.699..31275.699 rows=193 loops=1)
-> Hash Join
(cost=37061.98..592216.84 rows=27 width=448) (actual
time=6046.588..31275.047 rows=193 loops=1)
Hash Cond: (s.ids_doc = d.ids)
-> Hash Join
(cost=52.77..555070.26 rows=13709 width=256) (actual
time=19.962..30406.478 rows=370803 loops=1)
Hash Cond:
(s.ids_num = n.ids)
-> Seq Scan on
a_sklad s (cost=0.00..534721.93 rows=5375593 width=256) (actual
time=5.867..27962.054 rows=5375690 loops=1)
-> Hash
(cost=52.47..52.47 rows=24 width=128) (actual time=0.299..0.299
rows=20 loops=1)
-> Bitmap
Heap Scan on a_nomen n (cost=4.39..52.47 rows=24 width=128) (actual
time=0.061..0.276 rows=20 loops=1)

Filter: ((num)::text ~~ '191%'::text)
->
Bitmap Index Scan on i_nomen_num (cost=0.00..4.38 rows=13 width=0)
(actual time=0.043..0.043 rows=20 loops=1)

Index Cond: (((num)::text >= '191'::text) AND ((num)::text <
'192'::text))
-> Hash
(cost=36926.74..36926.74 rows=6598 width=256) (actual
time=485.920..485.920 rows=8191 loops=1)
-> Bitmap Heap
Scan on a_doc d (cost=223.17..36926.74 rows=6598 width=256) (actual
time=55.896..477.811 rows=8191 loops=1)
Recheck
Cond: ((date_op >= 12320) AND (date_op <= 12362))
Filter: (op = 1)
-> Bitmap
Index Scan on i_doc_date_op (cost=0.00..221.52 rows=10490 width=0)
(actual time=46.639..46.639 rows=11265 loops=1)
Index
Cond: ((date_op >= 12320) AND (date_op <= 12362))
-> Hash (cost=49563.16..49563.16
rows=441816 width=64) (actual time=2655.370..2655.370 rows=441806
loops=1)
-> Seq Scan on a_klienti kl
(cost=0.00..49563.16 rows=441816 width=64) (actual
time=10.237..2334.909 rows=441806 loops=1)
-> Hash (cost=77.72..77.72 rows=1672 width=64)
(actual time=2.138..2.138 rows=1672 loops=1)
-> Seq Scan on a_slujiteli sl
(cost=0.00..77.72 rows=1672 width=64) (actual time=0.019..1.005
rows=1672 loops=1)
-> Hash (cost=19.43..19.43 rows=343 width=64)
(actual time=0.464..0.464 rows=343 loops=1)
-> Seq Scan on a_location l (cost=0.00..19.43
rows=343 width=64) (actual time=0.012..0.263 rows=343 loops=1)
-> Hash (cost=12.81..12.81 rows=381 width=64) (actual
time=0.493..0.493 rows=381 loops=1)
-> Seq Scan on a_nom_gr nmgr (cost=0.00..12.81
rows=381 width=64) (actual time=0.024..0.276 rows=381 loops=1)
-> Hash (cost=77.72..77.72 rows=1672 width=64) (actual
time=1.633..1.633 rows=1672 loops=1)
-> Seq Scan on a_slujiteli slu (cost=0.00..77.72 rows=1672
width=64) (actual time=0.004..0.674 rows=1672 loops=1)
Total runtime: 40565.832 ms

regards,
Ivan.

-------------------------------------
Powered by Mail.BG - http://mail.bg

In response to

Browse pgsql-performance by date

  From Date Subject
Next Message zz_11 2009-09-14 16:13:53 Re: possible wrong query plan on pg 8.3.5,
Previous Message Scott Marlowe 2009-09-14 15:51:39 Re: possible wrong query plan on pg 8.3.5,