Re: Identical query slower on 8.4 vs 8.3 - Mailing list pgsql-performance

From Patrick Donlin
Subject Re: Identical query slower on 8.4 vs 8.3
Date
Msg-id 1123546138.13276371279206773000.JavaMail.root@mm-mailstore02.merit.edu
Whole thread Raw
In response to Re: Identical query slower on 8.4 vs 8.3  ("Kevin Grittner" <Kevin.Grittner@wicourts.gov>)
Responses Re: Identical query slower on 8.4 vs 8.3  (Alvaro Herrera <alvherre@commandprompt.com>)
Re: Identical query slower on 8.4 vs 8.3  (Andy Colson <andy@squeakycode.net>)
Re: Identical query slower on 8.4 vs 8.3  ("Kevin Grittner" <Kevin.Grittner@wicourts.gov>)
Re: Identical query slower on 8.4 vs 8.3  (Merlin Moncure <mmoncure@gmail.com>)
Re: Identical query slower on 8.4 vs 8.3  ("Igor Neyman" <ineyman@perceptron.com>)
List pgsql-performance
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

pgsql-performance by date:

Previous
From: "Kevin Grittner"
Date:
Subject: Re: Identical query slower on 8.4 vs 8.3
Next
From: Alvaro Herrera
Date:
Subject: Re: Identical query slower on 8.4 vs 8.3