Thread: full vacuum really slows down query
I have a query that takes 2 sec if I run it from a freshly restored dump. If I run a full vacuum on the database it then takes 30 seconds. Would someone please comment as to why I would see a 15x slow down by only vacuuming the DB? Reindexing does not help, and a full vacuum was run just prior to the dump. I run a full vacuum every night. I am using 8.3.1
On Wed, 2008-06-04 at 17:02 -0500, Jason Long wrote: > I have a query that takes 2 sec if I run it from a freshly restored > dump. If I run a full vacuum on the database it then takes 30 seconds. If you run it a second time after the vacuum full? Joshua D. Drake
Jason Long <mailing.list@supernovasoftware.com> writes:
> I have a query that takes 2 sec if I run it from a freshly restored
> dump. If I run a full vacuum on the database it then takes 30 seconds.
> Would someone please comment as to why I would see a 15x slow down by
> only vacuuming the DB?
EXPLAIN ANALYZE of both cases might yield some insight.
regards, tom lane
Yes.
This is what I do.
1. Vacuum full
2. Reindex force
This is done ever night
My users complained about a report being slow.
I grabbed a dump and restored it to my development machine.
The query worked just fine, but not on the production server.
I did a vacuum full and then reran the query. Now it performs just as
slow as on the production machine. That is the only change I made.
I am in the process of trying to figure out the EXPLAIN ANALYZE for
both queries, but I have never had to read this output and I am
unfamiliar with how to find the problem. I will post both here and
maybe someone can help me out.
Joshua D. Drake wrote:
On Wed, 2008-06-04 at 17:02 -0500, Jason Long wrote:
I have a query that takes 2 sec if I run it from a freshly restored
dump. If I run a full vacuum on the database it then takes 30 seconds.
If you run it a second time after the vacuum full?
Joshua D. Drake
Just post the explain analyze output here on the list. There's lots of folks here who can read it. On Wed, Jun 4, 2008 at 5:49 PM, Jason Long <mailing.list@supernovasoftware.com> wrote: > Yes. > This is what I do. > 1. Vacuum full > 2. Reindex force > This is done ever night > > My users complained about a report being slow. > > I grabbed a dump and restored it to my development machine. > > The query worked just fine, but not on the production server. > > I did a vacuum full and then reran the query. Now it performs just as slow > as on the production machine. That is the only change I made. > > I am in the process of trying to figure out the EXPLAIN ANALYZE for both > queries, but I have never had to read this output and I am unfamiliar with > how to find the problem. I will post both here and maybe someone can help > me out. > > > > Joshua D. Drake wrote: > > On Wed, 2008-06-04 at 17:02 -0500, Jason Long wrote: > > > I have a query that takes 2 sec if I run it from a freshly restored > dump. If I run a full vacuum on the database it then takes 30 seconds. > > > If you run it a second time after the vacuum full? > > Joshua D. Drake > > > >
I am resending this is plain text as it was rejected. What is the best way to include this kind of output to the mailing list? I would greatly appreciate any advice on how to read the following output from EXPLAIN ANALYZE. When running the query the first time from a fresh restore it takes about 55 sec. On a second run is take about 2 sec. After the vacuum it takes about 36 sec no matter how many times I run it. My application is growing rapidly in both size and complexity. I really need to get a handle on this soon. *Query run from a fresh restore* "Sort (cost=242145.26..242145.27 rows=1 width=1200) (actual time=55100.785..55100.820 rows=158 loops=1)" " Sort Key: (sum(pipe0_1_.numpieces)), (sum(pipe0_.numfeet))" " Sort Method: quicksort Memory: 52kB" " -> HashAggregate (cost=242145.24..242145.25 rows=1 width=1200) (actual time=55099.970..55100.194 rows=158 loops=1)" " -> Nested Loop (cost=0.00..242145.20 rows=1 width=1200) (actual time=391.496..55092.841 rows=427 loops=1)" " Join Filter: (pipe0_.popipe_id = popipe1_.id)" " -> Nested Loop (cost=0.00..240701.08 rows=1 width=684) (actual time=2.543..-2171.666 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240700.46 rows=1 width=676) (actual time=2.486..-1946.110 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240699.93 rows=1 width=644) (actual time=2.431..-1462.137 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240699.56 rows=1 width=136) (actual time=2.357..-2010.958 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240698.36 rows=1 width=128) (actual time=2.279..-1534.495 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240698.08 rows=1 width=136) (actual time=0.909..-1323.123 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240692.30 rows=1 width=136) (actual time=0.882..-1625.883 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240690.71 rows=3 width=104) (actual time=0.826..-1155.887 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240665.27 rows=48 width=72) (actual time=0.766..-436.684 rows=7236 loops=1)" " -> Index Scan using t_pipe_pkey on t_pipe pipe0_ (cost=0.00..240391.77 rows=48 width=56) (actual time=0.759..796.516 rows=7236 loops=1)" " Filter: ((subplan) IS NULL)" " SubPlan" " -> Nested Loop Left Join (cost=0.00..24.85 rows=1 width=8) (actual time=0.048..0.077 rows=1 loops=9644)" " -> Nested Loop (cost=0.00..16.55 rows=1 width=48) (actual time=-0.013..0.042 rows=1 loops=9644)" " -> Index Scan using t_pipe_pkey on t_pipe p (cost=0.00..8.27 rows=1 width=48) (actual time=-0.021..0.006 rows=1 loops=9644)" " Index Cond: (id = $0)" " -> Index Scan using t_generic_item_pkey on t_generic_item gi (cost=0.00..8.27 rows=1 width=16) (actual time=0.057..0.031 rows=1 loops=9644)" " Index Cond: (gi.id = $0)" " -> Index Scan using uk_projection_weight_grade_endfinish_actor_condtion on t_projection pr (cost=0.00..8.28 rows=1 width=56) (actual time=0.005..0.005 rows=0 loops=9644)" " Index Cond: ((pr.popipe_id = p.popipe_id) AND (pr.weight_id = p.weight_id) AND (pr.grade_id = p.grade_id) AND (pr.endfinish_id = p.endfinish_id) AND (pr.actor_id = gi.actor_id) AND (pr.condition_id = p.condition_id))" " -> Index Scan using t_generic_item_pkey on t_generic_item pipe0_1_ (cost=0.00..5.69 rows=1 width=32) (actual time=-0.068..-0.138 rows=1 loops=7236)" " Index Cond: (pipe0_1_.id = pipe0_.id)" " -> Index Scan using pk_t_condition on t_condition condition7_ (cost=0.00..0.52 rows=1 width=40) (actual time=0.039..0.004 rows=1 loops=7236)" " Index Cond: (condition7_.id = pipe0_.condition_id)" " Filter: condition7_.needsprojection" " -> Index Scan using pk_t_endfinish on t_endfinish endfinish4_ (cost=0.00..0.52 rows=1 width=40) (actual time=0.045..0.004 rows=1 loops=6066)" " Index Cond: (endfinish4_.id = pipe0_.endfinish_id)" " -> Index Scan using t_action_pkey on t_state state9_ (cost=0.00..5.77 rows=1 width=16) (actual time=0.004..0.089 rows=1 loops=6066)" " Index Cond: (state9_.id = pipe0_1_.state_id)" " -> Index Scan using pk_t_status on t_status status10_ (cost=0.00..0.27 rows=1 width=8) (actual time=-0.080..-0.037 rows=1 loops=6066)" " Index Cond: (status10_.id = state9_.status_id)" " Filter: status10_.needsprojection" " -> Index Scan using pk_t_actor on t_actor actor5_ (cost=0.00..1.18 rows=1 width=16) (actual time=0.006..-0.154 rows=1 loops=3174)" " Index Cond: (actor5_.id = pipe0_1_.actor_id)" " -> Index Scan using pk_t_contact on t_contact contact6_ (cost=0.00..0.36 rows=1 width=524) (actual time=0.086..0.169 rows=1 loops=3174)" " Index Cond: (contact6_.id = actor5_.contact_id)" " -> Index Scan using pk_t_grade on t_grade grade3_ (cost=0.00..0.52 rows=1 width=40) (actual time=0.004..-0.156 rows=1 loops=3174)" " Index Cond: (grade3_.id = pipe0_.grade_id)" " -> Index Scan using pk_t_weight on t_weight weight2_ (cost=0.00..0.60 rows=1 width=16) (actual time=0.004..0.006 rows=1 loops=3174)" " Index Cond: (weight2_.id = pipe0_.weight_id)" " -> Merge Join (cost=0.00..1428.20 rows=1274 width=532) (actual time=0.531..17.466 rows=998 loops=3174)" " Merge Cond: (popipe1_.id = popipe1_1_.id)" " -> Index Scan using t_po_pipe_pkey on t_po_pipe popipe1_ (cost=0.00..170.49 rows=2549 width=8) (actual time=0.335..2.914 rows=2549 loops=3174)" " -> Index Scan using t_action_pkey on t_state popipe1_1_ (cost=0.00..1229.50 rows=3641 width=524) (actual time=0.092..10.843 rows=5727 loops=3174)" " Filter: (NOT popipe1_1_.spec)" "Total runtime: 55101.547 ms" *Before vacuum but after a second run of the query* "Sort (cost=241636.97..241637.00 rows=10 width=183) (actual time=2182.240..2182.273 rows=158 loops=1)" " Sort Key: (sum(pipe0_1_.numpieces)), (sum(pipe0_.numfeet))" " Sort Method: quicksort Memory: 52kB" " -> HashAggregate (cost=241636.63..241636.81 rows=10 width=183) (actual time=1924.839..1925.114 rows=158 loops=1)" " -> Nested Loop (cost=467.32..241636.26 rows=10 width=183) (actual time=29.712..1922.303 rows=427 loops=1)" " -> Hash Join (cost=467.32..241630.12 rows=10 width=175) (actual time=29.701..1662.213 rows=427 loops=1)" " Hash Cond: (pipe0_.grade_id = grade3_.id)" " -> Hash Join (cost=465.37..241628.04 rows=10 width=143) (actual time=29.608..1661.590 rows=427 loops=1)" " Hash Cond: (pipe0_.endfinish_id = endfinish4_.id)" " -> Nested Loop (cost=463.31..241625.85 rows=10 width=111) (actual time=29.531..1660.932 rows=427 loops=1)" " -> Nested Loop (cost=463.31..241622.11 rows=10 width=111) (actual time=29.520..1657.811 rows=427 loops=1)" " -> Nested Loop (cost=463.31..241610.14 rows=10 width=103) (actual time=29.508..1655.306 rows=427 loops=1)" " Join Filter: (pipe0_.popipe_id = popipe1_.id)" " -> Nested Loop (cost=0.00..240600.89 rows=12 width=96) (actual time=1.127..307.107 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240594.13 rows=24 width=104) (actual time=0.124..-232.727 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240455.39 rows=24 width=104) (actual time=0.106..-11.779 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240429.94 rows=48 width=72) (actual time=0.094..469.592 rows=7236 loops=1)" " -> Index Scan using t_pipe_pkey on t_pipe pipe0_ (cost=0.00..240156.45 rows=48 width=56) (actual time=0.089..175.278 rows=7236 loops=1)" " Filter: ((subplan) IS NULL)" " SubPlan" " -> Nested Loop Left Join (cost=0.00..24.85 rows=1 width=8) (actual time=-0.093..-0.091 rows=1 loops=9644)" " -> Nested Loop (cost=0.00..16.55 rows=1 width=48) (actual time=-0.018..-0.017 rows=1 loops=9644)" " -> Index Scan using t_pipe_pkey on t_pipe p (cost=0.00..8.27 rows=1 width=48) (actual time=0.003..-0.024 rows=1 loops=9644)" " Index Cond: (id = $0)" " -> Index Scan using t_generic_item_pkey on t_generic_item gi (cost=0.00..8.27 rows=1 width=16) (actual time=0.003..-0.023 rows=1 loops=9644)" " Index Cond: (gi.id = $0)" " -> Index Scan using uk_projection_weight_grade_endfinish_actor_condtion on t_projection pr (cost=0.00..8.28 rows=1 width=56) (actual time=0.003..0.003 rows=0 loops=9644)" " Index Cond: ((pr.popipe_id = p.popipe_id) AND (pr.weight_id = p.weight_id) AND (pr.grade_id = p.grade_id) AND (pr.endfinish_id = p.endfinish_id) AND (pr.actor_id = gi.actor_id) AND (pr.condition_id = p.condition_id))" " -> Index Scan using t_generic_item_pkey on t_generic_item pipe0_1_ (cost=0.00..5.69 rows=1 width=32) (actual time=0.002..0.003 rows=1 loops=7236)" " Index Cond: (pipe0_1_.id = pipe0_.id)" " -> Index Scan using pk_t_condition on t_condition condition7_ (cost=0.00..0.52 rows=1 width=40) (actual time=0.037..0.002 rows=1 loops=7236)" " Index Cond: (condition7_.id = pipe0_.condition_id)" " Filter: condition7_.needsprojection" " -> Index Scan using t_action_pkey on t_state state9_ (cost=0.00..5.77 rows=1 width=16) (actual time=-0.039..-0.039 rows=1 loops=6066)" " Index Cond: (state9_.id = pipe0_1_.state_id)" " -> Index Scan using pk_t_status on t_status status10_ (cost=0.00..0.27 rows=1 width=8) (actual time=0.045..0.130 rows=1 loops=6066)" " Index Cond: (status10_.id = state9_.status_id)" " Filter: status10_.needsprojection" " -> Materialize (cost=463.31..483.53 rows=2022 width=23) (actual time=0.001..-0.357 rows=998 loops=3174)" " -> Hash Join (cost=81.35..461.29 rows=2022 width=23) (actual time=2.740..13.504 rows=998 loops=1)" " Hash Cond: (popipe1_1_.id = popipe1_.id)" " -> Seq Scan on t_state popipe1_1_ (cost=0.00..330.83 rows=5778 width=15) (actual time=0.008..8.412 rows=5732 loops=1)" " Filter: (NOT spec)" " -> Hash (cost=49.49..49.49 rows=2549 width=8) (actual time=2.701..2.701 rows=2549 loops=1)" " -> Seq Scan on t_po_pipe popipe1_ (cost=0.00..49.49 rows=2549 width=8) (actual time=0.010..257.753 rows=2549 loops=1)" " -> Index Scan using pk_t_actor on t_actor actor5_ (cost=0.00..1.18 rows=1 width=16) (actual time=0.003..0.004 rows=1 loops=427)" " Index Cond: (actor5_.id = pipe0_1_.actor_id)" " -> Index Scan using pk_t_contact on t_contact contact6_ (cost=0.00..0.36 rows=1 width=16) (actual time=0.004..0.005 rows=1 loops=427)" " Index Cond: (contact6_.id = actor5_.contact_id)" " -> Hash (cost=1.47..1.47 rows=47 width=40) (actual time=0.059..0.059 rows=47 loops=1)" " -> Seq Scan on t_endfinish endfinish4_ (cost=0.00..1.47 rows=47 width=40) (actual time=0.016..0.033 rows=47 loops=1)" " -> Hash (cost=1.42..1.42 rows=42 width=40) (actual time=0.071..0.071 rows=42 loops=1)" " -> Seq Scan on t_grade grade3_ (cost=0.00..1.42 rows=42 width=40) (actual time=0.029..0.045 rows=42 loops=1)" " -> Index Scan using pk_t_weight on t_weight weight2_ (cost=0.00..0.60 rows=1 width=16) (actual time=0.605..0.606 rows=1 loops=427)" " Index Cond: (weight2_.id = pipe0_.weight_id)" "Total runtime: 2183.176 ms" *After vacuum -- I see no improvement even after several runs* "Sort (cost=243084.23..243084.24 rows=5 width=107) (actual time=36649.839..36649.876 rows=158 loops=1)" " Sort Key: (sum(pipe0_1_.numpieces)), (sum(pipe0_.numfeet))" " Sort Method: quicksort Memory: 52kB" " -> HashAggregate (cost=243084.08..243084.17 rows=5 width=107) (actual time=36649.104..36649.337 rows=158 loops=1)" " -> Nested Loop (cost=81.35..243083.89 rows=5 width=107) (actual time=3.495..36330.092 rows=427 loops=1)" " -> Nested Loop (cost=81.35..243080.83 rows=5 width=99) (actual time=3.486..36325.964 rows=427 loops=1)" " -> Nested Loop (cost=81.35..243078.18 rows=5 width=93) (actual time=3.477..36322.061 rows=427 loops=1)" " -> Nested Loop (cost=81.35..243075.53 rows=5 width=86) (actual time=3.468..36318.062 rows=427 loops=1)" " -> Nested Loop (cost=81.35..243073.66 rows=5 width=86) (actual time=3.457..36312.957 rows=427 loops=1)" " -> Nested Loop (cost=81.35..243067.67 rows=5 width=78) (actual time=3.441..36305.745 rows=427 loops=1)" " Join Filter: (pipe0_.popipe_id = popipe1_.id)" " -> Nested Loop (cost=0.00..240558.99 rows=6 width=71) (actual time=1.185..1522.885 rows=3174 loops=1)" " -> Nested Loop (cost=0.00..240554.20 rows=17 width=79) (actual time=0.101..440.045 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240455.93 rows=17 width=79) (actual time=0.090..-131.182 rows=6066 loops=1)" " -> Nested Loop (cost=0.00..240430.48 rows=48 width=72) (actual time=0.083..591.038 rows=7236 loops=1)" " -> Index Scan using t_pipe_pkey on t_pipe pipe0_ (cost=0.00..240156.99 rows=48 width=56) (actual time=0.078..541.958 rows=7236 loops=1)" " Filter: ((subplan) IS NULL)" " SubPlan" " -> Nested Loop Left Join (cost=0.00..24.85 rows=1 width=8) (actual time=0.048..0.077 rows=1 loops=9644)" " -> Nested Loop (cost=0.00..16.55 rows=1 width=48) (actual time=0.067..0.095 rows=1 loops=9644)" " -> Index Scan using t_pipe_pkey on t_pipe p (cost=0.00..8.27 rows=1 width=48) (actual time=0.059..0.059 rows=1 loops=9644)" " Index Cond: (id = $0)" " -> Index Scan using t_generic_item_pkey on t_generic_item gi (cost=0.00..8.27 rows=1 width=16) (actual time=0.031..0.031 rows=1 loops=9644)" " Index Cond: (gi.id = $0)" " -> Index Scan using uk_projection_weight_grade_endfinish_actor_condtion on t_projection pr (cost=0.00..8.28 rows=1 width=56) (actual time=-0.075..-0.075 rows=0 loops=9644)" " Index Cond: ((pr.popipe_id = p.popipe_id) AND (pr.weight_id = p.weight_id) AND (pr.grade_id = p.grade_id) AND (pr.endfinish_id = p.endfinish_id) AND (pr.actor_id = gi.actor_id) AND (pr.condition_id = p.condition_id))" " -> Index Scan using t_generic_item_pkey on t_generic_item pipe0_1_ (cost=0.00..5.69 rows=1 width=32) (actual time=-0.069..-0.067 rows=1 loops=7236)" " Index Cond: (pipe0_1_.id = pipe0_.id)" " -> Index Scan using pk_t_condition on t_condition condition7_ (cost=0.00..0.52 rows=1 width=15) (actual time=-0.139..-0.209 rows=1 loops=7236)" " Index Cond: (condition7_.id = pipe0_.condition_id)" " Filter: condition7_.needsprojection" " -> Index Scan using t_action_pkey on t_state state9_ (cost=0.00..5.77 rows=1 width=16) (actual time=0.132..0.091 rows=1 loops=6066)" " Index Cond: (state9_.id = pipe0_1_.state_id)" " -> Index Scan using pk_t_status on t_status status10_ (cost=0.00..0.27 rows=1 width=8) (actual time=0.047..0.091 rows=1 loops=6066)" " Index Cond: (status10_.id = state9_.status_id)" " Filter: status10_.needsprojection" " -> Hash Join (cost=81.35..460.86 rows=2004 width=23) (actual time=0.092..11.790 rows=998 loops=3174)" " Hash Cond: (popipe1_1_.id = popipe1_.id)" " -> Seq Scan on t_state popipe1_1_ (cost=0.00..330.83 rows=5727 width=15) (actual time=0.087..8.880 rows=5732 loops=3174)" " Filter: (NOT spec)" " -> Hash (cost=49.49..49.49 rows=2549 width=8) (actual time=2.507..2.507 rows=2549 loops=1)" " -> Seq Scan on t_po_pipe popipe1_ (cost=0.00..49.49 rows=2549 width=8) (actual time=0.015..1.208 rows=2549 loops=1)" " -> Index Scan using pk_t_actor on t_actor actor5_ (cost=0.00..1.18 rows=1 width=16) (actual time=0.011..0.011 rows=1 loops=427)" " Index Cond: (actor5_.id = pipe0_1_.actor_id)" " -> Index Scan using pk_t_contact on t_contact contact6_ (cost=0.00..0.36 rows=1 width=16) (actual time=-0.597..-0.597 rows=1 loops=427)" " Index Cond: (contact6_.id = actor5_.contact_id)" " -> Index Scan using pk_t_endfinish on t_endfinish endfinish4_ (cost=0.00..0.52 rows=1 width=15) (actual time=0.005..0.005 rows=1 loops=427)" " Index Cond: (endfinish4_.id = pipe0_.endfinish_id)" " -> Index Scan using pk_t_grade on t_grade grade3_ (cost=0.00..0.52 rows=1 width=14) (actual time=0.004..0.005 rows=1 loops=427)" " Index Cond: (grade3_.id = pipe0_.grade_id)" " -> Index Scan using pk_t_weight on t_weight weight2_ (cost=0.00..0.60 rows=1 width=16) (actual time=0.005..0.006 rows=1 loops=427)" " Index Cond: (weight2_.id = pipe0_.weight_id)" "Total runtime: 36650.609 ms" Tom Lane wrote: > Jason Long <mailing.list@supernovasoftware.com> writes: > >> I have a query that takes 2 sec if I run it from a freshly restored >> dump. If I run a full vacuum on the database it then takes 30 seconds. >> > > >> Would someone please comment as to why I would see a 15x slow down by >> only vacuuming the DB? >> > > EXPLAIN ANALYZE of both cases might yield some insight. > > regards, tom lane >
Jason Long wrote: > I would greatly appreciate any advice on how to read the following > output from EXPLAIN ANALYZE. > > When running the query the first time from a fresh restore it takes > about 55 sec. > On a second run is take about 2 sec. > After the vacuum it takes about 36 sec no matter how many > times I run it. > *Query run from a fresh restore* > "Sort (cost=242145.26..242145.27 rows=1 width=1200) (actual > time=55100.785..55100.820 rows=158 loops=1)" ... > "Total runtime: 55101.547 ms" What is shown is the query plan that the planner chose as having the cheapest estimated cost. The cost of the various components of the query plan are shown. The units are not time, but estimations of relative cost. The estimated number of rows that will be returned by each component are also shown. The actual milliseconds it took and rows returned are also shown. If a component is looped through, the time is the averageper loop. The second values for cost and time are the cost or time to complete. Documentation: http://www.postgresql.org/docs/8.3/interactive/using-explain.html I can't explain why you get negative actual times. > *Before vacuum but after a second run of the query* > "Sort (cost=241636.97..241637.00 rows=10 width=183) (actual > time=2182.240..2182.273 rows=158 loops=1)" ... > "Total runtime: 2183.176 ms" Just looking at the first line shows that this second query has chosen a different plan that the one above. > *After vacuum -- I see no improvement even after several runs* > "Sort (cost=243084.23..243084.24 rows=5 width=107) (actual > time=36649.839..36649.876 rows=158 loops=1)" ... > "Total runtime: 36650.609 ms" This is obviously a third query plan. i.e. All three of the queries shown are using different plans, so what you are looking for is why different plans are chosen,rather than why a single plan sometimes runs fast, and sometimes runs slow. When there are large differences in times that queries take, it is often due to gross under-estimation of the number of rowsthat a portion of the plan will return, resulting in many loops through a portion of the query that the planner thoughtit would only go through a small number of times. The join of popipe1_1_.id = popipe1_.id shows an example of this, in your first query it is the last 5 lines, which it isexpecting to loop through once, which we can tell due to the line indented to the same amount much higher up (with estimatedcost 240701.08). That join has moved in the second query, and is under a Materialize line. The chosen plan is different, and that portionis only performed once. The Materialize part was expected to be looped through 12 times, but it went through 3174times. In the third plan, it isn't under a Materialize, and is expected to loop 6 times. It loops 3174 times. Hopefully others can provide more help, I've gotta go... Regards, Stephen Denne. -- At the Datamail Group we value teamwork, respect, achievement, client focus, and courage. This email with any attachments is confidential and may be subject to legal privilege. If it is not intended for you please advise by replying immediately, destroy it and do not copy, disclose or use it in any way. The Datamail Group, through our GoGreen programme, is committed to environmental sustainability. Help us in our efforts by not printing this email. __________________________________________________________________ This email has been scanned by the DMZGlobal Business Quality Electronic Messaging Suite. Please see http://www.dmzglobal.com/dmzmessaging.htm for details. __________________________________________________________________
Have you run analyze on the tables? bumped up default stats and re-run analyze? Best way to send query plans is as attachments btw.
Oh, another point of attack. Always test your queries under just \timing. You can wrap up like this: \timing select count(*) from (subselect goes here); I've been on a few machines where the cost of explain analyze itself threw the timing way off.
Thanks for the advice. I will keep playing with it. Can someone here comment on EnterpriseDB or another companies paid support? I may consider this to quickly improve my performance. Scott Marlowe wrote: > Have you run analyze on the tables? bumped up default stats and re-run analyze? > > Best way to send query plans is as attachments btw. >