PostgreSQL 7.4 runs slower than 7.3 - Mailing list pgsql-hackers

I had previously mentioned that queries run much different depending on
whether a VACUUM ANALYZE is done or just a plain ANALYZE.  At the time I
was told that that couldn't be and since I could just use the one that
worked better I didn't worry about it.  Now I have updated my database
to 7.4 and both work badly.  Here is the EXPLAIN output.  Marvin is
running 7.3.6 and romeo is running 7.4.3.  We didn't try to do an
EXPLAIN ANALYZE on romeo because it takes too long but I can assure you
that the numbers are indeed indicative of how long the query takes. 
Does anyone have an explanation?  The data in both cases is exactly the
same as is the table definitions and indexes.

******************* on marvin before ANALYZE
**********************************
cert=# explain analyze
cert-# select 'TO_TRANS (SUPRA) '::text, sum(cnt_t) as cnt_t,
sum(certrans_amount_t) as certrans_amount_t, sum(cnt_f) as cnt_f,
sum(certrans_amount_f) as certrans_amount_f from (select count(*) as
cnt_t, sum(certrans_amount) as certrans_amount_t, 0::int as cnt_f,
0::numeric as certrans_amount_f from certrans where certrans_active =
't' and certrans_date between '2004-09-12' and '2004-09-17 15:10' UNION
ALL select 0::int as cnt_t, 0::numeric as certrans_amount_t, count(*) as
cnt_f, sum(certrans_amount) as certrans_amount_f from certrans where
certrans_active = 'f' and certrans_date between '2004-09-12' and
'2004-09-17 15:10') as list;
QUERYPLAN
 
-----------------------------------------------------------------------
-----------------------------------------------------------------------
-------------------------------------------------Aggregate  (cost=9.01..9.01 rows=1 width=11) (actual
time=3172.67..3172.68 rows=1 loops=1)  ->  Subquery Scan list  (cost=4.49..8.99 rows=2 width=11) (actual
time=2626.05..3172.63 rows=2 loops=1)        ->  Append  (cost=4.49..8.99 rows=2 width=11) (actual
time=2626.04..3172.61 rows=2 loops=1)              ->  Subquery Scan "*SELECT* 1"  (cost=4.49..4.49 rows=1
width=11) (actual time=2626.04..2626.04 rows=1 loops=1)                    ->  Aggregate  (cost=4.49..4.49 rows=1
width=11)
(actual time=2626.02..2626.02 rows=1 loops=1)                          ->  Index Scan using certrans_certrans_date
on certrans  (cost=0.00..4.49 rows=1 width=11) (actual
time=0.37..1944.16 rows=329162 loops=1)                                Index Cond: ((certrans_date >=
'2004-09-12 00:00:00-04'::timestamp with time zone) AND (certrans_date
<= '2004-09-17 15:10:00-04'::timestamp with time zone))                                Filter: (certrans_active = true)
            ->  Subquery Scan "*SELECT* 2"  (cost=4.49..4.49 rows=1
 
width=11) (actual time=546.56..546.56 rows=1 loops=1)                    ->  Aggregate  (cost=4.49..4.49 rows=1
width=11)
(actual time=546.54..546.54 rows=1 loops=1)                          ->  Index Scan using certrans_certrans_date
on certrans  (cost=0.00..4.49 rows=1 width=11) (actual time=0.42..543.94
rows=1061 loops=1)                                Index Cond: ((certrans_date >=
'2004-09-12 00:00:00-04'::timestamp with time zone) AND (certrans_date
<= '2004-09-17 15:10:00-04'::timestamp with time zone))                                Filter: (certrans_active =
false)Totalruntime: 3173.07 msec
 
(14 rows)

