pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
8.4.7, incorrect estimate
8+ messages / 4 participants
[nested] [flat]

* 8.4.7, incorrect estimate
@ 2011-04-29 18:24 Wayne Conrad <wayne@databill.com>
  2011-04-29 19:12 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-04-29 19:33 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
  0 siblings, 2 replies; 8+ messages in thread

From: Wayne Conrad @ 2011-04-29 18:24 UTC (permalink / raw)
  To: pgsql-performance

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?



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
@ 2011-04-29 19:12 ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-05-02 13:19   ` Re: 8.4.7, incorrect estimate Wayne Conrad <wconrad@yagni.com>
  1 sibling, 1 reply; 8+ messages in thread

From: Kevin Grittner @ 2011-04-29 19:12 UTC (permalink / raw)
  To: Wayne Conrad <wayne@databill.com>; pgsql-performance

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



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
  2011-04-29 19:12 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
@ 2011-05-02 13:19   ` Wayne Conrad <wconrad@yagni.com>
  2011-05-02 15:11     ` Re: 8.4.7, incorrect estimate Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 8+ messages in thread

From: Wayne Conrad @ 2011-05-02 13:19 UTC (permalink / raw)
  To: pgsql-performance

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)




^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
  2011-04-29 19:12 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-05-02 13:19   ` Re: 8.4.7, incorrect estimate Wayne Conrad <wconrad@yagni.com>
@ 2011-05-02 15:11     ` Tom Lane <tgl@sss.pgh.pa.us>
  2011-05-02 16:04       ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-05-02 16:14       ` Re: 8.4.7, incorrect estimate Wayne Conrad <wconrad@yagni.com>
  0 siblings, 2 replies; 8+ messages in thread

From: Tom Lane @ 2011-05-02 15:11 UTC (permalink / raw)
  To: Wayne Conrad <wconrad@yagni.com>; +Cc: pgsql-performance

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



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
  2011-04-29 19:12 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-05-02 13:19   ` Re: 8.4.7, incorrect estimate Wayne Conrad <wconrad@yagni.com>
  2011-05-02 15:11     ` Re: 8.4.7, incorrect estimate Tom Lane <tgl@sss.pgh.pa.us>
@ 2011-05-02 16:04       ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
  1 sibling, 0 replies; 8+ messages in thread

From: Kevin Grittner @ 2011-05-02 16:04 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; Wayne Conrad <wconrad@yagni.com>; +Cc: pgsql-performance

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



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
  2011-04-29 19:12 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-05-02 13:19   ` Re: 8.4.7, incorrect estimate Wayne Conrad <wconrad@yagni.com>
  2011-05-02 15:11     ` Re: 8.4.7, incorrect estimate Tom Lane <tgl@sss.pgh.pa.us>
@ 2011-05-02 16:14       ` Wayne Conrad <wconrad@yagni.com>
  1 sibling, 0 replies; 8+ messages in thread

From: Wayne Conrad @ 2011-05-02 16:14 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance

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



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
@ 2011-04-29 19:33 ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
  2011-04-29 20:58   ` Re: 8.4.7, incorrect estimate Tom Lane <tgl@sss.pgh.pa.us>
  1 sibling, 1 reply; 8+ messages in thread

From: Kevin Grittner @ 2011-04-29 19:33 UTC (permalink / raw)
  To: Wayne Conrad <wayne@databill.com>; pgsql-performance

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



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: 8.4.7, incorrect estimate
  2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
  2011-04-29 19:33 ` Re: 8.4.7, incorrect estimate Kevin Grittner <Kevin.Grittner@wicourts.gov>
@ 2011-04-29 20:58   ` Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 0 replies; 8+ messages in thread

From: Tom Lane @ 2011-04-29 20:58 UTC (permalink / raw)
  To: Kevin Grittner <Kevin.Grittner@wicourts.gov>; +Cc: Wayne Conrad <wayne@databill.com>; pgsql-performance

"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



^ permalink  raw  reply  [nested|flat] 8+ messages in thread


end of thread, other threads:[~2011-05-02 16:14 UTC | newest]

Thread overview: 8+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2011-04-29 18:24 8.4.7, incorrect estimate Wayne Conrad <wayne@databill.com>
2011-04-29 19:12 ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
2011-05-02 13:19   ` Wayne Conrad <wconrad@yagni.com>
2011-05-02 15:11     ` Tom Lane <tgl@sss.pgh.pa.us>
2011-05-02 16:04       ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
2011-05-02 16:14       ` Wayne Conrad <wconrad@yagni.com>
2011-04-29 19:33 ` Kevin Grittner <Kevin.Grittner@wicourts.gov>
2011-04-29 20:58   ` Tom Lane <tgl@sss.pgh.pa.us>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox