Message-ID: <4C3F29D1.1080100@squeakycode.net>
Date: Thu, 15 Jul 2010 10:31:29 -0500
From: Andy Colson <andy@squeakycode.net>
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US;
	rv:1.9.2.4) Gecko/20100608 Lightning/1.0b2 Thunderbird/3.1
MIME-Version: 1.0
To: Patrick Donlin <pdonlin@oaisd.org>, pgsql-performance@postgresql.org
Subject: Re: Identical query slower on 8.4 vs 8.3
References: <4C3EDB070200002500033621@gw.wicourts.gov>
	<1123546138.13276371279206773000.JavaMail.root@mm-mailstore02.merit.edu>
In-Reply-To: 
 <1123546138.13276371279206773000.JavaMail.root@mm-mailstore02.merit.edu>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit

FULL is usually bad.  Stick to "vacuum analyze" and drop the full.

Do you have indexes on:

test.tid, testresult.fk_tid, questionresult.fk_trid and testresult.trid


-Andy


On 7/15/2010 10:12 AM, Patrick Donlin wrote:
> I'll read over that wiki entry, but for now here is the EXPLAIN ANALYZE
> output assuming I did it correctly. I have run vacuumdb --full
> --analyze, it actually runs as a nightly cron job.
>
> 8.4.4 Sever:
> "Unique (cost=202950.82..227521.59 rows=702022 width=86) (actual
> time=21273.371..22429.511 rows=700536 loops=1)"
> " -> Sort (cost=202950.82..204705.87 rows=702022 width=86) (actual
> time=21273.368..22015.948 rows=700536 loops=1)"
> " Sort Key: test.tid, testresult.trscore, testresult.trpossiblescore,
> testresult.trstart, testresult.trfinish, testresult.trscorebreakdown,
> testresult.fk_sid, test.tname, qr.qrscore, qr.qrtotalscore,
> testresult.trid, qr.qrid"
> " Sort Method: external merge Disk: 71768kB"
> " -> Hash Join (cost=2300.82..34001.42 rows=702022 width=86) (actual
> time=64.388..1177.468 rows=700536 loops=1)"
> " Hash Cond: (qr.fk_trid = testresult.trid)"
> " -> Seq Scan on questionresult qr (cost=0.00..12182.22 rows=702022
> width=16) (actual time=0.090..275.518 rows=702022 loops=1)"
> " -> Hash (cost=1552.97..1552.97 rows=29668 width=74) (actual
> time=63.042..63.042 rows=29515 loops=1)"
> " -> Hash Join (cost=3.35..1552.97 rows=29668 width=74) (actual
> time=0.227..39.111 rows=29515 loops=1)"
> " Hash Cond: (testresult.fk_tid = test.tid)"
> " -> Seq Scan on testresult (cost=0.00..1141.68 rows=29668 width=53)
> (actual time=0.019..15.622 rows=29668 loops=1)"
> " -> Hash (cost=2.60..2.60 rows=60 width=21) (actual time=0.088..0.088
> rows=60 loops=1)"
> " -> Seq Scan on test (cost=0.00..2.60 rows=60 width=21) (actual
> time=0.015..0.044 rows=60 loops=1)"
> "Total runtime: 22528.820 ms"
>
> 8.3.7 Server:
> "Unique (cost=202950.82..227521.59 rows=702022 width=86) (actual
> time=22157.714..23343.461 rows=700536 loops=1)"
> " -> Sort (cost=202950.82..204705.87 rows=702022 width=86) (actual
> time=22157.706..22942.018 rows=700536 loops=1)"
> " Sort Key: test.tid, testresult.trscore, testresult.trpossiblescore,
> testresult.trstart, testresult.trfinish, testresult.trscorebreakdown,
> testresult.fk_sid, test.tname, qr.qrscore, qr.qrtotalscore,
> testresult.trid, qr.qrid"
> " Sort Method: external merge Disk: 75864kB"
> " -> Hash Join (cost=2300.82..34001.42 rows=702022 width=86) (actual
> time=72.842..1276.634 rows=700536 loops=1)"
> " Hash Cond: (qr.fk_trid = testresult.trid)"
> " -> Seq Scan on questionresult qr (cost=0.00..12182.22 rows=702022
> width=16) (actual time=0.112..229.987 rows=702022 loops=1)"
> " -> Hash (cost=1552.97..1552.97 rows=29668 width=74) (actual
> time=71.421..71.421 rows=29515 loops=1)"
> " -> Hash Join (cost=3.35..1552.97 rows=29668 width=74) (actual
> time=0.398..44.524 rows=29515 loops=1)"
> " Hash Cond: (testresult.fk_tid = test.tid)"
> " -> Seq Scan on testresult (cost=0.00..1141.68 rows=29668 width=53)
> (actual time=0.117..20.890 rows=29668 loops=1)"
> " -> Hash (cost=2.60..2.60 rows=60 width=21) (actual time=0.112..0.112
> rows=60 loops=1)"
> " -> Seq Scan on test (cost=0.00..2.60 rows=60 width=21) (actual
> time=0.035..0.069 rows=60 loops=1)"
> "Total runtime: 23462.639 ms"
>
>
> Thanks for the quick responses and being patient with me not providing
> enough information.
> -Patrick
>
> ----- Original Message -----
> From: "Kevin Grittner" <Kevin.Grittner@wicourts.gov>
> To: "Patrick Donlin" <pdonlin@oaisd.org>, pgsql-performance@postgresql.org
> Sent: Thursday, July 15, 2010 10:55:19 AM GMT -05:00 US/Canada Eastern
> Subject: Re: [PERFORM] Identical query slower on 8.4 vs 8.3
>
> Patrick Donlin <pdonlin@oaisd.org> wrote:
>
>  > Anyone have any ideas on where I should start looking to figure
>  > this out?
>
> You're going to want to run EXPLAIN ANALYZE for the slow query on
> both servers. If you want the rest of us to be able to contribute
> ideas, we'll need a little more information -- please read this
> page:
>
> http://wiki.postgresql.org/wiki/SlowQueryQuestions
>
>  > I didn't perform any special steps when moving to v8.4, I just did
>  > a pg_dump from the 8.3 server and restored it on the new 8.4
>  > servers.
>
> A database VACUUM ANALYZE by a superuser is a good idea; otherwise
> that's fine technique.
>
> -Kevin