BUG #1851: Performance reduction from 8.0.3

Started by Steve Wormleyover 20 years ago3 messagesbugs
Jump to latest
#1Steve Wormley
steve@wormley.com

The following bug has been logged online:

Bug reference: 1851
Logged by: Steve Wormley
Email address: steve@wormley.com
PostgreSQL version: 8.1beta1
Operating system: RedHat Linux, Kernel: 2.6.12.2
Description: Performance reduction from 8.0.3
Details:

Did a dump and restore of my DB to 8.1beta1 (running concurrently with
8.0.3) and performance on the same query is about 50% slower with the beta.
Ran query twice on each instance in sequence to make sure all data was in OS
cache.

8.0.3
explain analyze select 7208,avg(data.sl),mcc,mnc from grid_geography_link
as gglink , meta_data as meta, signal_level_stats as data where data.ogc_fid
= meta.ogc_fid AND data.isvalid=true AND meta.isvalid = true AND meta.gridid
= gglink.gridid and 7208 = gglink.geographyid group by mcc,mnc;

QUERY PLAN

----------------------------------------------------------------------------
----------------------------------------------------------------------------
--------------------------------
HashAggregate (cost=36735.67..36736.24 rows=228 width=16) (actual
time=3834.630..3834.668 rows=8 loops=1)
-> Nested Loop (cost=16.19..36722.89 rows=1704 width=16) (actual
time=141.628..3526.391 rows=67824 loops=1)
-> Merge Join (cost=16.19..30737.86 rows=1766 width=16) (actual
time=141.565..1566.594 rows=68547 loops=1)
Merge Cond: ("outer".gridid = "inner".gridid)
-> Index Scan using meta_data_gridid on meta_data meta
(cost=0.00..35362.89 rows=312214 width=20) (actual time=0.103..499.071
rows=89081 loops=1)
Filter: (isvalid = true)
-> Sort (cost=16.19..16.76 rows=229 width=4) (actual
time=7.291..219.951 rows=68567 loops=1)
Sort Key: gglink.gridid
-> Index Scan using grid_geography_link_geographyid on
grid_geography_link gglink (cost=0.00..7.22 rows=229 width=4) (actual
time=0.077..3.865 rows=995 loops=1)
Index Cond: (7208 = geographyid)
-> Index Scan using signal_level_stats_pkey on signal_level_stats
data (cost=0.00..3.38 rows=1 width=16) (actual time=0.011..0.015 rows=1
loops=68547)
Index Cond: (data.ogc_fid = "outer".ogc_fid)
Filter: (isvalid = true)
Total runtime: 3834.868 ms
(14 rows)

8.1beta1:
explain analyze select 7208,avg(data.sl),mcc,mnc from grid_geography_link as
gglink , meta_data as meta, signal_level_stats as data where data.ogc_fid =
meta.ogc_fid AND data.isvalid=true AND meta.isvalid = true AND meta.gridid =
gglink.gridid and 7208 = gglink.geographyid group by mcc,mnc;

QUERY PLAN

----------------------------------------------------------------------------
----------------------------------------------------------------------------
------------------------
HashAggregate (cost=41180.34..41230.34 rows=20000 width=16) (actual
time=8834.251..8834.372 rows=8 loops=1)
-> Merge Join (cost=31059.37..37808.18 rows=449621 width=16) (actual
time=7969.032..8614.804 rows=67823 loops=1)
Merge Cond: ("outer".gridid = "inner".gridid)
-> Sort (cost=971.33..973.57 rows=896 width=4) (actual
time=7.344..10.284 rows=995 loops=1)
Sort Key: gglink.gridid
-> Bitmap Heap Scan on grid_geography_link gglink
(cost=6.13..927.39 rows=896 width=4) (actual time=0.289..3.687 rows=995
loops=1)
Recheck Cond: (7208 = geographyid)
-> Bitmap Index Scan on
grid_geography_link_geographyid (cost=0.00..6.13 rows=896 width=0) (actual
time=0.260..0.260 rows=995 loops=1)
Index Cond: (7208 = geographyid)
-> Sort (cost=30088.04..30338.95 rows=100362 width=20) (actual
time=7864.261..8124.173 rows=88143 loops=1)
Sort Key: meta.gridid
-> Hash Join (cost=8165.88..21750.54 rows=100362 width=20)
(actual time=2863.617..6363.921 rows=309036 loops=1)
Hash Cond: ("outer".ogc_fid = "inner".ogc_fid)
-> Bitmap Heap Scan on meta_data meta
(cost=1166.30..10165.86 rows=204656 width=20) (actual time=61.030..1271.910
rows=314108 loops=1)
Filter: isvalid
-> Bitmap Index Scan on meta_data_isvalid
(cost=0.00..1166.30 rows=204656 width=0) (actual time=58.417..58.417
rows=314108 loops=1)
Index Cond: (isvalid = true)
-> Hash (cost=6497.77..6497.77 rows=200724 width=16)
(actual time=2802.385..2802.385 rows=394772 loops=1)
-> Bitmap Heap Scan on signal_level_stats data
(cost=1144.53..6497.77 rows=200724 width=16) (actual time=71.196..1458.890
rows=394772 loops=1)
Filter: isvalid
-> Bitmap Index Scan on
signal_level_stats_isvalid (cost=0.00..1144.53 rows=200724 width=0) (actual
time=69.892..69.892 rows=394772 loops=1)
Index Cond: (isvalid = true)
Total runtime: 8884.601 ms
(23 rows)

(Of course, I was hoping with the new bitmaps things would be faster.)

#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: Steve Wormley (#1)
Re: BUG #1851: Performance reduction from 8.0.3

"Steve Wormley" <steve@wormley.com> writes:

Did a dump and restore of my DB to 8.1beta1 (running concurrently with
8.0.3) and performance on the same query is about 50% slower with the beta.
Ran query twice on each instance in sequence to make sure all data was in OS
cache.

Did you vacuum analyze (or at least analyze) both databases? The
rowcount estimates seem quite a bit different, which suggests the
two planners aren't working with the same stats.

regards, tom lane

#3Steve Wormley
steve@wormley.com
In reply to: Tom Lane (#2)
Re: BUG #1851: Performance reduction from 8.0.3

On 2005-08-26 16:17, "Tom Lane" <tgl@sss.pgh.pa.us> wrote:

"Steve Wormley" <steve@wormley.com> writes:

Did a dump and restore of my DB to 8.1beta1 (running concurrently with
8.0.3) and performance on the same query is about 50% slower with the beta.
Ran query twice on each instance in sequence to make sure all data was in OS
cache.

Did you vacuum analyze (or at least analyze) both databases? The
rowcount estimates seem quite a bit different, which suggests the
two planners aren't working with the same stats.

Sigh, I swore I remembered to at least analyze both, but I guess not. After
vacuum analyze 8.1beta1 is fine and happy and using a virtually identical
plan and coming in a few hundred milliseconds faster.

Thanks,
-Steve Wormley