pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
odd planner again, pg 9.0.8
4+ messages / 3 participants
[nested] [flat]

* odd planner again, pg 9.0.8
@ 2012-07-25 15:36 Marcus Engene <mengpg2@engene.se>
  2012-07-25 16:19 ` Re: odd planner again, pg 9.0.8 Pavel Stehule <pavel.stehule@gmail.com>
  2012-07-25 16:39 ` Re: odd planner again, pg 9.0.8 Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 2 replies; 4+ messages in thread

From: Marcus Engene @ 2012-07-25 15:36 UTC (permalink / raw)
  To: pgsql-performance

Hi,

Lacking index hints I have a bit of a problem with a slow select.

  select
      pic.objectid as pic_objectid
     ,pu.objectid as pu_objectid
     ,ppcr.preproc_me as pul_preproc_me
     ,pp.price_amount as pp_price_amount
     ,pim.aut_item_container as pim_aut_item_container
     ,COALESCE((select coalesce(pcg.name_preferred, pcg.name) from 
codec_gfx pcg where pcg.objectid = pim.aut_codec_gfx), 'unknown') as 
pcg_name
     ,COALESCE((select pis.name from item_snd pis where pis.objectid = 
pim.aut_codec_snd), 'unknown') as pis_name
--            ,(select pii2.price_arr from item_image pii2 where 
pii2.item_common = pic.objectid) as pii_price_arr
     ,pii.price_arr as pii_price_arr
  from
      (
          select
              ppcr.item_common
             ,pul.preproc_me as preproc_me
             ,pul.ul_finished_at as ul_finished_at
             ,pul.to_curator_at as to_curator_at
          from
              pic_curate ppc
             ,pic_curate_row ppcr
             ,uploading pul
          where
              ppc.user_curator = 2 AND
              ppcr.pic_curate = ppc.objectid AND
              ppcr.item_common = pul.item_common
      ) ppcr
     ,item_common pic
      left outer join item_movieclip pim on (pim.item_common = pic.objectid)
      left outer join item_soundclip pisc on (pisc.item_common = 
pic.objectid)
      left outer join item_image pii on (pii.item_common = pic.objectid)
     ,user pu
     ,pricing pp
  where
      pic.objectid = ppcr.item_common AND
      pu.objectid = pic.user AND
      pp.item_common = ppcr.item_common AND
      date_trunc ('sec', current_timestamp) BETWEEN pp.startdate and 
pp.stopdate
  order by
      ppcr.item_common

Item_common is the main table. It has some 10M rows

This query executes with...

  Nested Loop  (cost=256.16..2770236.40 rows=3028 width=523) (actual 
time=0.141..64428.788 rows=919 l
oops=1)
    ->  Nested Loop  (cost=256.16..2753774.01 rows=1066 width=515) 
(actual time=0.095..64414.614 rows=919 loops=1)
          ->  Nested Loop  (cost=256.16..2753472.18 rows=1066 width=501) 
(actual time=0.089..64411.782 rows=919 loops=1)
                ->  Merge Join  (cost=256.16..2750791.56 rows=1066 
width=477) (actual time=0.080..64318.897 rows=919 loops=1)
                      Merge Cond: (pic.objectid = ppcr.item_common)
                      ->  Merge Left Join (cost=251.72..2733545.74 
rows=10970452 width=473) (actual time=0.038..63075.673 rows=10831339 
loops=1)
                            Merge Cond: (pic.objectid = pisc.item_common)
                            ->  Merge Left Join (cost=251.72..2689409.45 
rows=10970452 width=457) (actual time=0.031..59173.547 rows=10831339 
loops=1)
                                  Merge Cond: (pic.objectid = 
pii.item_common)
                                  ->  Merge Left Join 
(cost=251.72..1844762.76 rows=10970452 width=404) (actual 
time=0.022..36763.334 rows=10831339 loops=1)
                                        Merge Cond: (pic.objectid = 
pim.item_common)
                                        ->  Index Scan using 
item_common_pkey on item_common pic  (cost=0.00..1764469.78 
rows=10970452 width=380) (actual time=0.010..20389.141 rows=10831339 
loops=1)
                                        ->  Index Scan using 
item_movieclip_pkey on item_movieclip pim  (cost=0.00..34287.89 
rows=1486673 width=28) (actual time=0.007..839.065 rows=1440175 loops=1)
                                  ->  Index Scan using item_image_pkey 
on item_image pii  (cost=0.00..707403.77 rows=8785343 width=57) (actual 
time=0.007..14972.056 rows=8701222 loops=1)
                            ->  Index Scan using item_soundclip_pkey on 
item_soundclip pisc  (cost=0.00..10690.67 rows=481559 width=20) (actual 
time=0.007..252.650 rows=478672 loops=1)
                      ->  Materialize  (cost=0.00..109.95 rows=1066 
width=4) (actual time=0.019..1.792 rows=919 loops=1)
                            ->  Nested Loop  (cost=0.00..107.28 
rows=1066 width=4) (actual time=0.018..1.429 rows=919 loops=1)
                                  Join Filter: (ppc.objectid = 
ppcr.pic_curate)
                                  ->  Index Scan using 
pic_curate_row_pkey on pic_curate_row ppcr  (cost=0.00..58.27 rows=3199 
width=8) (actual time=0.010..0.650 rows=919 loops=1)
                                  ->  Materialize (cost=0.00..1.03 
rows=1 width=4) (actual time=0.000..0.000 rows=1 loops=919)
                                        ->  Seq Scan on pic_curate ppc  
(cost=0.00..1.02 rows=1 width=4) (actual time=0.005..0.006 rows=1 loops=1)
                                              Filter: (user_curator = 2)
                ->  Index Scan using uploading_x2 on uploading pul  
(cost=0.00..2.50 rows=1 width=24) (actual time=0.100..0.100 rows=1 
loops=919)
                      Index Cond: (pul.item_common = ppcr.item_common)
          ->  Index Scan using user_pkey on user pu (cost=0.00..0.27 
rows=1 width=14) (actual time=0.002..0.002 rows=1 loops=919)
                Index Cond: (pu.objectid = pic.user)
    ->  Index Scan using pricing_x1 on pricing pp (cost=0.00..3.55 
rows=3 width=16) (actual time=0.004..0.005 rows=1 loops=919)
          Index Cond: (pp.item_common = ppcr.item_common)
          Filter: ((date_trunc('sec'::text, now()) >= pp.startdate) AND 
(date_trunc('sec'::text, now()) <= pp.stopdate))
    SubPlan 1
      ->  Index Scan using codec_gfx_pkey on codec_gfx pcg 
(cost=0.00..2.26 rows=1 width=27) (actual time=0.000..0.000 rows=0 
loops=919)
            Index Cond: (objectid = $0)
    SubPlan 2
      ->  Seq Scan on item_snd pis  (cost=0.00..1.90 rows=1 width=15) 
(actual time=0.007..0.008 rows=0 loops=919)
            Filter: (objectid = $1)
  Total runtime: 64429.074 ms
(36 rows)

...but if I comment out pii...

--    ,pii.price_arr as pii_price_arr
...
--     left outer join item_image pii on (pii.item_common = pic.objectid)

I get...

  Nested Loop  (cost=0.00..9808.71 rows=1307 width=36) (actual 
time=0.073..23.335 rows=919 loops=1)
    ->  Nested Loop  (cost=0.00..2681.09 rows=460 width=32) (actual 
time=0.037..11.289 rows=919 loops=1)
          ->  Nested Loop Left Join  (cost=0.00..2550.85 rows=460 
width=32) (actual time=0.033..9.001 rows=919 loops=1)
                ->  Nested Loop  (cost=0.00..2404.77 rows=460 width=20) 
(actual time=0.029..6.987 rows=919 loops=1)
                      ->  Nested Loop  (cost=0.00..1226.38 rows=460 
width=12) (actual time=0.025..4.065 rows=919 loops=1)
                            ->  Nested Loop  (cost=0.00..50.26 rows=460 
width=4) (actual time=0.018..1.095 rows=919 loops=1)
                                  Join Filter: (ppc.objectid = 
ppcr.pic_curate)
                                  ->  Index Scan using 
