Re: vacuum analyze slows sql query

have you reindexes your tables. When I was running 7.1.4, I ran a vacuum and reindex nightly. Otherwise your index
files will keep getting bigger and bigger (this has been fixed in 7.4).

Jim

---------- Original Message -----------
From: patrick ~ <sidsrr(at)yahoo(dot)com>
To: pgsql-sql(at)postgresql(dot)org
Sent: Tue, 2 Nov 2004 18:50:31 -0800 (PST)
Subject: [SQL] vacuum analyze slows sql query

> Greetings pgsql-sql,
>
> I have a very strange problem. Our production database is a fair
> sized db, structure wise, and quite huge data wise. We have a web/php
> based UI for our customer to manage the data in our application db.
> The customer complains that the UI is sluggish accessing certain
> pages and completely times-out on certain other pages.
>
> We have a nightly "garbage collection" process that runs and purges
> any old data. After this process a 'vacuum analyze' is kicked off
> (regardless of whether or not any data was actually purged).
>
> At this point I should mention that our customer sites are running
> PostgreSQL 7.1.3; however, I am able to reproduce the issue on 7.4.2.
> If it at all matters, customer is running the db on a Dell PowerEdge
> 2550 equiped with 1gig of ram. My personal test box is a 700Mhz Intel
> with 512mb ram.
>
> I have in the past made modifications to our SQL statements to make
> queries more efficient. At this point I have given up and set out
> to strip down our database and data enough to be able to post to
> the list and ask for help from more qualified SQL experts.
>
> In the process of "stripping down" our database I noticed some very
> strange behavior which I could not explain. I started to reformulate
> my original to-be post to to the list to ask assistence in explaining
> this strange behavior I was observing. Next I noticed yet another
> strange issue with PostgreSQL.
>
> I noticed that a freshly created db with freshly inserted data (from
> a previous pg_dump) would result in quite fast results. However,
> after running 'vacuum analyze' the very same query slowed down about
> 1250x (Time: 1080688.921 ms vs Time: 864.522 ms).
>
> Following is a paste from a psql shell after a dropdb, createdb
> and populate db. The query is fast. I next run 'explain' and 'explain
> verbose' on the query. Then you see a 'vacuum analyze' followed by
> the the 'explain', 'explain verbose' and lastly the query again which
> is now extremely slow!
>
> ------ begin
> orig=# select offer_id, pkk_offer_has_pending_purch( offer_id ) from pkk_offer
> ;
> <ommiting output />
> (618 rows)
>
> Time: 864.522 ms
> orig=# explain select offer_id, pkk_offer_has_pending_purch( offer_id ) from
> pkk_offer ;
> QUERY PLAN
> -------------------------------------------------------------
> Seq Scan on pkk_offer (cost=0.00..22.50 rows=1000 width=4)
> (1 row)
>
> Time: 24.251 ms
> orig=# explain verbose select offer_id, pkk_offer_has_pending_purch( offer_id )
> from pkk_offer ;
>
> QUERY PLAN
> -------------------------------------------------------------
> {SEQSCAN
> :startup_cost 0.00
> :total_cost 22.50
> :plan_rows 1000
> :plan_width 4
> :targetlist (
> {TARGETENTRY
> :resdom
> {RESDOM
> :resno 1
> :restype 23
> :restypmod -1
> :resname offer_id
> :ressortgroupref 0
> :resorigtbl 34965071
> :resorigcol 1
> :resjunk false
> }
>
> :expr
> {VAR
> :varno 1
> :varattno 1
> :vartype 23
> :vartypmod -1
> :varlevelsup 0
> :varnoold 1
> :varoattno 1
> }
> }
>
> {TARGETENTRY
> :resdom
> {RESDOM
> :resno 2
> :restype 16
> :restypmod -1
> :resname pkk_offer_has_pending_purch
> :ressortgroupref 0
> :resorigtbl 0
> :resorigcol 0
> :resjunk false
> }
>
> :expr
> {FUNCEXPR
> :funcid 34965096
> :funcresulttype 16
> :funcretset false
> :funcformat 0
> :args (
> {VAR
> :varno 1
> :varattno 1
> :vartype 23
> :vartypmod -1
> :varlevelsup 0
> :varnoold 1
> :varoattno 1
> }
> )
> }
> }
> )
>
> :qual <>
> :lefttree <>
> :righttree <>
> :initPlan <>
> :extParam ()
>
> :allParam ()
>
> :nParamExec 0
> :scanrelid 1
> }
>
> Seq Scan on pkk_offer (cost=0.00..22.50 rows=1000 width=4)
> (78 rows)
>
> Time: 10.915 ms
> orig=# vacuum analyze ;
> VACUUM
> Time: 504701.795 ms
> orig=# explain select offer_id, pkk_offer_has_pending_purch( offer_id ) from
> pkk_offer ;
> QUERY PLAN
> ------------------------------------------------------------
> Seq Scan on pkk_offer (cost=0.00..13.72 rows=618 width=4)
> (1 row)
>
> Time: 96.903 ms
> orig=# explain verbose select offer_id, pkk_offer_has_pending_purch( offer_id )
> from pkk_offer ;
> QUERY PLAN
> ------------------------------------------------------------
> {SEQSCAN
> :startup_cost 0.00
> :total_cost 13.72
> :plan_rows 618
> :plan_width 4
> :targetlist (
> {TARGETENTRY
> :resdom
> {RESDOM
> :resno 1
> :restype 23
> :restypmod -1
> :resname offer_id
> :ressortgroupref 0
> :resorigtbl 34965071
> :resorigcol 1
> :resjunk false
> }
>
> :expr
> {VAR
> :varno 1
> :varattno 1
> :vartype 23
> :vartypmod -1
> :varlevelsup 0
> :varnoold 1
> :varoattno 1
> }
> }
>
> {TARGETENTRY
> :resdom
> {RESDOM
> :resno 2
> :restype 16
> :restypmod -1
> :resname pkk_offer_has_pending_purch
> :ressortgroupref 0
> :resorigtbl 0
> :resorigcol 0
> :resjunk false
> }
>
> :expr
> {FUNCEXPR
> :funcid 34965096
> :funcresulttype 16
> :funcretset false
> :funcformat 0
> :args (
> {VAR
> :varno 1
> :varattno 1
> :vartype 23
> :vartypmod -1
> :varlevelsup 0
> :varnoold 1
> :varoattno 1
> }
> )
> }
> }
> )
>
> :qual <>
> :lefttree <>
> :righttree <>
> :initPlan <>
> :extParam ()
>
> :allParam ()
>
> :nParamExec 0
> :scanrelid 1
> }
>
> Seq Scan on pkk_offer (cost=0.00..13.72 rows=618 width=4)
> (78 rows)
>
> Time: 2.207 ms
> orig=# select offer_id, pkk_offer_has_pending_purch( offer_id ) from pkk_offer
> ;
> <ommiting output />
> (618 rows)
>
> Time: 1080688.921 ms
> ------ end
>
> Has anyone seen something like this before? Is this standard,
> expected behavior?
>
> The .sql file that will create the tables and stored function
> follows. It has been processed by uuencode to avoid Yahoo! mail
> wrapping lines and messing things up.
>
> The data that I'm testing this db with is somewhat large; even in
> its "stripped down," "sanatized" and gzip'ed form:
>
> % ls -lG --si pkk.20041028_00.sql.gz
> -rw-r--r-- 1 patrick 17M Oct 28 18:15 pkk.20041028_00.sql.gz
>
> I can email the data file, split(1) in multiple chunks, to anyone
> interested in looking into this problem. I may be able to provide an
> http (or possibly an ftp) link for downloading it for a short period
> of time. I can't have the http link up permanently as I am limited
> bandwith wise. By far emailing would be my prefered method.
>
> Thanks for reading,
> --patrick
>
>
> __________________________________
> Do you Yahoo!?
> Check out the new Yahoo! Front Page.
> www.yahoo.com
>
> ---------------------------(end of broadcast)---------------------------
> TIP 8: explain analyze is your friend
------- End of Original Message -------