******************* on romeo before ANALYZE
**********************************
cert=# explain analyze
cert-# select 'TO_TRANS (SUPRA) '::text, sum(cnt_t) as cnt_t,
sum(certrans_amount_t) as certrans_amount_t, sum(cnt_f) as cnt_f,
sum(certrans_amount_f) as certrans_amount_f from (select count(*) as
cnt_t, sum(certrans_amount) as certrans_amount_t, 0::int as cnt_f,
0::numeric as certrans_amount_f from certrans where certrans_active =
't' and certrans_date between '2004-09-12' and '2004-09-17 15:10' UNION
ALL select 0::int as cnt_t, 0::numeric as certrans_amount_t, count(*) as
cnt_f, sum(certrans_amount) as certrans_amount_f from certrans where
certrans_active = 'f' and certrans_date between '2004-09-12' and
'2004-09-17 15:10') as list;
QUERY
PLAN
-----------------------------------------------------------------------
-----------------------------------------------------------------------
-------------------------------------------------Aggregate  (cost=601160.96..601160.96 rows=1 width=80) (actual
time=214478.840..214478.841 rows=1 loops=1)  ->  Subquery Scan list  (cost=407872.85..601160.93 rows=2 width=80)
(actual time=7306.212..214478.553 rows=2 loops=1)        ->  Append  (cost=407872.85..601160.91 rows=2 width=10)
(actual
time=7306.198..214478.531 rows=2 loops=1)              ->  Subquery Scan "*SELECT* 1" 
(cost=407872.85..407872.86 rows=1 width=10) (actual
time=7306.195..7306.199 rows=1 loops=1)                    ->  Aggregate  (cost=407872.85..407872.85 rows=1
width=10) (actual time=7306.181..7306.182 rows=1 loops=1)                          ->  Index Scan using
certrans_certrans_date
on certrans  (cost=0.00..406617.92 rows=250986 width=10) (actual
time=16.278..6442.917 rows=329162 loops=1)                                Index Cond: ((certrans_date >=
'2004-09-12 00:00:00-04'::timestamp with time zone) AND (certrans_date
<= '2004-09-17 15:10:00-04'::timestamp with time zone))                                Filter: (certrans_active = true)
->
 
Subquery Scan "*SELECT* 2"  (cost=193288.04..193288.05 rows=1 width=10)
(actual time=207172.320..207172.323 rows=1 loops=1)                    ->  Aggregate  (cost=193288.04..193288.04
rows=1
width=10) (actual time=207172.293..207172.294 rows=1 loops=1)                          ->  Index Scan using
certrans_certrans_active
on certrans  (cost=0.00..193271.08 rows=3392 width=10) (actual
time=1.209..207169.751 rows=1061 loops=1)                                Index Cond: (certrans_active = false)
                     Filter: ((certrans_date >= '2004-09-12
 
00:00:00-04'::timestamp with time zone) AND (certrans_date <=
'2004-09-17 15:10:00-04'::timestamp with time zone))Total runtime: 214479.023 ms
(14 rows)

******************* on marvin after ANALYZE
**********************************
cert=# vacuum analyze certrans;
VACUUM
cert=# explain
cert-# select 'TO_TRANS (SUPRA) '::text, sum(cnt_t) as cnt_t,
sum(certrans_amount_t) as certrans_amount_t, sum(cnt_f) as cnt_f,
sum(certrans_amount_f) as certrans_amount_f from (select count(*) as
cnt_t, sum(certrans_amount) as certrans_amount_t, 0::int as cnt_f,
0::numeric as certrans_amount_f from certrans where certrans_active =
't' and certrans_date between '2004-09-12' and '2004-09-17 15:10' UNION
ALL select 0::int as cnt_t, 0::numeric as certrans_amount_t, count(*) as
cnt_f, sum(certrans_amount) as certrans_amount_f from certrans where
certrans_active = 'f' and certrans_date between '2004-09-12' and
'2004-09-17 15:10') as list;
QUERYPLAN
 
-----------------------------------------------------------------------
-----------------------------------------------------------------------
-------------------------------------------------Aggregate  (cost=639660.78..639660.78 rows=1 width=11)  ->  Subquery
Scanlist  (cost=424765.55..639660.76 rows=2 width=11)        ->  Append  (cost=424765.55..639660.76 rows=2 width=11)
         ->  Subquery Scan "*SELECT* 1" 
 
(cost=424765.55..424765.55 rows=1 width=11)                    ->  Aggregate  (cost=424765.55..424765.55 rows=1
width=11)                          ->  Index Scan using certrans_certrans_date
on certrans  (cost=0.00..423625.93 rows=227924 width=11)                                Index Cond: ((certrans_date >=
'2004-09-12 00:00:00-04'::timestamp with time zone) AND (certrans_date
<= '2004-09-17 15:10:00-04'::timestamp with time zone))                                Filter: (certrans_active = true)
            ->  Subquery Scan "*SELECT* 2"  
(cost=214895.21..214895.21 rows=1 width=11)                    ->  Aggregate  (cost=214895.21..214895.21 rows=1
width=11)                          ->  Index Scan using certrans_certrans_active
on certrans  (cost=0.00..214880.98 rows=2846 width=11)                                Index Cond: (certrans_active =
false)                               Filter: ((certrans_date >= '2004-09-12
 
00:00:00-04'::timestamp with time zone) AND (certrans_date <=
'2004-09-17 15:10:00-04'::timestamp with time zone))
(13 rows)

***************** to check databases reportq, eft and kelseys
*****************
psql -h db-reportq -p 5454 eft -c "select now()"; psql -h db-reportq -p
5456 kelseys -c "select now()"; psql -h db-reportq -p 5458 reportq -c
"select now()"


******************* on romeo after ANALYZE
**********************************
cert=# vacuum analyze certrans;
VACUUM
cert=# explain
cert-# select 'TO_TRANS (SUPRA) '::text, sum(cnt_t) as cnt_t,
sum(certrans_amount_t) as certrans_amount_t, sum(cnt_f) as cnt_f,
sum(certrans_amount_f) as certrans_amount_f from (select count(*) as
cnt_t, sum(certrans_amount) as certrans_amount_t, 0::int as cnt_f,
0::numeric as certrans_amount_f from certrans where certrans_active =
't' and certrans_date between '2004-09-16' and '2004-09-17 15:10' UNION
ALL select 0::int as cnt_t, 0::numeric as certrans_amount_t, count(*) as
cnt_f, sum(certrans_amount) as certrans_amount_f from certrans where
certrans_active = 'f' and certrans_date between '2004-09-16' and
'2004-09-17 15:10') as list;
QUERYPLAN
 
-----------------------------------------------------------------------
-----------------------------------------------------------------------
-------------------------------------------------Aggregate  (cost=198145.87..198145.87 rows=1 width=80)  ->  Subquery
Scanlist  (cost=116922.43..198145.84 rows=2 width=80)        ->  Append  (cost=116922.43..198145.82 rows=2 width=10)
         ->  Subquery Scan "*SELECT* 1" 
 
(cost=116922.43..116922.44 rows=1 width=10)                    ->  Aggregate  (cost=116922.43..116922.43 rows=1
width=10)                          ->  Index Scan using certrans_certrans_date
on certrans  (cost=0.00..116556.16 rows=73254 width=10)                                Index Cond: ((certrans_date >=
'2004-09-16 00:00:00-04'::timestamp with time zone) AND (certrans_date
<= '2004-09-17 15:10:00-04'::timestamp with time zone))                                Filter: (certrans_active = true)
            ->  Subquery Scan "*SELECT* 2"  (cost=81223.37..81223.38
 
rows=1 width=10)                    ->  Aggregate  (cost=81223.37..81223.37 rows=1
width=10)                          ->  Index Scan using certrans_certrans_active
on certrans  (cost=0.00..81219.41 rows=790 width=10)                                Index Cond: (certrans_active =
false)                               Filter: ((certrans_date >= '2004-09-16
 
00:00:00-04'::timestamp with time zone) AND (certrans_date <=
'2004-09-17 15:10:00-04'::timestamp with time zone))
(13 rows)

After I ran "vacuum analyze" or "analyze" things got worse on marvin and
it did not get better with pg_autovacuum help.

Is there any way to find out what's going on?

http://jobjar.givex.com/index.py?28947
2004-09-20 08:29:51.821779-04

Vladimir Yevdokimov



-- 
D'Arcy J.M. Cain <darcy@druid.net>         |  Democracy is three wolves
http://www.druid.net/darcy/                |  and a sheep voting on
+1 416 425 1212     (DoD#0082)    (eNTP)   |  what's for dinner.