pic_curate_row_pkey on pic_curate_row ppcr  (cost=0.00..35.45 rows=919 
width=8) (actual time=0.008..0.360 rows=919 loops=1)
                                  ->  Materialize (cost=0.00..1.03 
rows=1 width=4) (actual time=0.000..0.000 rows=1 loops=919)
                                        ->  Seq Scan on pic_curate ppc  
(cost=0.00..1.02 rows=1 width=4) (actual time=0.005..0.005 rows=1 loops=1)
                                              Filter: (user_curator = 2)
                            ->  Index Scan using uploading_x2 on 
uploading pul  (cost=0.00..2.54 rows=1 width=8) (actual 
time=0.002..0.003 rows=1 loops=919)
                                  Index Cond: (pul.item_common = 
ppcr.item_common)
                      ->  Index Scan using item_common_pkey on 
item_common pic  (cost=0.00..2.55 rows=1 width=8) (actual 
time=0.002..0.003 rows=1 loops=919)
                            Index Cond: (pic.objectid = ppcr.item_common)
                ->  Index Scan using item_movieclip_pkey on 
item_movieclip pim  (cost=0.00..0.31 rows=1 width=16) (actual 
time=0.002..0.002 rows=0 loops=919)
                      Index Cond: (pim.item_common = pic.objectid)
          ->  Index Scan using user_pkey on user pu (cost=0.00..0.27 
rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=919)
                Index Cond: (pu.objectid = pic.user)
    ->  Index Scan using pricing_x1 on pricing pp (cost=0.00..3.63 
rows=3 width=12) (actual time=0.003..0.004 rows=1 loops=919)
          Index Cond: (pp.item_common = ppcr.item_common)
          Filter: ((date_trunc('sec'::text, now()) >= pp.startdate) AND 
(date_trunc('sec'::text, now()) <= pp.stopdate))
    SubPlan 1
      ->  Index Scan using codec_gfx_pkey on codec_gfx pcg 
(cost=0.00..2.26 rows=1 width=27) (actual time=0.000..0.000 rows=0 
loops=919)
            Index Cond: (objectid = $0)
    SubPlan 2
      ->  Seq Scan on item_snd pis  (cost=0.00..1.90 rows=1 width=15) 
(actual time=0.007..0.008 rows=0 loops=919)
            Filter: (objectid = $1)
  Total runtime: 23.564 ms
(29 rows)

root@pg9:/usr/local/pgsql90/data# grep -v '^#' postgresql.conf | tr '\t' 
' ' | grep -v '^ ' | sort -u
checkpoint_completion_target = 0.9 # checkpoint target duration, 0.0 - 1.0
cpu_index_tuple_cost = 0.00001  # same scale as above
datestyle = 'iso, mdy'
default_text_search_config = 'pg_catalog.english'
effective_cache_size = 32GB
lc_messages = 'en_US.UTF-8'   # locale for system error message
lc_monetary = 'en_US.UTF-8'   # locale for monetary formatting
lc_numeric = 'en_US.UTF-8'   # locale for number formatting
lc_time = 'en_US.UTF-8'    # locale for time formatting
listen_addresses = 'localhost,10.0.0.3'  # what IP address(es) to listen on;
maintenance_work_mem = 2GB  # min 1MB
max_connections = 500   # (change requires restart)
port = 5440    # (change requires restart)
random_page_cost = 1.0   # same scale as above
shared_buffers = 12GB   # min 128kB
temp_buffers = 64MB   # min 800kB
wal_buffers = 16MB   # min 32kB
work_mem = 64MB    # min 64kB

Without improvement i tried
enable_seqscan = off
cpu_index_tuple_cost = 0
seq_page_cost = 2.0

There are several selects looking similar to this in our application 
that suddenly jumped from a handfull of ms to many seconds. Can I 
workaround this by config instead of rewriting the sql to an 
inrecognizable nightmare? Preferrable I'd like to turn off full table 
scan completely (where indexes are present), but that didn't bite.

