|
Home > Archive > PostgreSQL Performance > March 2006 > Index scan startup time
You are viewing an archived Text-only version of the thread.
To view this thread in it's original format and/or if you want to reply to
this thread please [click here]
| Author |
Index scan startup time
|
|
| Peter Eisentraut 2006-03-30, 7:33 am |
| [Apologies if this already went through. I don't see it in the archives.]
Normally one expects that an index scan would have a startup time of nearly
zero. Can anyone explain this:
EXPLAIN ANALYZE select activity_id from activity where state in (10000, 10001)
order by activity_id limit 100;
QUERY PLAN
Limit (cost=0.00..622.72 rows=100 width=8) (actual
time=207356.054..207356.876 rows=100 loops=1)
-> Index Scan using activity_pk on activity (cost=0.00..40717259.91
rows=6538650 width=8) (actual time=207356.050..207356.722 rows=100 loops=1)
Filter: ((state = 10000) OR (state = 10001))
Total runtime: 207357.000 ms
The table has seen VACUUM FULL and REINDEX before this.
The plan choice and the statistics look right, but why does it take 3 minutes
before doing anything? Or is the measurement of the actual start time
inaccurate? This is quite reproducible, so it's not just a case of a
temporary I/O bottleneck, say.
(PostgreSQL 8.0.3)
--
Peter Eisentraut
http://developer.postgresql.org/~petere/
---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo@postgresql
.org so that your
message can get through to the mailing list cleanly
| |
| Steinar H. Gunderson 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 01:59:10PM +0200, Peter Eisentraut wrote:
> EXPLAIN ANALYZE select activity_id from activity where state in (10000, 10001)
> order by activity_id limit 100;
>
> QUERY PLAN
>
> Limit (cost=0.00..622.72 rows=100 width=8) (actual
> time=207356.054..207356.876 rows=100 loops=1)
> -> Index Scan using activity_pk on activity (cost=0.00..40717259.91
> rows=6538650 width=8) (actual time=207356.050..207356.722 rows=100 loops=1)
> Filter: ((state = 10000) OR (state = 10001))
> Total runtime: 207357.000 ms
>
> The table has seen VACUUM FULL and REINDEX before this.
The index scan is by activity_id, not by state. Do you have an index on state
at all?
/* Steinar */
--
Homepage: http://www.sesse.net/
---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?
http://archives.postgresql.org
| |
| Michael Stone 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 01:59:10PM +0200, Peter Eisentraut wrote:
>The table has seen VACUUM FULL and REINDEX before this.
But no analyze?
Mike Stone
---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?
http://www.postgresql.org/docs/faq
| |
| Peter Eisentraut 2006-03-30, 7:33 am |
| Am Donnerstag, 30. März 2006 14:02 schrieb Steinar H. Gunderson:
> On Thu, Mar 30, 2006 at 01:59:10PM +0200, Peter Eisentraut wrote:
>
> The index scan is by activity_id, not by state. Do you have an index on
> state at all?
There is an index on state as well but the column is not selective enough.
--
Peter Eisentraut
http://developer.postgresql.org/~petere/
---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings
| |
| Peter Eisentraut 2006-03-30, 7:33 am |
| Am Donnerstag, 30. März 2006 14:06 schrieb Michael Stone:
> On Thu, Mar 30, 2006 at 01:59:10PM +0200, Peter Eisentraut wrote:
>
> But no analyze?
ANALYZE as well, but the plan choice is not the point anyway.
--
Peter Eisentraut
http://developer.postgresql.org/~petere/
---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?
http://archives.postgresql.org
| |
| Steinar H. Gunderson 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 02:23:53PM +0200, Peter Eisentraut wrote:
> There is an index on state as well but the column is not selective enough.
Well, it's logical enough; it scans along activity_id until it finds one with
state=10000 or state=10001. You obviously have a _lot_ of records with low
activity_id and state none of these two, so Postgres needs to scan all those
records before it founds 100 it can output. This is the “startup cost” you're
seeing.
/* Steinar */
--
Homepage: http://www.sesse.net/
---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend
| |
| Markus Schaber 2006-03-30, 7:33 am |
| Hi, Peter,
Peter Eisentraut wrote:
> ANALYZE as well, but the plan choice is not the point anyway.
Maybe you could add a combined Index on activity_id and state, or (if
you use this kind of query more often) a conditional index on
activity_id where state in (10000,10001).
Btw, PostgreSQL 8.1 could AND two bitmap index scans on the activity and
state indices, and get the result faster (i presume).
Markus
--
Markus Schaber | Logical Tracking&Tracing International AG
Dipl. Inf. | Software Development GIS
Fight against software patents in EU! www.ffii.org www.nosoftwarepatents.org
---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend
| |
| Michael Stone 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 02:31:34PM +0200, Steinar H. Gunderson wrote:
>Well, it's logical enough; it scans along activity_id until it finds one with
>state=10000 or state=10001. You obviously have a _lot_ of records with low
>activity_id and state none of these two, so Postgres needs to scan all those
>records before it founds 100 it can output. This is the “startup cost” you're
>seeing.
Yes. And the estimates are bad enough (orders of magnitude) that I can't
help but wonder whether pg could come up with a better plan with better
statistics:
[color=darkred]
Mike Stone
---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?
http://archives.postgresql.org
| |
| Steinar H. Gunderson 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 07:42:53AM -0500, Michael Stone wrote:[color=darkred
]
> Yes. And the estimates are bad enough (orders of magnitude) that I can't
> help but wonder whether pg could come up with a better plan with better
> statistics:
>
Isn't the rows=100 here because of the LIMIT?
/* Steinar */
--
Homepage: http://www.sesse.net/
---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings
| |
| Peter Eisentraut 2006-03-30, 7:33 am |
| Am Donnerstag, 30. März 2006 14:31 schrieb Steinar H. Gunderson:
> Well, it's logical enough; it scans along activity_id until it finds one
> with state=10000 or state=10001. You obviously have a _lot_ of records with
> low activity_id and state none of these two, so Postgres needs to scan all
> those records before it founds 100 it can output. This is the “startup
> cost” you're seeing.
The startup cost is the cost until the plan is set up to start outputting
rows. It is not the time until the first row is found.
--
Peter Eisentraut
http://developer.postgresql.org/~petere/
---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster
| |
| Steinar H. Gunderson 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 02:59:02PM +0200, Peter Eisentraut wrote:
> The startup cost is the cost until the plan is set up to start outputting
> rows. It is not the time until the first row is found.
Well, point, my terminology was wrong. Still, what you're seeing is endless
scanning for the first row. I don't know your distribution, but are you
really sure state wouldn't have better selectivity?
/* Steinar */
--
Homepage: http://www.sesse.net/
---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?
http://www.postgresql.org/docs/faq
| |
| Michael Stone 2006-03-30, 7:33 am |
| On Thu, Mar 30, 2006 at 02:51:47PM +0200, Steinar H. Gunderson wrote:
>On Thu, Mar 30, 2006 at 07:42:53AM -0500, Michael Stone wrote:
>
>Isn't the rows=100 here because of the LIMIT?
Yes. I was looking at the other side; I thought pg could estimate how
much work it would have to do to hit the limit, but double-checking it
looks like it can't.
Mike Stone
---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match
| |
| Tom Lane 2006-03-30, 9:34 am |
| Michael Stone < mstone+postgres@math
om.us> writes:
> Yes. I was looking at the other side; I thought pg could estimate how
> much work it would have to do to hit the limit, but double-checking it
> looks like it can't.
Yes, it does, you just have to understand how to interpret the EXPLAIN
output. Peter had
Limit (cost=0.00..622.72 rows=100 width=8) (actual time=207356.054..207356.876 rows=100 loops=1)
-> Index Scan using activity_pk on activity (cost=0.00..40717259.91 rows=6538650 width=8) (actual time=207356.050..207356.722 rows=100 loops=1)
Filter: ((state = 10000) OR (state = 10001))
Total runtime: 207357.000 ms
Notice that the total cost of the LIMIT node is estimated as far less
than the total cost of the IndexScan node. That's exactly because the
planner doesn't expect the indexscan to run to completion.
The problem here appears to be a non-random correlation between state
and activity, such that the desired state values are not randomly
scattered in the activity sequence. The planner doesn't know about that
correlation and hence can't predict the poor startup time.
regards, tom lane
---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster
| |
| Peter Eisentraut 2006-03-30, 9:34 am |
| Tom Lane wrote:
> The problem here appears to be a non-random correlation between state
> and activity, such that the desired state values are not randomly
> scattered in the activity sequence. The planner doesn't know about
> that correlation and hence can't predict the poor startup time.
So from when to when is the startup time (the "x" in "x..y") actually
measured? When does the clock start ticking and when does it stop?
That is what's confusing me.
--
Peter Eisentraut
http://developer.postgresql.org/~petere/
---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings
| |
| Tom Lane 2006-03-30, 9:34 am |
| Peter Eisentraut <peter_e@gmx.net> writes:
> So from when to when is the startup time (the "x" in "x..y") actually
> measured? When does the clock start ticking and when does it stop?
> That is what's confusing me.
The planner thinks of the startup time (the first estimated-cost number)
as the time before the output scan can start, eg, time to do the sort in
a sort node. EXPLAIN ANALYZE however reports the actual time until the
first output row is delivered. When you've got a filter applied to the
node result, as in this case, there can be a material difference between
the two definitions, because of the time spent scanning rows that don't
get past the filter.
regards, tom lane
---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend
| |
| Simon Riggs 2006-03-30, 11:30 am |
| On Thu, 2006-03-30 at 13:59 +0200, Peter Eisentraut wrote:
> Can anyone explain this:
>
> EXPLAIN ANALYZE select activity_id from activity where state in (10000, 10001)
> order by activity_id limit 100;
>
> QUERY PLAN
>
> Limit (cost=0.00..622.72 rows=100 width=8) (actual
> time=207356.054..207356.876 rows=100 loops=1)
> -> Index Scan using activity_pk on activity (cost=0.00..40717259.91
> rows=6538650 width=8) (actual time=207356.050..207356.722 rows=100 loops=1)
> Filter: ((state = 10000) OR (state = 10001))
> Total runtime: 207357.000 ms
>
....just adding to Tom's comments:
The interesting thing about this query is it *looks* like the index is
being used to retrieve the matching rows and so the startup time looks
wrong. However the index is being used instead of a sort to satisfy the
ORDER BY, with the state clauses being applied as after-scan filters
since those columns aren't part of the index. So the Index Scan starts
at the leftmost page and scans the whole index...
If the query had chosen a sort, the startup time would have been easily
understandable, but there's no indication from the EXPLAIN as to why the
Index Scan exists.
Perhaps it should be a TODO item to make the EXPLAIN say explicitly when
an Index Scan is being used to provide sorted output?
Best Regards, Simon Riggs
---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster
|
|
|
|
|