Hello,

We are using PostgreSQL for our business application. Recently, during
testing of our application with large volumes of data, we faced a weird
problem. Our query performance dropped *dramatically* after "VACUUM FULL
ANALYZE" command. We have encountered a similar problem listed on
mailing list archives, but the submitter solved his problem by rewriting
his query, which is unfortunatelly very hard for us.

I am attaching two EXPLAIN ANALYZE outputs, first one is just before the
VACUUM FULL ANALYZE command and the other is the one after. Also
attached is the SQL query, which is simplified to clearify the problem.
In the example query time increases from 1.8 second to > 4.0 secons. The
difference for the complete query is much bigger, query time increases
from 7.8 seconds to > 110 seconds.

Any help is appreciated, we were unable to identify what causes the
query planner to choose a different/poor performing plan.

Notes:
Our production platform is Ubuntu Linux Hoary on i386, PostgreSQL 8.0.3,
compiled from sources. Same tests were carried on Windows XP
Professional and PostgreSQL 8.0.1 with similar results. The queries use
little IO, high CPU. The largest table involved in the sample query has
about 10000 rows. Indexes are used intensively, some tables use > 4
indexes.

Best regards,
Umit Oztosun

SELECT * FROM (
    SELECT 
        COALESCE (
            (SELECT COALESCE (sum(irskal.anamiktar), 0)  
                * (SELECT 
                    birim.fiyat2 * (SELECT kur1 
                                    FROM sis_doviz_kuru kur 
                                    WHERE birim._key_sis_doviz2 = kur._key_sis_doviz 
                                    ORDER BY tarih desc 
                                    LIMIT 1)
                    FROM scf_stokkart_birimleri birim
                    WHERE _key_scf_stokkart = stok._key
                    AND anabirim = '1'
                  )
                 FROM scf_irsaliye irs, scf_irsaliye_kalemi irskal
                 WHERE irskal._key_kalemturu = stok._key
                 AND irskal._key_scf_irsaliye = irs._key
                 AND irs.karsifirma = 'KENDI'
                 AND (irs.turu='MAI' OR irs.turu='KGI' OR irs.turu='PS' OR irs.turu='TS' OR irs.turu='KC' OR irs.turu='KCO')
                 AND ( irs._key_sis_depo_dest = '$$$$0000003l$1$$'  OR  irs._key_sis_depo_dest = '$$$$00000048$1$$'  OR  irs._key_sis_depo_dest = '$$$$0000004b$1$$'  OR  irs._key_sis_depo_dest = '$$$$0000004d$1$$' )
                 AND ((irskal._key LIKE '0000%' OR irskal._key LIKE '0101%' OR irskal._key LIKE '$$%'))
                 AND irs.tarih <= '2005-08-26'
            ), 0
        ) as arti_fiili_irs_karsifirma,
        stok.*
        FROM scf_stokkart stok
) AS _SWT WHERE (_key LIKE '00%' OR _key LIKE '01%' OR _key LIKE '$$%') ORDER BY _key desc
Before VACUUM FULL ANALYZE - Short Query
---------------------------------------
Sort  (cost=9094.31..9094.40 rows=37 width=817) (actual time=1852.799..1877.738 
rows=10000 loops=1)
  Sort Key: stok._key
  ->  Seq Scan on scf_stokkart stok  (cost=0.00..9093.34 rows=37 width=817) 
(actual time=8.670..1575.586 rows=10000 loops=1)
        Filter: (((_key)::text ~~ '00%'::text) OR ((_key)::text ~~ '01%'::text) 
OR ((_key)::text ~~ '$$%'::text))
        SubPlan
          ->  Aggregate  (cost=237.29..237.29 rows=1 width=16) (actual 
time=0.136..0.138 rows=1 loops=10000)
                InitPlan
                  ->  Index Scan using 
scf_stokkart_birimleri_key_scf_stokkart_idx on scf_stokkart_birimleri birim  
(cost=0.00..209.59 rows=1 width=58) (actual time=0.088..0.093 rows=1 
loops=10000)
                        Index Cond: ((_key_scf_stokkart)::text = ($1)::text)
                        Filter: (anabirim = '1'::bpchar)
                        SubPlan
                          ->  Limit  (cost=9.31..9.31 rows=1 width=17) (actual 
time=0.046..0.048 rows=1 loops=10000)
                                ->  Sort  (cost=9.31..9.31 rows=2 width=17) 
(actual time=0.041..0.041 rows=1 loops=10000)
                                      Sort Key: tarih
                                      ->  Index Scan using 
sis_doviz_kuru_key_sis_doviz_idx on sis_doviz_kuru kur  (cost=0.00..9.30 rows=2 
width=17) (actual time=0.018..0.029 rows=2 loops=10000)
                                            Index Cond: (($0)::text = 
(_key_sis_doviz)::text)
                ->  Nested Loop  (cost=0.00..27.69 rows=1 width=16) (actual 
time=0.033..0.033 rows=0 loops=10000)
                      ->  Index Scan using 