Thanks,
Marcus




^ permalink  raw  reply  [nested|flat] 4+ messages in thread

* Re: odd planner again, pg 9.0.8
  2012-07-25 15:36 odd planner again, pg 9.0.8 Marcus Engene <mengpg2@engene.se>
@ 2012-07-25 16:19 ` Pavel Stehule <pavel.stehule@gmail.com>
  1 sibling, 0 replies; 4+ messages in thread

From: Pavel Stehule @ 2012-07-25 16:19 UTC (permalink / raw)
  To: Marcus Engene <mengpg2@engene.se>; +Cc: pgsql-performance

Hello

you have too slow merge join

maybe you have bloated  item_common_pkey or item_common relations -
can you try reindex or vacuum full

you use random_page_cost = 1.0 - it can be source of bad plan

Regards

Pavel Stehule

2012/7/25 Marcus Engene <mengpg2@engene.se>:
> Hi,
>
> Lacking index hints I have a bit of a problem with a slow select.
>
>  select
>      pic.objectid as pic_objectid
>     ,pu.objectid as pu_objectid
>     ,ppcr.preproc_me as pul_preproc_me
>     ,pp.price_amount as pp_price_amount
>     ,pim.aut_item_container as pim_aut_item_container
>     ,COALESCE((select coalesce(pcg.name_preferred, pcg.name) from codec_gfx
> pcg where pcg.objectid = pim.aut_codec_gfx), 'unknown') as pcg_name
>     ,COALESCE((select pis.name from item_snd pis where pis.objectid =
> pim.aut_codec_snd), 'unknown') as pis_name
> --            ,(select pii2.price_arr from item_image pii2 where
> pii2.item_common = pic.objectid) as pii_price_arr
>     ,pii.price_arr as pii_price_arr
>  from
>      (
>          select
>              ppcr.item_common
>             ,pul.preproc_me as preproc_me
>             ,pul.ul_finished_at as ul_finished_at
>             ,pul.to_curator_at as to_curator_at
>          from
>              pic_curate ppc
>             ,pic_curate_row ppcr
>             ,uploading pul
>          where
>              ppc.user_curator = 2 AND
>              ppcr.pic_curate = ppc.objectid AND
>              ppcr.item_common = pul.item_common
>      ) ppcr
>     ,item_common pic
>      left outer join item_movieclip pim on (pim.item_common = pic.objectid)
>      left outer join item_soundclip pisc on (pisc.item_common =
> pic.objectid)
>      left outer join item_image pii on (pii.item_common = pic.objectid)
>     ,user pu
>     ,pricing pp
>  where
>      pic.objectid = ppcr.item_common AND
>      pu.objectid = pic.user AND
>      pp.item_common = ppcr.item_common AND
>      date_trunc ('sec', current_timestamp) BETWEEN pp.startdate and
> pp.stopdate
>  order by
>      ppcr.item_common
>
> Item_common is the main table. It has some 10M rows
>
> This query executes with...
>
>  Nested Loop  (cost=256.16..2770236.40 rows=3028 width=523) (actual
> time=0.141..64428.788 rows=919 l
> oops=1)
>    ->  Nested Loop  (cost=256.16..2753774.01 rows=1066 width=515) (actual
> time=0.095..64414.614 rows=919 loops=1)
>          ->  Nested Loop  (cost=256.16..2753472.18 rows=1066 width=501)
> (actual time=0.089..64411.782 rows=919 loops=1)
>                ->  Merge Join  (cost=256.16..2750791.56 rows=1066 width=477)
> (actual time=0.080..64318.897 rows=919 loops=1)
>                      Merge Cond: (pic.objectid = ppcr.item_common)
>                      ->  Merge Left Join (cost=251.72..2733545.74
> rows=10970452 width=473) (actual time=0.038..63075.673 rows=10831339
> loops=1)
>                            Merge Cond: (pic.objectid = pisc.item_common)
>                            ->  Merge Left Join (cost=251.72..2689409.45
> rows=10970452 width=457) (actual time=0.031..59173.547 rows=10831339
> loops=1)
>                                  Merge Cond: (pic.objectid =
> pii.item_common)
>                                  ->  Merge Left Join
> (cost=251.72..1844762.76 rows=10970452 width=404) (actual
> time=0.022..36763.334 rows=10831339 loops=1)
>                                        Merge Cond: (pic.objectid =
> pim.item_common)
>                                        ->  Index Scan using item_common_pkey
> on item_common pic  (cost=0.00..1764469.78 rows=10970452 width=380) (actual
> time=0.010..20389.141 rows=10831339 loops=1)
>                                        ->  Index Scan using
> item_movieclip_pkey on item_movieclip pim  (cost=0.00..34287.89 rows=1486673
> width=28) (actual time=0.007..839.065 rows=1440175 loops=1)
>                                  ->  Index Scan using item_image_pkey on
> item_image pii  (cost=0.00..707403.77 rows=8785343 width=57) (actual
> time=0.007..14972.056 rows=8701222 loops=1)
>                            ->  Index Scan using item_soundclip_pkey on
> item_soundclip pisc  (cost=0.00..10690.67 rows=481559 width=20) (actual
> time=0.007..252.650 rows=478672 loops=1)
>                      ->  Materialize  (cost=0.00..109.95 rows=1066 width=4)
> (actual time=0.019..1.792 rows=919 loops=1)
>                            ->  Nested Loop  (cost=0.00..107.28 rows=1066
> width=4) (actual time=0.018..1.429 rows=919 loops=1)
>                                  Join Filter: (ppc.objectid =
> ppcr.pic_curate)
>                                  ->  Index Scan using pic_curate_row_pkey on
> pic_curate_row ppcr  (cost=0.00..58.27 rows=3199 width=8) (actual
> time=0.010..0.650 rows=919 loops=1)
>                                  ->  Materialize (cost=0.00..1.03 rows=1
> width=4) (actual time=0.000..0.000 rows=1 loops=919)
>                                        ->  Seq Scan on pic_curate ppc
> (cost=0.00..1.02 rows=1 width=4) (actual time=0.005..0.006 rows=1 loops=1)
>                                              Filter: (user_curator = 2)
>                ->  Index Scan using uploading_x2 on uploading pul
> (cost=0.00..2.50 rows=1 width=24) (actual time=0.100..0.100 rows=1
> loops=919)
>                      Index Cond: (pul.item_common = ppcr.item_common)
>          ->  Index Scan using user_pkey on user pu (cost=0.00..0.27 rows=1
> width=14) (actual time=0.002..0.002 rows=1 loops=919)
>                Index Cond: (pu.objectid = pic.user)
>    ->  Index Scan using pricing_x1 on pricing pp (cost=0.00..3.55 rows=3
> width=16) (actual time=0.004..0.005 rows=1 loops=919)
>          Index Cond: (pp.item_common = ppcr.item_common)
>          Filter: ((date_trunc('sec'::text, now()) >= pp.startdate) AND
> (date_trunc('sec'::text, now()) <= pp.stopdate))
>    SubPlan 1
>      ->  Index Scan using codec_gfx_pkey on codec_gfx pcg (cost=0.00..2.26
> rows=1 width=27) (actual time=0.000..0.000 rows=0 loops=919)
>            Index Cond: (objectid = $0)
>    SubPlan 2
>      ->  Seq Scan on item_snd pis  (cost=0.00..1.90 rows=1 width=15) (actual
> time=0.007..0.008 rows=0 loops=919)
>            Filter: (objectid = $1)
>  Total runtime: 64429.074 ms
> (36 rows)
>
> ...but if I comment out pii...
>
> --    ,pii.price_arr as pii_price_arr
> ...
> --     left outer join item_image pii on (pii.item_common = pic.objectid)
>
> I get...
>
>  Nested Loop  (cost=0.00..9808.71 rows=1307 width=36) (actual
> time=0.073..23.335 rows=919 loops=1)
>    ->  Nested Loop  (cost=0.00..2681.09 rows=460 width=32) (actual
> time=0.037..11.289 rows=919 loops=1)
>          ->  Nested Loop Left Join  (cost=0.00..2550.85 rows=460 width=32)
> (actual time=0.033..9.001 rows=919 loops=1)
>                ->  Nested Loop  (cost=0.00..2404.77 rows=460 width=20)
> (actual time=0.029..6.987 rows=919 loops=1)
>                      ->  Nested Loop  (cost=0.00..1226.38 rows=460 width=12)
> (actual time=0.025..4.065 rows=919 loops=1)
>                            ->  Nested Loop  (cost=0.00..50.26 rows=460
> width=4) (actual time=0.018..1.095 rows=919 loops=1)
>                                  Join Filter: (ppc.objectid =
> ppcr.pic_curate)
>                                  ->  Index Scan using pic_curate_row_pkey on
> pic_curate_row ppcr  (cost=0.00..35.45 rows=919 width=8) (actual
> time=0.008..0.360 rows=919 loops=1)
>                                  ->  Materialize (cost=0.00..1.03 rows=1
> width=4) (actual time=0.000..0.000 rows=1 loops=919)
>                                        ->  Seq Scan on pic_curate ppc
> (cost=0.00..1.02 rows=1 width=4) (actual time=0.005..0.005 rows=1 loops=1)
>                                              Filter: (user_curator = 2)
>                            ->  Index Scan using uploading_x2 on uploading
> pul  (cost=0.00..2.54 rows=1 width=8) (actual time=0.002..0.003 rows=1
> loops=919)
>                                  Index Cond: (pul.item_common =
> ppcr.item_common)
>                      ->  Index Scan using item_common_pkey on item_common
> pic  (cost=0.00..2.55 rows=1 width=8) (actual time=0.002..0.003 rows=1
> loops=919)
>                            Index Cond: (pic.objectid = ppcr.item_common)
>                ->  Index Scan using item_movieclip_pkey on item_movieclip
> pim  (cost=0.00..0.31 rows=1 width=16) (actual time=0.002..0.002 rows=0
> loops=919)
>                      Index Cond: (pim.item_common = pic.objectid)
>          ->  Index Scan using user_pkey on user pu (cost=0.00..0.27 rows=1
> width=4) (actual time=0.002..0.002 rows=1 loops=919)
>                Index Cond: (pu.objectid = pic.user)
>    ->  Index Scan using pricing_x1 on pricing pp (cost=0.00..3.63 rows=3
> width=12) (actual time=0.003..0.004 rows=1 loops=919)
>          Index Cond: (pp.item_common = ppcr.item_common)
>          Filter: ((date_trunc('sec'::text, now()) >= pp.startdate) AND
> (date_trunc('sec'::text, now()) <= pp.stopdate))
>    SubPlan 1
>      ->  Index Scan using codec_gfx_pkey on codec_gfx pcg (cost=0.00..2.26
> rows=1 width=27) (actual time=0.000..0.000 rows=0 loops=919)
>            Index Cond: (objectid = $0)
>    SubPlan 2
>      ->  Seq Scan on item_snd pis  (cost=0.00..1.90 rows=1 width=15) (actual
> time=0.007..0.008 rows=0 loops=919)
>            Filter: (objectid = $1)
>  Total runtime: 23.564 ms
> (29 rows)
>
> root@pg9:/usr/local/pgsql90/data# grep -v '^#' postgresql.conf | tr '\t' ' '
> | grep -v '^ ' | sort -u
> checkpoint_completion_target = 0.9 # checkpoint target duration, 0.0 - 1.0
> cpu_index_tuple_cost = 0.00001  # same scale as above
> datestyle = 'iso, mdy'
> default_text_search_config = 'pg_catalog.english'
> effective_cache_size = 32GB
> lc_messages = 'en_US.UTF-8'   # locale for system error message
> lc_monetary = 'en_US.UTF-8'   # locale for monetary formatting
> lc_numeric = 'en_US.UTF-8'   # locale for number formatting
> lc_time = 'en_US.UTF-8'    # locale for time formatting
> listen_addresses = 'localhost,10.0.0.3'  # what IP address(es) to listen on;
> maintenance_work_mem = 2GB  # min 1MB
> max_connections = 500   # (change requires restart)
> port = 5440    # (change requires restart)
> random_page_cost = 1.0   # same scale as above
> shared_buffers = 12GB   # min 128kB
> temp_buffers = 64MB   # min 800kB
> wal_buffers = 16MB   # min 32kB
> work_mem = 64MB    # min 64kB
>
> Without improvement i tried
> enable_seqscan = off
> cpu_index_tuple_cost = 0
> seq_page_cost = 2.0
>
> There are several selects looking similar to this in our application that
> suddenly jumped from a handfull of ms to many seconds. Can I workaround this
> by config instead of rewriting the sql to an inrecognizable nightmare?
> Preferrable I'd like to turn off full table scan completely (where indexes
> are present), but that didn't bite.
>
> Thanks,
> Marcus
>
>
> --
> Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-performance



^ permalink  raw  reply  [nested|flat] 4+ messages in thread

* Re: odd planner again, pg 9.0.8
  2012-07-25 15:36 odd planner again, pg 9.0.8 Marcus Engene <mengpg2@engene.se>
@ 2012-07-25 16:39 ` Tom Lane <tgl@sss.pgh.pa.us>
  2012-07-25 18:11   ` Re: odd planner again, pg 9.0.8 Marcus Engene <mengpg2@engene.se>
  1 sibling, 1 reply; 4+ messages in thread

From: Tom Lane @ 2012-07-25 16:39 UTC (permalink / raw)
  To: Marcus Engene <mengpg2@engene.se>; +Cc: pgsql-performance

Marcus Engene <mengpg2@engene.se> writes:
> Lacking index hints I have a bit of a problem with a slow select.

I don't think you need index hints.  What you probably do need is to
increase join_collapse_limit and/or from_collapse_limit to deal with
this complex query as a whole.

> There are several selects looking similar to this in our application 
> that suddenly jumped from a handfull of ms to many seconds.

Perhaps you had those settings adjusted properly and somebody turned
them off again?

			regards, tom lane



^ permalink  raw  reply  [nested|flat] 4+ messages in thread

* Re: odd planner again, pg 9.0.8
  2012-07-25 15:36 odd planner again, pg 9.0.8 Marcus Engene <mengpg2@engene.se>
  2012-07-25 16:39 ` Re: odd planner again, pg 9.0.8 Tom Lane <tgl@sss.pgh.pa.us>
