Re: How to track down inconsistent performance?

From: Ron Snyder <snyder(at)roguewave(dot)com>
To: 'Tom Lane' <tgl(at)sss(dot)pgh(dot)pa(dot)us>, Ron Snyder <snyder(at)roguewave(dot)com>
Cc: pgsql General List <pgsql-general(at)postgresql(dot)org>
Subject: Re: How to track down inconsistent performance?
Date: 2002-04-28 16:49:51
Message-ID: F888C30C3021D411B9DA00B0D0209BE8026E3039@cvo-exchange.cvo.roguewave.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

I learned last night that 'visible' is false in about 95% of the records.
The products are not evenly distributed either-- sourcepro_db (the previous
example) accounts for 1/2 of the records, and math (today's example) account
for 3%.

Here's the output of explain analyze-- these were executed less than 30
seconds apart.
These are: "explain analyze" the query; do the query; "explain analyze" the
query again.

bash-2.05$ time psql quickview -c "explain analyze select distinct
os,compiler,stdlibtype,threadlib from builds where product='math' and
visible=true order by 1 asc;"
NOTICE: QUERY PLAN:

Unique (cost=33579.50..33664.14 rows=846 width=50) (actual
time=27453.33..27478.75 rows=202 loops=1)
-> Sort (cost=33579.50..33579.50 rows=8463 width=50) (actual
time=27453.32..27462.24 rows=5934 loops=1)
-> Index Scan using builds_visible_product on builds
(cost=0.00..32868.90 rows=8463 width=50) (actual time=0.30..27266.32
rows=5934 loops=1)
Total runtime: 27491.93 msec

EXPLAIN

real 0m27.528s
user 0m0.000s
sys 0m0.000s
bash-2.05$ time psql quickview -c "select distinct
os,compiler,stdlibtype,threadlib from builds where product='math' and
visible=true order by 1 asc;" > /dev/null

real 0m0.330s
user 0m0.000s
sys 0m0.010s
bash-2.05$ time psql quickview -c "explain analyze select distinct
os,compiler,stdlibtype,threadlib from builds where product='math' and
visible=true order by 1 asc;"
NOTICE: QUERY PLAN:

Unique (cost=33579.50..33664.14 rows=846 width=50) (actual
time=270.59..297.45 rows=202 loops=1)
-> Sort (cost=33579.50..33579.50 rows=8463 width=50) (actual
time=270.58..280.75 rows=5934 loops=1)
-> Index Scan using builds_visible_product on builds
(cost=0.00..32868.90 rows=8463 width=50) (actual time=0.08..90.87 rows=5934
loops=1)
Total runtime: 307.74 msec

EXPLAIN

real 0m0.336s
user 0m0.000s
sys 0m0.010s

Thanks for your help!
-ron

> -----Original Message-----
> From: Tom Lane [mailto:tgl(at)sss(dot)pgh(dot)pa(dot)us]
> Sent: Sunday, April 28, 2002 7:59 AM
> To: Ron Snyder
> Cc: pgsql General List
> Subject: Re: [GENERAL] How to track down inconsistent performance?
>
>
> Ron Snyder <snyder(at)roguewave(dot)com> writes:
> > 'visible' is a boolean, 'product' is a varchar(30), and
> there are about 210K
> > records in the builds table. (I don't know if it's
> relevant, but there are
> > about 39 distinct product values.
>
> Hmm, a rough guess would suggest that the query will be
> retrieving about
> 1/78th of the rows (unless there are statistics you haven't
> mentioned that
> affect that). I would think that a seqscan would be faster for this.
> I would definitely think that the planner would think so --- are you
> forcing enable_seqscan off?
>
> Since you're evidently running 7.2, I'd ask for EXPLAIN ANALYZE rather
> than just EXPLAIN output. It'd be even more helpful if you are able
> to catch both the fast and slow cases under EXPLAIN ANALYZE.
>
> regards, tom lane
>

Browse pgsql-general by date

  From Date Subject
Next Message Ron Snyder 2002-04-28 17:17:44 Re: How to track down inconsistent performance?
Previous Message Justin Clift 2002-04-28 16:32:29 Re: Compiling 7.2 on Solaris 8: runtime error on