scf_irsaliye_kalemi_key_kalemturu_idx on scf_irsaliye_kalemi irskal  
(cost=0.00..21.75 rows=1 width=58) (actual time=0.017..0.020 rows=0 loops=10000)
                            Index Cond: ((_key_kalemturu)::text = ($1)::text)
                            Filter: (((_key)::text ~~ '0000%'::text) OR 
((_key)::text ~~ '0101%'::text) OR ((_key)::text ~~ '$$%'::text))
                      ->  Index Scan using scf_irsaliye_pkey on scf_irsaliye 
irs  (cost=0.00..5.94 rows=1 width=42) (actual time=0.021..0.021 rows=0 
loops=3000)
                            Index Cond: (("outer"._key_scf_irsaliye)::text = 
(irs._key)::text)
                            Filter: (((karsifirma)::text = 'KENDI'::text) AND 
(((turu)::text = 'MAI'::text) OR ((turu)::text = 'KGI'::text) OR ((turu)::text 
= 'PS'::text) OR ((turu)::text = 'TS'::text) OR ((turu)::text = 'KC'::text) OR 
((turu)::text = 'KCO'::text)) AND (((_key_sis_depo_dest)::text = 
'$$$$0000003l$1$$'::text) OR ((_key_sis_depo_dest)::text = 
'$$$$00000048$1$$'::text) OR ((_key_sis_depo_dest)::text = 
'$$$$0000004b$1$$'::text) OR ((_key_sis_depo_dest)::text = 
'$$$$0000004d$1$$'::text)) AND (tarih <= '2005-08-26'::date))
Total runtime: 1899.533 ms
After VACUUM FULL ANALYZE - Short Query
---------------------------------------
Index Scan Backward using scf_stokkart_pkey on scf_stokkart stok  
(cost=0.00..392045.63 rows=9998 width=166) (actual time=0.661..4431.568 
rows=10000 loops=1)
  Filter: (((_key)::text ~~ '00%'::text) OR ((_key)::text ~~ '01%'::text) OR 
((_key)::text ~~ '$$%'::text))
  SubPlan
    ->  Aggregate  (cost=39.16..39.16 rows=1 width=10) (actual 
time=0.416..0.418 rows=1 loops=10000)
          InitPlan
            ->  Index Scan using scf_stokkart_birimleri_key_scf_stokkart_idx on 
scf_stokkart_birimleri birim  (cost=0.00..5.25 rows=2 width=28) (actual 
time=0.101..0.105 rows=1 loops=10000)
                  Index Cond: ((_key_scf_stokkart)::text = ($1)::text)
                  Filter: (anabirim = '1'::bpchar)
                  SubPlan
                    ->  Limit  (cost=1.08..1.09 rows=1 width=15) (actual 
time=0.048..0.050 rows=1 loops=10000)
                          ->  Sort  (cost=1.08..1.09 rows=2 width=15) (actual 
time=0.043..0.043 rows=1 loops=10000)
                                Sort Key: tarih
                                ->  Seq Scan on sis_doviz_kuru kur  
(cost=0.00..1.07 rows=2 width=15) (actual time=0.009..0.026 rows=2 loops=10000)
                                      Filter: (($0)::text = 
(_key_sis_doviz)::text)
          ->  Nested Loop  (cost=0.00..33.90 rows=1 width=10) (actual 
time=0.295..0.295 rows=0 loops=10000)
                ->  Seq Scan on scf_irsaliye irs  (cost=0.00..30.00 rows=1 
width=20) (actual time=0.290..0.290 rows=0 loops=10000)
                      Filter: (((karsifirma)::text = 'KENDI'::text) AND 
(((turu)::text = 'MAI'::text) OR ((turu)::text = 'KGI'::text) OR ((turu)::text 
= 'PS'::text) OR ((turu)::text = 'TS'::text) OR ((turu)::text = 'KC'::text) OR 
((turu)::text = 'KCO'::text)) AND (((_key_sis_depo_dest)::text = 
'$$$$0000003l$1$$'::text) OR ((_key_sis_depo_dest)::text = 
'$$$$00000048$1$$'::text) OR ((_key_sis_depo_dest)::text = 
'$$$$0000004b$1$$'::text) OR ((_key_sis_depo_dest)::text = 
'$$$$0000004d$1$$'::text)) AND (tarih <= '2005-08-26'::date))
                ->  Index Scan using scf_irsaliye_kalemi_key_scf_irsaliye_idx 
on scf_irsaliye_kalemi irskal  (cost=0.00..3.89 rows=1 width=30) (never 
executed)
                      Index Cond: ((irskal._key_scf_irsaliye)::text = 
("outer"._key)::text)
                      Filter: (((_key_kalemturu)::text = ($1)::text) AND 
(((_key)::text ~~ '0000%'::text) OR ((_key)::text ~~ '0101%'::text) OR 
((_key)::text ~~ '$$%'::text)))
Total runtime: 4456.895 ms
---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
       subscribe-nomail command to [EMAIL PROTECTED] so that your
       message can get through to the mailing list cleanly

Reply via email to