@ 2012-07-25 18:11   ` Marcus Engene <mengpg2@engene.se>
  0 siblings, 0 replies; 4+ messages in thread

From: Marcus Engene @ 2012-07-25 18:11 UTC (permalink / raw)
  To: pgsql-performance

On 7/25/12 6:39 PM, Tom Lane wrote:
> Marcus Engene <mengpg2@engene.se> writes:
>> Lacking index hints I have a bit of a problem with a slow select.
> I don't think you need index hints.  What you probably do need is to
> increase join_collapse_limit and/or from_collapse_limit to deal with
> this complex query as a whole.
>
>> There are several selects looking similar to this in our application
>> that suddenly jumped from a handfull of ms to many seconds.
> Perhaps you had those settings adjusted properly and somebody turned
> them off again?
>
> 			regards, tom lane
>
Wonderful mr Lane, now the query executes amazingly fast! I increased 
from_collapse_limit from it default 8 to 10 and it behaves as expected.

Thank you!
Marcus

  Sort  (cost=10628.68..10631.95 rows=1307 width=89) (actual 
time=26.430..26.493 rows=919 loops=1)
    Sort Key: ppcr.item_common
    Sort Method:  quicksort  Memory: 154kB
    ->  Nested Loop  (cost=0.00..10561.03 rows=1307 width=89) (actual 
time=0.093..25.612 rows=919 loops=1)
          ->  Nested Loop  (cost=0.00..3433.41 rows=460 width=85) 
(actual time=0.061..13.257 rows=919 loops=1)
                ->  Nested Loop Left Join  (cost=0.00..3134.45 rows=460 
width=85) (actual time=0.057..10.972 rows=919 loops=1)
                      ->  Nested Loop Left Join (cost=0.00..2706.99 
rows=460 width=32) (actual time=0.053..9.092 rows=919 loops=1)
                            ->  Nested Loop  (cost=0.00..2391.21 
rows=460 width=20) (actual time=0.047..6.964 rows=919 loops=1)
                                  ->  Nested Loop (cost=0.00..1212.82 
rows=460 width=12) (actual time=0.039..3.756 rows=919 loops=1)
                                        ->  Nested Loop 
(cost=0.00..36.70 rows=460 width=4) (actual time=0.028..0.436 rows=919 
loops=1)
                                              Join Filter: (ppc.objectid 
= ppcr.pic_curate)
                                              ->  Seq Scan on pic_curate 
ppc  (cost=0.00..1.02 rows=1 width=4) (actual time=0.006..0.006 rows=1 
loops=1)
                                                    Filter: 
(user_curator = 2)
                                              ->  Seq Scan on 
pic_curate_row ppcr  (cost=0.00..24.19 rows=919 width=8) (actual 
time=0.019..0.147 rows=919 loops=1)
                                        ->  Index Scan using 
uploading_x2 on uploading pul  (cost=0.00..2.54 rows=1 width=8) (actual 
time=0.003..0.003 rows=1 loops=919)
                                              Index Cond: 
(pul.item_common = ppcr.item_common)
                                  ->  Index Scan using item_common_pkey 
on item_common pic  (cost=0.00..2.55 rows=1 width=8) (actual 
time=0.003..0.003 rows=1 loops=919)
                                        Index Cond: (pic.objectid = 
ppcr.item_common)
                            ->  Index Scan using item_movieclip_pkey on 
item_movieclip pim  (cost=0.00..0.67 rows=1 width=16) (actual 
time=0.002..0.002 rows=0 loops=919)
                                  Index Cond: (pim.item_common = 
pic.objectid)
                      ->  Index Scan using item_image_pkey on item_image 
pii  (cost=0.00..0.92 rows=1 width=57) (actual time=0.002..0.002 rows=0 
loops=919)
                            Index Cond: (pii.item_common = pic.objectid)
                ->  Index Scan using user_pkey on user pu 
(cost=0.00..0.64 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=919)
                      Index Cond: (pu.objectid = pic.user)
          ->  Index Scan using pricing_x1 on pricing pp (cost=0.00..3.63 
rows=3 width=12) (actual time=0.004..0.004 rows=1 loops=919)
                Index Cond: (pp.item_common = ppcr.item_common)
                Filter: ((date_trunc('sec'::text, now()) >= 
pp.startdate) AND (date_trunc('sec'::text, now()) <= pp.stopdate))
          SubPlan 1
            ->  Index Scan using codec_gfx_pkey on codec_gfx pcg 
(cost=0.00..2.26 rows=1 width=27) (actual time=0.000..0.000 rows=0 
loops=919)
                  Index Cond: (objectid = $0)
          SubPlan 2
            ->  Seq Scan on item_snd pis  (cost=0.00..1.90 rows=1 
width=15) (actual time=0.007..0.008 rows=0 loops=919)
                  Filter: (objectid = $1)
  Total runtime: 26.795 ms
(34 rows)





^ permalink  raw  reply  [nested|flat] 4+ messages in thread


end of thread, other threads:[~2012-07-25 18:11 UTC | newest]

Thread overview: 4+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2012-07-25 15:36 odd planner again, pg 9.0.8 Marcus Engene <mengpg2@engene.se>
2012-07-25 16:19 ` Pavel Stehule <pavel.stehule@gmail.com>
2012-07-25 16:39 ` Tom Lane <tgl@sss.pgh.pa.us>
2012-07-25 18:11   ` Marcus Engene <mengpg2@engene.se>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox