Обсуждение: Slow query-plan generation (fast query) PG 9.2

Hi.

I have a strange situation where generating the query plan takes 6s+ and
executing it takes very little time.

2013-09-03 09:19:38.726 db=# explain select table.id  from db.table left
join db.tablepro on db.id = tablepro.table_id where table.fts @@
to_tsquery('english','q12345') ;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Nested Loop Left Join  (cost=43.71..12711.39 rows=2930 width=4)
   ->  Bitmap Heap Scan on sequence  (cost=43.71..4449.10 rows=2930 width=4)
         Recheck Cond: (fts @@ '''q12345'''::tsquery)
         ->  Bitmap Index Scan on table_gin_idx  (cost=0.00..42.98
rows=2930 width=0)
               Index Cond: (fts @@ '''q12345'''::tsquery)
   ->  Index Only Scan using tablepro_seqid_idx on tablepro
(cost=0.00..2.81 rows=1 width=4)
         Index Cond: (tablepro_id = table.id)
(7 rows)

Time: 10458.404 ms


The query gives 4 rows out of 50.000.000, so the query-plan is actually
correct and as expected.

Any suggestions?

Jesper

On 09/03/2013 03:46 PM, jesper@krogh.cc wrote:
> Hi.
>
> I have a strange situation where generating the query plan takes 6s+ and
> executing it takes very little time.

How do you determine that it's planning time at fault here?

Please take separate timing for:

PREPARE testq AS select table.id  from db.table left
join db.tablepro on db.id = tablepro.table_id where table.fts @@
to_tsquery('english','q12345') ;

and then:

EXPLAIN ANALYZE EXECUTE testq;

--
 Craig Ringer                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services

On 09/03/2013 03:46 PM, jesper@krogh.cc wrote:

Hi.

I have a strange situation where generating the query plan takes 6s+ and
executing it takes very little time.

How do you determine that it's planning time at fault here?

Not that I'm sure, but the timing I send were only for "explain" not "explain analyze". The database is constantly updating and at the moment i cannot reproduce it any more. But at the time I picked the numbers it were very reproducible.. (tried 10+ times over 15 minutes).

Please take separate timing for: PREPARE testq AS select table.id from db.table left join db.tablepro on db.id = tablepro.table_id where table.fts @@ to_tsquery('english','q12345') ; and then: EXPLAIN ANALYZE EXECUTE testq;

I'll try to do that if i see the problem re-occour. I'm just very interested in what explain then does if it is not only the time for the query plan. When I did try the "PREPARE / EXECUTE" dance as you described .. i didnt see the prepare state take time, which seems to be consistent with that the planning time is in the EXECUTE step according to the documentation.

--
Jesper

On Tue, Sep 3, 2013 at 2:34 PM, Jesper Krogh <jesper@krogh.cc> wrote:
> On 03/09/13 09:47, Craig Ringer wrote:
>
> On 09/03/2013 03:46 PM, jesper@krogh.cc wrote:
>
> Hi.
>
> I have a strange situation where generating the query plan takes 6s+ and
> executing it takes very little time.
>
> How do you determine that it's planning time at fault here?
>
> Not that I'm sure, but the timing I send were only for "explain" not
> "explain analyze". The database is constantly updating and at the moment i
> cannot reproduce it any more. But at the time I picked the numbers it were
> very reproducible.. (tried 10+ times over 15 minutes).

Maybe your explain was blocking on locks?

merlin