Thread: index scan forward vs backward = speed difference of 357X slower!

index scan forward vs backward = speed difference of 357X slower!

From
Kevin Traster
Date:

PostgreSQL 9.1.2 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.1.2 20080704 (Red Hat 4.1.2-51), 64-bit

Dedicated DB server

4GB ram

Shared_Buffers = 1 GB

Effective_cache_size = 3GB

Work_mem = 32GB

Analyze done

Queries ran multiple times, same differences/results

Default Statistics = 1000


Query (5366ms) :

explain analyze select initcap (fullname), initcap(issuer),upper(rsymbol), initcap(industry), activity,to_char(shareschange,'FM9,999,999,999,999,999'),sharespchange ||+ E'\%' from changes where activity in (4,5) and mfiled >= (select max(mfiled) from changes) order by shareschange asc limit 15 


Slow Ascending explain Analyze:

http://explain.depesz.com/s/zFz


Query (15ms) :

explain analyze select initcap (fullname), initcap(issuer),upper(rsymbol), initcap(industry), activity,to_char(shareschange,'FM9,999,999,999,999,999'),sharespchange ||+ E'\%' from changes where activity in (4,5) and mfiled >= (select max(mfiled) from changes) order by shareschange desc limit 15 


Fast descending explain analyze:

http://explain.depesz.com/s/OP7



The index: changes_shareschange is a btree index created with default ascending order


The query plan and estimates are exactly the same, except desc has index scan backwards instead of index scan for changes_shareschange.


Yet, actual runtime performance is different by 357x slower for the ascending version instead of descending.


Why and how do I fix it?




Re: index scan forward vs backward = speed difference of 357X slower!

From
Rural Hunter
Date:
what's the size of the index? is it too big to fit in shared_buffers? maybe the firt 15 rows by asc order are in
bufferbut the ones of desc order are not, while your disk IO is very slow?<br /> btw, your mem configuration of
work_menis very strange. <br /><br /> 于 2012/2/8 0:49, Kevin Traster 写道: <blockquote
cite="mid:CAC7CH7GB2Yi1VqQ9hy8Yex0avGvgLfvQkHabFGfmZa1WRU3X+A@mail.gmail.com"type="cite"><span
style="border-collapse:collapse"><pstyle="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font
face="arial,sans-serif">PostgreSQL 9.1.2 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.1.2 20080704 (Red Hat
4.1.2-51),64-bit</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif">DedicatedDB server</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font
face="arial,sans-serif">4GB ram</font><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif">Shared_Buffers
=1 GB</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif">Effective_cache_size= 3GB</font><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif">Work_mem =
32GB</font><pstyle="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif">Analyzedone</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font
face="arial,sans-serif">Queries ran multiple times, same differences/results</font><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif">Default
Statistics= 1000</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif"><br/></font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif">Query(5366ms) :</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="color:rgb(11,55,77);font-family:inherit;background-color:rgb(255,255,255);font-size:12px;text-align:left">explain
analyzeselect initcap (fullname), initcap(issuer),upper(rsymbol), initcap(industry),
activity,to_char(shareschange,'FM9,999,999,999,999,999'),sharespchange||+ E'\%' from changes where activity in (4,5)
andmfiled >= (select max(mfiled) from changes) order by shareschange asc limit 15 </span><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="color:rgb(11,55,77);font-family:inherit;background-color:rgb(255,255,255);font-size:12px;text-align:left"><br
/></span><pstyle="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px">SlowAscending explain Analyze:<p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><ahref="http://explain.depesz.com/s/zFz"
moz-do-not-send="true">http://explain.depesz.com/s/zFz</a><brclass="Apple-interchange-newline" /><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="color:rgb(11,55,77);font-family:inherit;background-color:rgb(255,255,255);font-size:12px;text-align:left"><br
/></span><pstyle="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif">Query(15ms) :</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="color:rgb(11,55,77);font-family:inherit;background-color:rgb(255,255,255);font-size:12px;text-align:left">explain
analyzeselect initcap (fullname), initcap(issuer),upper(rsymbol), initcap(industry),
activity,to_char(shareschange,'FM9,999,999,999,999,999'),sharespchange||+ E'\%' from changes where activity in (4,5)
andmfiled >= (select max(mfiled) from changes) order by shareschange desc limit 15 </span><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><br/><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif">Fast descending
explainanalyze:</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><a
href="http://explain.depesz.com/s/OP7"moz-do-not-send="true">http://explain.depesz.com/s/OP7</a><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><br/><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="font-family:arial,sans-serif;font-size:13.2px"><br/></span><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="font-family:arial,sans-serif;font-size:13.2px">Theindex: </span><span
style="font-family:arial,sans-serif;font-size:13px">changes_shareschange</span><span
style="background-color:rgb(255,255,255);color:rgb(11,55,77);font-family:inherit;font-size:12px;text-align:left">is
a </span><spanstyle="font-family:arial,sans-serif;font-size:13.2px">btree index created with default ascending
order</span><pstyle="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="font-family:arial,sans-serif;font-size:13.2px"><br/></span><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="font-family:arial,sans-serif;font-size:13.2px">Thequery plan and estimates are exactly the same, except desc has
indexscan backwards instead of index scan for changes_shareschange.</span><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><span
style="font-family:arial,sans-serif;font-size:13.2px"><br/></span><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif">Yet, actual
runtime performance isdifferent by 357x slower for the ascending version instead of descending.</font><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif"><br /></font><p
style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><fontface="arial, sans-serif">Why and how do
Ifix it?</font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif"><br/></font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif"><br/></font><p style="margin-top:0px;margin-right:0px;margin-bottom:0px;margin-left:0px"><font face="arial,
sans-serif"><br/></font></span></blockquote><br /> 

Re: index scan forward vs backward = speed difference of 357X slower!

From
Rural Hunter
Date:
what's the size of the index? is it too big to fit in shared_buffers?
maybe the firt 15 rows by asc order are in buffer but the ones of desc
order are not, while your disk IO is very slow?
btw, your mem configuration of work_men is very strange.

于 2012/2/8 0:49, Kevin Traster 写道:
>
> PostgreSQL 9.1.2 on x86_64-unknown-linux-gnu, compiled by gcc (GCC)
> 4.1.2 20080704 (Red Hat 4.1.2-51), 64-bit
>
> Dedicated DB server
>
> 4GB ram
>
> Shared_Buffers = 1 GB
>
> Effective_cache_size = 3GB
>
> Work_mem = 32GB
>
> Analyze done
>
> Queries ran multiple times, same differences/results
>
> Default Statistics = 1000
>
>
> Query (5366ms) :
>
> explain analyze select initcap (fullname),
> initcap(issuer),upper(rsymbol), initcap(industry),
> activity,to_char(shareschange,'FM9,999,999,999,999,999'),sharespchange
> ||+ E'\%' from changes where activity in (4,5) and mfiled >= (select
> max(mfiled) from changes) order by shareschange asc limit 15
>
>
> Slow Ascending explain Analyze:
>
> http://explain.depesz.com/s/zFz
>
>
>
> Query (15ms) :
>
> explain analyze select initcap (fullname),
> initcap(issuer),upper(rsymbol), initcap(industry),
> activity,to_char(shareschange,'FM9,999,999,999,999,999'),sharespchange
> ||+ E'\%' from changes where activity in (4,5) and mfiled >= (select
> max(mfiled) from changes) order by shareschange desc limit 15
>
>
> Fast descending explain analyze:
>
> http://explain.depesz.com/s/OP7
>
>
>
> The index: changes_shareschange is a btree index created with default
> ascending order
>
>
> The query plan and estimates are exactly the same, except desc has
> index scan backwards instead of index scan for changes_shareschange.
>
>
> Yet, actual runtime performance is different by 357x slower for the
> ascending version instead of descending.
>
>
> Why and how do I fix it?
>
>
>
>



Re: index scan forward vs backward = speed difference of 357X slower!

From
Tom Lane
Date:
Kevin Traster <ktraster@freshgrillfoods.com> writes:
> The query plan and estimates are exactly the same, except desc has index
> scan backwards instead of index scan for changes_shareschange.
> Yet, actual runtime performance is different by 357x slower for the
> ascending version instead of descending.

Apparently, there are some rows passing the filter condition that are
close to the end of the index, but none that are close to the start.
So it takes a lot longer to find the first 15 matches in one case than
the other.  You haven't shown us the index definition, but I gather from
the fact that the scan condition is just a Filter (not an Index Cond)
that the index itself doesn't offer any clue as to whether a given row
meets those conditions.  So this plan is going to be doing a lot of
random-access heap probes until it finds a match.

> Why and how do I fix it?

Probably, you need an index better suited to the query condition.
If you have one and the problem is that the planner's not choosing it,
then this is going to take more information to resolve.

            regards, tom lane

Re: index scan forward vs backward = speed difference of 357X slower!

From
Kevin Traster
Date:
Typo: Work_mem = 32 MB

The definition for both column and index:
 shareschange                  | numeric |
"changes_shareschange" btree (shareschange)

Index created using: CREATE INDEX changes_shareschange ON changes(shareschange);

The entire table is created nightly (and analyzed afterwords), and
used only for reporting - there no updates/deletes, so there shouldn't
be any dead rows in the table.
Likewise, there is no nulls in the column.

Please elaborate on:

>You haven't shown us the index definition, but I gather from
> the fact that the scan condition is just a Filter (not an Index Cond)
> that the index itself doesn't offer any clue as to whether a given row
> meets those conditions

Are you saying it is the retrieval of the physically random located 15
rows to meet the ascending condition that causes the 5 sec difference?
The table is not-clustered, so it is "random" for descending also.

The condition is shareschange ascending, I have an index for that
condition and the planner is using it.

What else can I look at?



