Thread: 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_rows1000 :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
:varoattno1 } } {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
onpkk_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_rows618 :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
:varoattno1 } } {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
onpkk_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
begin 644 pkk_db.sql
M+RHJ"B`J("1)9#H@)`H@*@H@*B!#;W!Y<FEG:'0@*&,I(#(P,#0@<&%T<FEC
M:R!K97-H:7-H:6%N"B`J"B`J(%1H:7,@:7,@82`B;6EM:6-E9"(@9&%T86)A
M<V4@=&\@<F5P;&EC871E(&$@<VQO=R!344P@=VET:&]U=`H@*B!D:79A=6QG
M:6YG('1O;R!M=6-H(&%B;W5T('1H92!I;G1E<FYA;"!D871A(&]F('1H92!O
M<FEG:6YA;`H@*B!D871A8F%S92!I;B!P<F]D=6-T:6]N('-Y<W1E;7,N"B`J
M+PH*+RHJ"B`J($1R;W`@=&%B;&5S(&%N9"!D871A8F%S92!E;&5M96YT<R!F
M:7)S="`N+BX*("HO"F1R;W`@9G5N8W1I;VX@<&MK7V]F9F5R7VAA<U]P96YD
M:6YG7W!U<F-H*"!I;G1E9V5R("D@.PID<F]P(&9U;F-T:6]N('!K:U]O9F9E
M<E]H87-?<&5N9&EN9U]P=7)C:#(H(&EN=&5G97(@*2`["F1R;W`@=&%B;&4@
M<&MK7V)I;&QI;F<@.PID<F]P('1A8FQE('!K:U]P=7)C:&%S92`["F1R;W`@
M=&%B;&4@<&MK7V]F9F5R(#L*"B\J*@H@*B!#<F5A=&4@=&%B;&5S(&%N9"!O
M=&AE<B!D871A8F%S92!E;&5M96YT<R`N+BX*("HO"F-R96%T92!T86)L90IP
M:VM?;V9F97(*("`@("@*("`@(&]F9F5R7VED("`@("`@("!I;G1E9V5R("`@
M("!P<FEM87)Y(&ME>2P*("`@(&1E<V-R:7!T:6]N("`@("!T97AT"B`@("`I
M(#L*"F-R96%T92!T86)L90IP:VM?<'5R8VAA<V4*("`@("@*("`@('!U<F-H
M87-E7VED("`@("!I;G1E9V5R("`@("!N;W0@;G5L;"P*("`@(&-L:65N=%]I
M9"`@("`@("!V87)C:&%R*#(P*2!N;W0@;G5L;"P*("`@(&]F9F5R7VED("`@
M("`@("!I;G1E9V5R("`@("!N;W0@;G5L;"P@+2T@9F]R96EG;B!K97D*("`@
M(&5X<&ER95]T:6UE("`@("!T:6UE<W1A;7`@=VET:&]U="!T:6UE('IO;F4L
M"B`@("!C86YC96Q?9&%T92`@("`@=&EM97-T86UP('=I=&AO=70@=&EM92!Z
M;VYE+`H@("`@<&5N9&EN9R`@("`@("`@(&)O;VQE86XL"@H@("`@<')I;6%R
M>2!K97DH('!U<F-H87-E7VED+"!C;&EE;G1?:60@*2P*"B`@("!C;VYS=')A
M:6YT(&9K7W!U<E]O9F9E<E]I9`H@("`@("`@(&9O<F5I9VX@:V5Y("@@;V9F
M97)?:60@*0H@("`@("`@("`@("!R969E<F5N8V5S('!K:U]O9F9E<B@@;V9F
M97)?:60@*0H@("`@*2`["F-R96%T92!I;F1E>"!P=7)?;V9F97)?:61?:61X
M(&]N('!K:U]P=7)C:&%S92@@;V9F97)?:60@*3L*8W)E871E(&EN9&5X('!U
M<E]E>'!I<F5?=&EM95]I9'@@;VX@<&MK7W!U<F-H87-E*"!E>'!I<F5?=&EM
M92`I.PIC<F5A=&4@:6YD97@@<'5R7W!E;F1I;F=?:61X(&]N('!K:U]P=7)C
M:&%S92@@<&5N9&EN9R`I.PH*8W)E871E('1A8FQE"G!K:U]B:6QL:6YG"B`@
M("`H"B`@("!P=7)C:&%S95]I9"`@("`@:6YT96=E<B`@("`@;F]T(&YU;&PL
M("TM(&9O<F5I9VX@:V5Y"B`@("!C;&EE;G1?:60@("`@("`@=F%R8VAA<B@R
M,"D@;F]T(&YU;&PL("TM(&1I='1O"B`@("!P96YD:6YG("`@("`@("`@8F]O
M;&5A;BP*"B`@("!C;VYS=')A:6YT(&9K7V)I;%]P=7)?:60*("`@("`@("!F
M;W)E:6=N(&ME>2`H('!U<F-H87-E7VED+"!C;&EE;G1?:60@*0H@("`@("`@
M("`@("!R969E<F5N8V5S('!K:U]P=7)C:&%S92@@<'5R8VAA<V5?:60L(&-L
M:65N=%]I9"`I"B`@("`I(#L*8W)E871E(&EN9&5X(&)I;%]P96YD:6YG7VED
M>"!O;B!P:VM?8FEL;&EN9R@@<&5N9&EN9R`I.PH*"B\J*@H@*B!,971S(&-R
M96%T92!O=7(@9G5N8W1I;VYS("XN+@H@*B\*+RHJ"B`J(%!U<F-H87-E(&ES
M('!E;F1I;F<@:68@86YY(&]F('1H92!F;VQL;W=I;F<@8V]N9&ET:6]N<R!H
M;VQD('1R=64Z"B`J("!A+B!P96YD:6YG(&9I96QD(&ES('-E="!T;R!T<G5E
M("U/4BT*("H@(&(N(&-A8VYE;%]D871E(&ES($Y53$P@*&DN92XL(&YO="!C
M86YC;&QE9"D@+4%.1"T*("H@("`@("!I+B!E>'!I<F5?=&EM92!I<R!I;B!T
M:&4@9G5T=7)E("U/4BT*("H@("`@(&EI+B!E>'!I<F5?=&EM92!I<R!.54Q,
M("AI+F4N+"!A(')E8W5R<FEN9R!P=7)C:&%S92]S=6)S8W)I<'1I;VXI"B`J
M+PIC<F5A=&4@9G5N8W1I;VX*<&MK7V]F9F5R7VAA<U]P96YD:6YG7W!U<F-H
M*"!I;G1E9V5R("D*("`@(')E='5R;G,@8F]O;`IA<R`@)PH@("`@<V5L96-T
M("!C87-E"B`@("`@("`@("`@('=H96X*("`@("`@("`@("`@("`@("@*("`@
M("`@("`@("`@("`@('-E;&5C="`@<#`N<'5R8VAA<V5?:60*("`@("`@("`@
M("`@("`@("`@9G)O;2`@<&MK7W!U<F-H87-E('`P"B`@("`@("`@("`@("`@
M("`@=VAE<F4@('`P+F]F9F5R7VED(#T@)#$*("`@("`@("`@("`@("`@("`@
M("`@("`@86YD("@@<#`N<&5N9&EN9R`]('1R=64*("`@("`@("`@("`@("`@
M("`@("`@("`@("`@(&]R("@@*"!P,"YE>'!I<F5?=&EM92`^(&YO=R@I"B`@
M("`@("`@("`@("`@("`@("`@("`@("`@("`@("`@(&]R('`P+F5X<&ER95]T
M:6UE(&ES;G5L;"`I"B`@("`@("`@("`@("`@("`@("`@("`@("`@("`@("!A
M;F0@<#`N8V%N8V5L7V1A=&4@:7-N=6QL("D@*0H@("`@("`@("`@("`@("`@
M("!L:6UI="`Q"B`@("`@("`@("`@("`@("`I"B`@("`@("`@("`@("`@("!I
M<VYU;&P*("`@("`@("`@("`@=&AE;B!F86QS90H@("`@("`@("`@("!E;'-E
M('1R=64*("`@("`@("`@("`@96YD(#L*)R!L86YG=6%G92`G<W%L)R`["@H*
M+RHJ"B`J(%1H:7,@9G5N8W1I;VX@9VEV97,@=V]R<V4@<&5R9F]R;6%N8V4@
M=&EM92X@($ET('=A<R!C<F5A=&5D"B`J(&9O<B!T97-T('!U<G!O<V5S(&]N
M;'DN"B`J+PIC<F5A=&4@9G5N8W1I;VX*<&MK7V]F9F5R7VAA<U]P96YD:6YG
M7W!U<F-H,B@@:6YT96=E<B`I"B`@("!R971U<FYS(&)O;VP*87,@("<*("`@
M('-E;&5C="`@*"!C;W5N="@J*2`^(#`@*3HZ8F]O;`H@("`@("!F<F]M("!P
M:VM?<'5R8VAA<V4@<#`*("`@("!W:&5R92`@<#`N;V9F97)?:60@/2`D,0H@
M("`@("`@("`@("!A;F0@*"!P,"YP96YD:6YG(#T@=')U90H@("`@("`@("`@
M("`@("`@;W(@*"`H('`P+F5X<&ER95]T:6UE(#X@;F]W*"D*("`@("`@("`@
M("`@("`@("`@("`@;W(@<#`N97AP:7)E7W1I;64@:7-N=6QL("D*("`@("`@
M("`@("`@("`@("`@(&%N9"!P,"YC86YC96Q?9&%T92!I<VYU;&P@*2`I"B`@
7("`["B<@;&%N9W5A9V4@)W-Q;"<@.PH`
`
end
__________________________________
Do you Yahoo!?
Check out the new Yahoo! Front Page.
www.yahoo.com
On Tue, Nov 02, 2004 at 06:50:31PM -0800, patrick ~ wrote: > 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. A 7.1 system takes an exclusive lock on any VACUUM. It's the same as VACUUM FULL in 7.4. Nothing you can do to make that not be sluggish. You want to get those sites off 7.1 anyway. At the very least, you should be aware of xid exhaustion which can be prevented in 7.1 only with an initdb and complete restore. Failure to accommodate that will mean that one day your databases will just disappear. Current VACUUM certainly does impose a serious I/O load; this is the reason for the vacuum setting tweaks in 8.0. See the -hackers archives (from more than a year ago now) for (for instance) Jan Wieck's discussion of his feature and the subsequent debates. > 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). > My best guess is that there's something going on inside your function. I'd be looking for locks here, though. That makes no sense, given that you've only 78 rows being returned. BTW, this topic should probably be better pursued on -performance. A -- Andrew Sullivan | ajs@crankycanuck.ca I remember when computers were frustrating because they *did* exactly what you told them to. That actually seems sort of quaint now. --J.D. Baldwin
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@yahoo.com>
To: pgsql-sql@postgresql.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 -------
On Wed, Nov 03, 2004 at 07:01:00AM -0500, Andrew Sullivan wrote:
> On Tue, Nov 02, 2004 at 06:50:31PM -0800, patrick ~ wrote:
> > 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.
>
> A 7.1 system takes an exclusive lock on any VACUUM. It's the
> same as VACUUM FULL in 7.4. Nothing you can do to make that
> not be sluggish.
Just to clarify, the sliggishness isn't only during the vacuum
period. There are more more serious issues during the vacuum,
but i am not touching on those. The sluggishness is persistant
throughout daily operations.
> You want to get those sites off 7.1 anyway. At the very least,
> you should be aware of xid exhaustion which can be prevented in
> 7.1 only with an initdb and complete restore. Failure to
> accommodate that will mean that one day your databases will just
> disappear.
Yes, the plan is to upgrade them with new release of our product.
I didn't know about the xid exhaustion problem. I'll need to
search the mailing list archives.
> Current VACUUM certainly does impose a serious I/O load; this is
> the reason for the vacuum setting tweaks in 8.0. See the -hackers
> archives (from more than a year ago now) for (for instance) Jan
> Wieck's discussion of his feature and the subsequent debates.
I'll look into this. I don't think we are ready to touch 8.x
yet.
> > 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).
>
> My best guess is that there's something going on inside your
> function. I'd be looking for locks here, though. That makes no
> sense, given that you've only 78 rows being returned. BTW, this
> topic should probably be better pursued on -performance.
Again to clarify, the output I pasted was from my standalone
PostgreSQL box. That is, it wasn't being used other than those
quries being executed.
I don't know if you looked at my stored function, but there are
no locks in it (no explicit ones anyway).
Thanks for your reply,
--patrick
__________________________________
Do you Yahoo!?
Check out the new Yahoo! Front Page.
www.yahoo.com
On Wed, Nov 03, 2004 at 10:31:33AM -0800, patrick ~ wrote: > Just to clarify, the sliggishness isn't only during the vacuum > period. There are more more serious issues during the vacuum, > but i am not touching on those. The sluggishness is persistant > throughout daily operations. Then I suspect you have two problems, not one. The locking in 7.1 will certainly cause the timeouts during vacuum, but won't explain the other items. Someone else suggested REINDEX, also, which is likely needed. But again, you'll get more useful remarks from the -performance list. > Yes, the plan is to upgrade them with new release of our product. > I didn't know about the xid exhaustion problem. I'll need to > search the mailing list archives. You can learn a bit about this in the _current_ version of the docs under regular maintenance. > Again to clarify, the output I pasted was from my standalone > PostgreSQL box. That is, it wasn't being used other than those > quries being executed. That's even worse. I certainly can't explain your results, then. You really want to move to the -performance list for that. > I don't know if you looked at my stored function, but there are > no locks in it (no explicit ones anyway). Foreign keys are one well-known area of locking surprises. A -- Andrew Sullivan | ajs@crankycanuck.ca This work was visionary and imaginative, and goes to show that visionary and imaginative work need not end up well. --Dennis Ritchie
patrick ~ <sidsrr@yahoo.com> writes: > 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). If it gets slower immediately after a single vacuum analyze then the problem is that one of the queries is getting planned wrong when stats are available. If it takes a while to slow down then it could be other problems such as index bloat etc. Don't use "explain verbose" use "explain analyze". I don't know if it was in 7.1 but you say you reproduced the problem with 7.4. It would be helpful to see the results of "explain analyze select ..." on the query before and after the vacuum analyze. -- greg