From: Ümit Öztosun <umit@likyabilisim.com>
To: pgsql-performance@postgresql.org
Subject: Weird performance drop after VACUUM
Date: Sat, 27 Aug 2005 01:04:19 +0300
Message-ID: <1125093859.9329.30.camel@localhost.localdomain> (raw)
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
Attachments:query.sql (text/x-sql, 1.5K) download
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.txt (text/plain, 2.8K) download
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.txt (text/plain, 2.5K) download
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
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-performance@postgresql.org
Cc: umit@likyabilisim.com
Subject: Re: Weird performance drop after VACUUM
In-Reply-To: <1125093859.9329.30.camel@localhost.localdomain>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
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