On Wed, Feb 8, 2012 at 11:31 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Kevin Traster <ktraster@freshgrillfoods.com> writes:
>> The query plan and estimates are exactly the same, except desc has index
>> scan backwards instead of index scan for changes_shareschange.
>> Yet, actual runtime performance is different by 357x slower for the
>> ascending version instead of descending.
>
> Apparently, there are some rows passing the filter condition that are
> close to the end of the index, but none that are close to the start.
> So it takes a lot longer to find the first 15 matches in one case than
> the other.  You haven't shown us the index definition, but I gather from
> the fact that the scan condition is just a Filter (not an Index Cond)
> that the index itself doesn't offer any clue as to whether a given row
> meets those conditions.  So this plan is going to be doing a lot of
> random-access heap probes until it finds a match.
>
>> Why and how do I fix it?
>
> Probably, you need an index better suited to the query condition.
> If you have one and the problem is that the planner's not choosing it,
> then this is going to take more information to resolve.
>
>                        regards, tom lane

Re: index scan forward vs backward = speed difference of 357X slower!

From
Merlin Moncure
Date:
On Wed, Feb 8, 2012 at 1:58 PM, Kevin Traster
<ktraster@freshgrillfoods.com> wrote:
> Typo: Work_mem = 32 MB
>
> The definition for both column and index:
>  shareschange                  | numeric |
> "changes_shareschange" btree (shareschange)
>
> Index created using: CREATE INDEX changes_shareschange ON changes(shareschange);
>
> The entire table is created nightly (and analyzed afterwords), and
> used only for reporting - there no updates/deletes, so there shouldn't
> be any dead rows in the table.
> Likewise, there is no nulls in the column.
>
> Please elaborate on:
>
>>You haven't shown us the index definition, but I gather from
>> the fact that the scan condition is just a Filter (not an Index Cond)
>> that the index itself doesn't offer any clue as to whether a given row
>> meets those conditions
>
> Are you saying it is the retrieval of the physically random located 15
> rows to meet the ascending condition that causes the 5 sec difference?
> The table is not-clustered, so it is "random" for descending also.
>
> The condition is shareschange ascending, I have an index for that
> condition and the planner is using it.

This is not a problem with dead rows, but the index is not really
satisfying your query and the database has to look through an
indeterminate amount of rows until the 'limit 15' is satisfied.  Yeah,
backwards scans are slower, especially for disk bound scans but you
also have to consider how many filter misses your have.  The smoking
gun is here:

"Index Scan Backward using changes_shareschange on changes
(cost=0.00..925150.26 rows=181997 width=98) (actual time=3.161..15.843
rows=15 loops=1)
Filter: ((activity = ANY ('{4,5}'::integer[])) AND (mfiled >= $1))"

When you see Filter: xyz, xyz is what each record has to be compared
against after the index pointed you to an area(s) in the heap.  It's
pure luck going forwards or backwards that determines how many records
you have to look through to get 15 good ones as defined by satisfying
the filter.  To prove that one way or the other you can convert your
where to a boolean returning (and bump the limit appropriately)
expression to see how many records get filtered out.

merlin

Re: index scan forward vs backward = speed difference of 357X slower!

From
Kevin Traster
Date:
> This is not a problem with dead rows, but the index is not really
> satisfying your query and the database has to look through an
> indeterminate amount of rows until the 'limit 15' is satisfied.  Yeah,
> backwards scans are slower, especially for disk bound scans but you
> also have to consider how many filter misses your have.  The smoking
> gun is here:
>
> "Index Scan Backward using changes_shareschange on changes
> (cost=0.00..925150.26 rows=181997 width=98) (actual time=3.161..15.843
> rows=15 loops=1)
> Filter: ((activity = ANY ('{4,5}'::integer[])) AND (mfiled >= $1))"
>
> When you see Filter: xyz, xyz is what each record has to be compared
> against after the index pointed you to an area(s) in the heap.  It's
> pure luck going forwards or backwards that determines how many records
> you have to look through to get 15 good ones as defined by satisfying
> the filter.  To prove that one way or the other you can convert your
> where to a boolean returning (and bump the limit appropriately)
> expression to see how many records get filtered out.
>
> merlin

I have indexes also on activity and mfiled (both btree) - wouldn't the
database use them? - Kevin

Re: index scan forward vs backward = speed difference of 357X slower!

From
"Kevin Grittner"
Date:
Kevin Traster <ktraster@freshgrillfoods.com> wrote:

> I have indexes also on activity and mfiled (both btree) - wouldn't
> the database use them? - Kevin

It will use them if they are part of the plan which had the lowest
cost when it compared the costs of all possible plans.

You haven't really shown us the schema, so there's more guesswork
involved in trying to help you than there could be.  This page might
be worth reviewing:

http://wiki.postgresql.org/wiki/SlowQueryQuestions

In particular, if there are indexes that aren't being used which you
think should be, there is a good chance that either there is a type
mismatch or your costing factors may need adjustment.

-Kevin