Thread: select vs cursor/fetch speed disparity

Hi folks,

I have a strange disparity between a query that is run as a
straight select and the same query via a cursor.  I hope I can
jog someone's memory with the description as I have been unable
to create a sanitized and/or reduced data set & schema that will
reproduce this ... so far. :-(

Running on Ubuntu 10.04 LTS fully updated, PG 8.4.8 and the machine
is no slouch.

I have the following tables and select that express the 'shape' of
the query while they don't actually produce the problem (names and
faces changed to protect the innocent):

===================================================================
create table parent (
    uid         serial8 NOT NULL primary key,
    bits        int8 NOT NULL,
    status      integer NOT NULL
);

create table subs (
    uid         serial8 NOT NULL primary key,
    bits        int8 NOT NULL,
    parent      int8 NOT NULL,
    name        varchar(127) NOT NULL
);

select p.uid, p.status
  from parent p
  where (p.bits & 1) = 0 and
        (p.status in ( 5,8,9,10,11,14)) and
        (p.uid in (select s.parent
                     from subs s
                     where (s.bits & 1) = 0 and
                            s.parent != -1  and
                            lower(s.name) like lower('%xyz%')
                  )
        )
  order by p.uid desc;
===================================================================

(The tables above represent a much reduced table 'width' as they have
many more fields in our DB.)

When I run the query above (which is actually machine generated and
identical to the one causing the issue) on our data-set as a simple
'select' the query takes ~75ms according to \timing.

When I run the following sequence:
    start transaction;
    declare xyz cursor for (the above select)
    fetch xyz;
    rollback;

the 'fetch' takes ~47.3 seconds (i.e. ~47300ms).

In our system the 'parent' table only has ~11k rows and the 'subs'
table only has ~60k rows.

One note that may be important is that the PG backend process that
is running the fetch pegs the CPU it is running on at 100% during
the entire running time for the operation.  (The machine has dual
quad core Opterons & 32GB of RAM.)

I sure hope this reminds someone of some problem I wasn't able to
find in the archives.  In the meantime I will be working on a test
case that reproduces the problem.

TIA.

Bosco.

Bosco Rama <postgres@boscorama.com> writes:
> I have a strange disparity between a query that is run as a
> straight select and the same query via a cursor.  I hope I can
> jog someone's memory with the description as I have been unable
> to create a sanitized and/or reduced data set & schema that will
> reproduce this ... so far. :-(

Cursors are biased towards fast-start plans on the theory that you
may not be intending to fetch the whole result.  Queries with ORDER BY
and/or LIMIT are particularly likely to see plan changes as a
consequence of that.  In 8.4 and up you can frob the
cursor_tuple_fraction setting to adjust this preference.  Use
"EXPLAIN query" vs "EXPLAIN DECLARE CURSOR FOR query" to see what
sort of plan you're getting.

            regards, tom lane

Hi Tom,

Tom Lane wrote:
> Bosco Rama <postgres@boscorama.com> writes:
>> I have a strange disparity between a query that is run as a
>> straight select and the same query via a cursor.  I hope I can
>> jog someone's memory with the description as I have been unable
>> to create a sanitized and/or reduced data set & schema that will
>> reproduce this ... so far. :-(
>
> Cursors are biased towards fast-start plans on the theory that you
> may not be intending to fetch the whole result.  Queries with ORDER BY
> and/or LIMIT are particularly likely to see plan changes as a
> consequence of that.  In 8.4 and up you can frob the
> cursor_tuple_fraction setting to adjust this preference.  Use
> "EXPLAIN query" vs "EXPLAIN DECLARE CURSOR FOR query" to see what
> sort of plan you're getting.

I'll take a look at that setting and try the two 'explain's.  However,
would that really account for an increase in time by a factor of ~630?
Just wondering.

(BTW, I'm still working on a public version of the data & schema that
reproduce this.)

Bosco.

Bosco Rama wrote:
> Tom Lane wrote:
>>
>> Cursors are biased towards fast-start plans on the theory that you
>> may not be intending to fetch the whole result.  Queries with ORDER BY
>> and/or LIMIT are particularly likely to see plan changes as a
>> consequence of that.  In 8.4 and up you can frob the
>> cursor_tuple_fraction setting to adjust this preference.  Use
>> "EXPLAIN query" vs "EXPLAIN DECLARE CURSOR FOR query" to see what
>> sort of plan you're getting.
>
> I'll take a look at that setting and try the two 'explain's.  However,
> would that really account for an increase in time by a factor of ~630?
> Just wondering.

Apparently it does.  Setting cursor_tuple_fraction to 1.0 alleviates
the problem in my test system (need end of day before I can test it in
the production system).  Thanks for the hint Tom.

I guess my question now is:  Why does it affect this query so badly?
This is the only one that has exhibited such behavior (... so far).

Also, is it a bad thing to set that value to 1.0 as the DB-wide setting?
Not understanding the internals that well I'm not too sure what exactly
is happening when I fool with this value.  I assume you guys set the
default to 0.1 based on some sort of generalized testing during the
development/testing phase(s).

> (BTW, I'm still working on a public version of the data & schema that
> reproduce this.)

I now have a small(er) sanitized example that shows this problem with
a slow-down factor of 100 (rather than the factor of 630 I had before).
Is it of any interest or is the above GUC setting all we care about?

Bosco.