Thread: 8.4.7, incorrect estimate
Howdy. We've got a query that takes less than a second unless we add a
"order by" to it, after which it takes 40 seconds. Here's the query:
select page_number, ps_id, ps_page_id from ps_page where ps_page_id in
(select ps_page_id from documents_ps_page where document_id in (select
document_id from temp_doc_ids)) order by ps_page_id;
The parts of the schema used in this query:
Table "public.ps_page"
Column | Type | Modifiers
-------------+---------+--------------------------------------------------------------
ps_page_id | integer | not null default
nextval('ps_page_ps_page_id_seq'::regclass)
ps_id | integer | not null
page_number | integer | not null
Indexes:
"ps_page_pkey" PRIMARY KEY, btree (ps_page_id)
"ps_page_ps_id_key" UNIQUE, btree (ps_id, page_number)
Table "public.documents_ps_page"
Column | Type | Modifiers
-------------+---------+-----------
document_id | text | not null
ps_page_id | integer | not null
Indexes:
"documents_ps_page_pkey" PRIMARY KEY, btree (document_id, ps_page_id)
"documents_ps_page_ps_page_id_idx" btree (ps_page_id)
temp_doc_ids (temporary table):
document_id text not null
The query with the "order by" (slow):
explain analyze select page_number, ps_id, ps_page_id from ps_page where
ps_page_id in (select ps_page_id from documents_ps_page where
document_id in (select document_id from temp_document_ids)) order by
ps_page_id
Merge Semi Join (cost=212570.02..3164648.31 rows=34398932
width=12) (actual time=54749.281..54749.295 rows=5 loops=1)
Merge Cond: (ps_page.ps_page_id = documents_ps_page.ps_page_id)
-> Index Scan using ps_page_pkey on ps_page
(cost=0.00..2999686.03 rows=86083592 width=12) (actual
time=0.029..36659.393 rows=85591467 loops=1)
-> Sort (cost=18139.39..18152.52 rows=6255 width=4) (actual
time=0.080..0.083 rows=5 loops=1)
Sort Key: documents_ps_page.ps_page_id
Sort Method: quicksort Memory: 25kB
-> Nested Loop (cost=26.23..17808.09 rows=6255 width=4)
(actual time=0.044..0.073 rows=5 loops=1)
-> HashAggregate (cost=26.23..27.83 rows=200
width=32) (actual time=0.015..0.017 rows=5 loops=1)
-> Seq Scan on temp_document_ids
(cost=0.00..23.48 rows=1310 width=32) (actual time=0.004..0.007 rows=5
loops=1)
-> Index Scan using documents_ps_page_pkey on
documents_ps_page (cost=0.00..88.59 rows=31 width=42) (actual
time=0.009..0.010 rows=1 loops=5)
Index Cond: (documents_ps_page.document_id =
(temp_document_ids.document_id)::text)
Total runtime: 54753.028 ms
The query without the "order by" (fast):
production=> explain analyze select page_number, ps_id, ps_page_id from
ps_page where ps_page_id in (select ps_page_id from documents_ps_page
where document_id in (select document_id from temp_doc_ids));
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=17821.42..87598.71 rows=34398932 width=12) (actual
time=0.099..0.136 rows=5 loops=1)
-> HashAggregate (cost=17821.42..17871.46 rows=6255 width=4)
(actual time=0.083..0.096 rows=5 loops=1)
-> Nested Loop (cost=26.23..17808.28 rows=6255 width=4)
(actual time=0.047..0.076 rows=5 loops=1)
-> HashAggregate (cost=26.23..27.83 rows=200 width=32)
(actual time=0.014..0.015 rows=5 loops=1)
-> Seq Scan on temp_doc_ids (cost=0.00..23.48
rows=1310 width=32) (actual time=0.005..0.005 rows=5 loops=1)
-> Index Scan using documents_ps_page_pkey on
documents_ps_page (cost=0.00..88.59 rows=31 width=42) (actual
time=0.010..0.010 rows=1 loops=5)
Index Cond: (documents_ps_page.document_id =
temp_doc_ids.document_id)
-> Index Scan using ps_page_pkey on ps_page (cost=0.00..11.14
rows=1 width=12) (actual time=0.007..0.007 rows=1 loops=5)
Index Cond: (ps_page.ps_page_id = documents_ps_page.ps_page_id)
Total runtime: 0.213 ms
(10 rows)
We notice that in all cases, the plans contain some estimated row counts
that differ quite a bit from the actual row counts. We tried increasing
(from 100 to 1,000 and 10,000) the statistics targets for each of the
indexed columns, one at a time, and analyzing the table/column with each
change. This had no effect.
Postgres version 8.4.7 on AMD64, Debian Linux "wheezy" (aka "testing").
Where should we look next?
Wayne Conrad <wayne@databill.com> wrote:
> select page_number, ps_id, ps_page_id from ps_page where
> ps_page_id in (select ps_page_id from documents_ps_page where
> document_id in (select document_id from temp_doc_ids)) order by
> ps_page_id;
> [estimated rows=34398932; actual rows=5]
> We tried increasing (from 100 to 1,000 and 10,000) the statistics
> targets for each of the indexed columns, one at a time, and
> analyzing the table/column with each change. This had no effect
Ouch.
Out of curiosity, what do you get with?:
explain analyze
select
page_number,
ps_id,
ps_page_id
from ps_page p
where exists
(
select * from documents_ps_page d
where d.ps_page_id = p.ps_page_id
and exists
(select * from temp_document_ids t
where t.document_id = d.document_id)
)
order by ps_page_id
;
-Kevin
Wayne Conrad <wayne@databill.com> wrote: > -> Seq Scan on temp_doc_ids > (cost=0.00..23.48 rows=1310 width=32) > (actual time=0.005..0.005 rows=5 loops=1) Also, make sure that you run ANALYZE against your temp table right before running your query. -Kevin
"Kevin Grittner" <Kevin.Grittner@wicourts.gov> writes:
> Also, make sure that you run ANALYZE against your temp table right
> before running your query.
Yeah. It's fairly hard to credit that temp_document_ids has any stats
given the way-off estimates for it. Keep in mind that autovacuum
can't help you on temp tables: since only your own session can
access a temp table, you have to ANALYZE it explicitly if you need
the planner to have decent stats about it.
regards, tom lane
Replying to the list this time (oops)...
On 04/29/11 12:33, Kevin Grittner wrote:
> Also, make sure that you run ANALYZE against your temp table right
> before running your query.
I did that, and also added an index to it. That had no effect on the
run time, but did fix the estimate for the temporary table.
On 04/29/11 12:12, Kevin Grittner wrote:
> Out of curiosity, what do you get with?:
>
> explain analyze
> select
> page_number,
> ps_id,
> ps_page_id
> from ps_page p
> where exists
> (
> select * from documents_ps_page d
> where d.ps_page_id = p.ps_page_id
> and exists
> (select * from temp_document_ids t
> where t.document_id = d.document_id)
> )
> order by ps_page_id
Merge Semi Join (cost=186501.69..107938082.91 rows=29952777 width=12)
(actual time=242801.828..244572.318 rows=5 loops=1)
Merge Cond: (p.ps_page_id = d.ps_page_id)
-> Index Scan using ps_page_pkey on ps_page p
(cost=0.00..2995637.47 rows=86141904 width=12) (actual
time=0.052..64140.510 rows=85401688 loops=1)
-> Index Scan using documents_ps_page_ps_page_id_idx on
documents_ps_page d (cost=0.00..104384546.06 rows=37358320 width=4)
(actual time=161483.657..163254.131 rows=5 loops=1)
Filter: (alternatives: SubPlan 1 or hashed SubPlan 2)
SubPlan 1
-> Seq Scan on temp_doc_ids t (cost=0.00..1.35 rows=1
width=0) (never executed)
Filter: (document_id = $0)
SubPlan 2
-> Seq Scan on temp_doc_ids t (cost=0.00..1.34 rows=5
width=35) (actual time=0.005..0.007 rows=5 loops=1)
Total runtime: 244572.432 ms
(11 rows)
Wayne Conrad <wconrad@yagni.com> writes:
> On 04/29/11 12:12, Kevin Grittner wrote:
>> Out of curiosity, what do you get with?:
>>
>> explain analyze
>> select
>> page_number,
>> ps_id,
>> ps_page_id
>> from ps_page p
>> where exists
>> (
>> select * from documents_ps_page d
>> where d.ps_page_id = p.ps_page_id
>> and exists
>> (select * from temp_document_ids t
>> where t.document_id = d.document_id)
>> )
>> order by ps_page_id
> Merge Semi Join (cost=186501.69..107938082.91 rows=29952777 width=12)
> (actual time=242801.828..244572.318 rows=5 loops=1)
> Merge Cond: (p.ps_page_id = d.ps_page_id)
> -> Index Scan using ps_page_pkey on ps_page p
> (cost=0.00..2995637.47 rows=86141904 width=12) (actual
> time=0.052..64140.510 rows=85401688 loops=1)
> -> Index Scan using documents_ps_page_ps_page_id_idx on
> documents_ps_page d (cost=0.00..104384546.06 rows=37358320 width=4)
> (actual time=161483.657..163254.131 rows=5 loops=1)
> Filter: (alternatives: SubPlan 1 or hashed SubPlan 2)
> SubPlan 1
> -> Seq Scan on temp_doc_ids t (cost=0.00..1.35 rows=1
> width=0) (never executed)
> Filter: (document_id = $0)
> SubPlan 2
> -> Seq Scan on temp_doc_ids t (cost=0.00..1.34 rows=5
> width=35) (actual time=0.005..0.007 rows=5 loops=1)
> Total runtime: 244572.432 ms
> (11 rows)
[ pokes at that ... ] I think what you've got here is an oversight in
the convert-EXISTS-to-semijoin logic: it pulls up the outer EXISTS but
fails to recurse on it, which would be needed to convert the lower
EXISTS into a semijoin as well, which is what's needed in order to get
a non-bogus selectivity estimate for it.
I'll take a look at fixing that, but not sure if it'll be reasonable to
back-patch or not. In the meantime, you need to look into restructuring
the query to avoid nesting the EXISTS probes, if possible.
regards, tom lane
Tom Lane <tgl@sss.pgh.pa.us> wrote: > Wayne Conrad <wconrad@yagni.com> writes: >> Total runtime: 244572.432 ms > I'll take a look at fixing that, but not sure if it'll be > reasonable to back-patch or not. In the meantime, you need to > look into restructuring the query to avoid nesting the EXISTS > probes, if possible. Wayne, I think your best bet at this point may be to just (INNER) JOIN the three tables, and if there is a possibility of duplicates to use SELECT DISTINCT. -Kevin
On 05/02/11 08:11, Tom Lane wrote: > Wayne Conrad<wconrad@yagni.com> writes: >> On 04/29/11 12:12, Kevin Grittner wrote: >>> Out of curiosity, what do you get with?: >>> >>> explain analyze >>> select >>> page_number, >>> ps_id, >>> ps_page_id >>> from ps_page p >>> where exists >>> ( >>> select * from documents_ps_page d >>> where d.ps_page_id = p.ps_page_id >>> and exists >>> (select * from temp_document_ids t >>> where t.document_id = d.document_id) >>> ) >>> order by ps_page_id > >> Merge Semi Join (cost=186501.69..107938082.91 rows=29952777 width=12) >> (actual time=242801.828..244572.318 rows=5 loops=1) >> Merge Cond: (p.ps_page_id = d.ps_page_id) >> -> Index Scan using ps_page_pkey on ps_page p >> (cost=0.00..2995637.47 rows=86141904 width=12) (actual >> time=0.052..64140.510 rows=85401688 loops=1) >> -> Index Scan using documents_ps_page_ps_page_id_idx on >> documents_ps_page d (cost=0.00..104384546.06 rows=37358320 width=4) >> (actual time=161483.657..163254.131 rows=5 loops=1) >> Filter: (alternatives: SubPlan 1 or hashed SubPlan 2) >> SubPlan 1 >> -> Seq Scan on temp_doc_ids t (cost=0.00..1.35 rows=1 >> width=0) (never executed) >> Filter: (document_id = $0) >> SubPlan 2 >> -> Seq Scan on temp_doc_ids t (cost=0.00..1.34 rows=5 >> width=35) (actual time=0.005..0.007 rows=5 loops=1) >> Total runtime: 244572.432 ms >> (11 rows) > > [ pokes at that ... ] I think what you've got here is an oversight in > the convert-EXISTS-to-semijoin logic: it pulls up the outer EXISTS but > fails to recurse on it, which would be needed to convert the lower > EXISTS into a semijoin as well, which is what's needed in order to get > a non-bogus selectivity estimate for it. > > I'll take a look at fixing that, but not sure if it'll be reasonable to > back-patch or not. In the meantime, you need to look into restructuring > the query to avoid nesting the EXISTS probes, if possible. > > regards, tom lane > Tom, Thanks for looking at this. FYI, the same problem occurs when nesting "where ... in (...)" (see start of thread, or I can repost it if you want). In any case, I can make the problem go away by using another layer of temporary table to avoid the nesting. That's what I'll do for now. I'm not worried about back-patches to fix this in 8.4. We'll be upgrading this box to 9 at some point; we'll just pick up any fix when it hits 9. Best Regards, Wayne Conrad