Specific query performance problem help requested - postgresql 7.4

From: "Brad Might" <bmight(at)storediq(dot)com>
To: <psql-performance(at)postgresql(dot)org>
Subject: Specific query performance problem help requested - postgresql 7.4
Date: 2005-05-26 15:36:51
Message-ID: E387E2E9622FDD408359F98BF183879E08DA4E@dc1.storediq.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

I am seeing vastly different performance characteristics for almost the
exact same query.
Can someone help me break this down and figure out why the one query
takes so much longer than the other?

Looking at the explain analyze output, I see that the loops value on the
innermost index scan when bucket = 3 is way out of wack with the others.

Here's the query...the only thing that changes from run to run is the
bucket number.

For some strange reason the id and bucket types are bigint although they
do not need to be.

Shared buffers is 48000
sort_mem is 32767

This is on 7.4.2 I'm seeing the same thing on 7.4.7 as well.

explain analyze
select
t0.filename,
t2.filename as parentname,
t0.st_atime,
t0.size,
t0.ownernameid,
t0.filetypeid,
t0.groupnameid,
t0.groupnameid,
t0.id,
t0.filename
from Nodes_215335885080_1114059806 as t0 inner join
fileftypebkt_215335885080_1114059806 as t1 on t0.id=t1.fileid inner join

dirs_215335885080_1114059806 as t2 on t0.parentnameid=t2.filenameid
where t1.bucket=3 order by t0.filename asc offset 0 limit 25

Here's the bucket distribution..i have clustered the index on the bucket
value.

bucket | count
--------+---------
9 | 13420
8 | 274053
7 | 2187261
6 | 1395
5 | 45570
4 | 2218830
3 | 16940
2 | 818405
1 | 4092
(9 rows)

And the explain analyzes for bucket values of 3 7 and 8


QUERY PLAN

------------------------------------------------------------------------
------------------------------------------------------------------------
--------------------------------------------------------------------
Limit (cost=0.00..18730.19 rows=25 width=112) (actual
time=89995.190..400863.350 rows=25 loops=1)
-> Nested Loop (cost=0.00..48333634.41 rows=64513 width=112)
(actual time=89995.172..400863.043 rows=25 loops=1)
-> Nested Loop (cost=0.00..47944899.32 rows=64513 width=69)
(actual time=89971.894..400484.701 rows=25 loops=1)
-> Index Scan using
xnodes_215335885080_1114059806_filename on nodes_215335885080_1114059806
t0 (cost=0.00..19090075.03 rows=4790475 width=69) (actual
time=0.074..319084.540 rows=713193 loops=1)
-> Index Scan using
xfileftypebkt_215335885080_1114059806_fileid on
fileftypebkt_215335885080_1114059806 t1 (cost=0.00..6.01 rows=1
width=8) (actual time=0.101..0.101 rows=0 loops=713193)
Index Cond: ("outer".id = t1.fileid)
Filter: (bucket = 3)
-> Index Scan using xdirs_215335885080_1114059806_filenameid
on dirs_215335885080_1114059806 t2 (cost=0.00..6.01 rows=1 width=59)
(actual time=15.096..15.103 rows=1 loops=25)
Index Cond: ("outer".parentnameid = t2.filenameid)
Total runtime: 400863.747 ms
(10 rows)


QUERY PLAN

------------------------------------------------------------------------
------------------------------------------------------------------------
--------------------------------------------------------------
Limit (cost=0.00..785.15 rows=25 width=112) (actual
time=173.935..552.075 rows=25 loops=1)
-> Nested Loop (cost=0.00..59327691.44 rows=1889045 width=112)
(actual time=173.917..551.763 rows=25 loops=1)
-> Nested Loop (cost=0.00..47944899.32 rows=1889045 width=69)
(actual time=151.198..303.463 rows=25 loops=1)
-> Index Scan using
xnodes_215335885080_1114059806_filename on nodes_215335885080_1114059806
t0 (cost=0.00..19090075.03 rows=4790475 width=69) (actual
time=0.225..82.328 rows=6930 loops=1)
-> Index Scan using
xfileftypebkt_215335885080_1114059806_fileid on
fileftypebkt_215335885080_1114059806 t1 (cost=0.00..6.01 rows=1
width=8) (actual time=0.019..0.019 rows=0 loops=6930)
Index Cond: ("outer".id = t1.fileid)
Filter: (bucket = 7)
-> Index Scan using xdirs_215335885080_1114059806_filenameid
on dirs_215335885080_1114059806 t2 (cost=0.00..6.01 rows=1 width=59)
(actual time=9.894..9.901 rows=1 loops=25)
Index Cond: ("outer".parentnameid = t2.filenameid)
Total runtime: 552.519 ms
(10 rows)


QUERY PLAN

------------------------------------------------------------------------
------------------------------------------------------------------------
-----------------------------------------------------------
Limit (cost=0.00..18730.19 rows=25 width=112) (actual
time=81.271..330.404 rows=25 loops=1)
-> Nested Loop (cost=0.00..48333634.41 rows=64513 width=112)
(actual time=81.254..330.107 rows=25 loops=1)
-> Nested Loop (cost=0.00..47944899.32 rows=64513 width=69)
(actual time=4.863..8.164 rows=25 loops=1)
-> Index Scan using
xnodes_215335885080_1114059806_filename on nodes_215335885080_1114059806
t0 (cost=0.00..19090075.03 rows=4790475 width=69) (actual
time=0.204..2.576 rows=75 loops=1)
-> Index Scan using
xfileftypebkt_215335885080_1114059806_fileid on
fileftypebkt_215335885080_1114059806 t1 (cost=0.00..6.01 rows=1
width=8) (actual time=0.054..0.057 rows=0 loops=75)
Index Cond: ("outer".id = t1.fileid)
Filter: (bucket = 8)
-> Index Scan using xdirs_215335885080_1114059806_filenameid
on dirs_215335885080_1114059806 t2 (cost=0.00..6.01 rows=1 width=59)
(actual time=12.841..12.847 rows=1 loops=25)
Index Cond: ("outer".parentnameid = t2.filenameid)
Total runtime: 330.835 ms
(10 rows)

Thanks,

brad

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2005-05-26 16:53:54 Re: Optimising queries involving unions
Previous Message Sam Mason 2005-05-26 15:22:03 Optimising queries involving unions