Обсуждение: 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