Thread: Cursors and different settings for default_statistics_target
Hi, the following statement retrieves 16358 rows in a cursor by fetching 1024 rows in bulks on a 8.2.4 server: DECLARE curs_285058224 CURSOR FOR SELECT objid, attrid, aggrid, lineid, objval FROM atobjval WHERE objid IN (281479288456304,281479288456359,281479288456360,281479288456384,2814792 88456385,281479288456403,281479288456404,281479288456406,281479288456408 ,281479288456432,281479288456433,281479288456434,281479288456438,2814792 88456442,281479288456468,281479288456499,281479288456546,281479288456547 ,281479288456590,281479288456636,281479288456638,281479288456722,2814792 88457111,281479288457125,281479288457126,281479288457143,281479288457229 ,281479288457230,281479288457477,281479288457478,281479288457546,2814792 88457559,281479288457676,281479288457686,281479288457792,281479288457808 ,281479288457809,281479288457852,281479288457853,281479288457902,2814792 88457961,281479288457962,281479288458005,281479288458097,281479288458116 ,281479288458155,281479288458156,281479288458183,281479288458516,2814792 88458523,281479288458576,281479288458577,281479288458624,281479288458716 ,281479288458721,281479288458735,281479288458736,281479288458737,2814792 88458758,281479288458786,281479288458788,281479288458789,281479288458794 ,281479288458806,281479288458914,281479288458957,281479288458958,2814792 88459029,281479288459126,281479288459127,281479288459135,281479288459259 ,281479288459260,281479288459261,281479288459262,281479288459321,2814792 88459425,281479288459426,281479288459427,281479288459428,281479288459447 ,281479288459450,281479288459453,281479288459457,281479288459462,2814792 88459607,281479288459608,281479288459635,281479288459636,281479288459732 ,281479288459767,281479288459954,281479288459974,281479288459975,2814792 88459976,281479288459977,281479288460034,281479288460060,281479288460070 ,281479288460073,281479288460088,281479288460162,281479288460163,2814792 88460167,281479288460170,281479288460173,281479288460176,281479288460179 ,281479288460182,281479288460185,281479288460188,281479288460217,2814792 88460290,281479288460292,281479288460318,281479288460325,281479288460332 ,281479288460337,281479288460339,281479288460377,281479288460378,2814792 88460394,281479288460412,281479288460457,281479288460565,281479288460566 ,281479288460567,281479288460608,281479288460609,281479288460683,2814792 88460684,281479288461021,281479288461024,281479288461059,281479288461091 ,281479288461281,281479288461367,281479288461368,281479288461369,2814792 88461377,281479288461429,281479288461477,281479288461483,281479288461484 ,281479288461485,281479288461493,281479288461494,281479288461502,2814792 88461522,281479288461570,281479288461578,281479288461654,281479288461655 ,281479288461690,281479288461711,281479288461712,281479288461747,2814792 88461776,281479288461777,281479288461838,281479288461839,281479288461878 ,281479288461889,281479288462036,281479288462083,281479288462090,2814792 88462096,281479288462104,281479288462129,281479288462136,281479288462276 ,281479288462277,281479288462366,281479288462367,281479288462448,2814792 88462450,281479288462502,281479288462817,281479288462967,281479288462968 ,281479288462969,281479288463200,281479288463246,281479288463247,2814792 88463248,281479288463255,281479288463437,281479288463441,281479288463462 ,281479288463482,281479288463642,281479288463645,281479288463782,2814792 88463790,281479288463802,281479288463809,281479288463819,281479288463843 ,281479288463859,281479288463967,281479288463968,281479288463969,2814792 88465253,281479288465396,281479288465397,281479288465417,281479288465429 ,281479288465436,281479288467191,285774255752169,285774255752181,2857742 55752183,285774255752188,285774255752189,285774255752198,285774255753788 ,285774255753789,285774255753790,285774255753793,285774255753794,2857742 55753808,285774255753809,285774255753811,285774255753812,285774255753828 ,285774255753893,285774255753993,285774255754091,285774255754106,2857742 55754110,285774255754160,285774255755169,285774255755179,285774255755184 ,285774255755187,285774255755205,285774255755252,285774255755254,2857742 55755271,285774255755481,285774255755494,285774255755514,285774255755534 ,285774255755571,285774255755597,285774255755616,285774255755622,2857742 55755632,285774255755696,285774255755717,285774255755729,285774255755747 ,285774255755759,285774255755787,285774255755791,285774255755798,2857742 55755802,285774255757269,285774255757270,285774255757286,285774255757287 ,285774255757518,285774255757687,285774255757797,285774255761019,2857742 55761021,285774255761069,285774255761070,285774255764181,285774255764182 ,285774255764196,285774255764204,285774255764276,285774255764290,2857742 55764301,285774255764312,285774255764333,285774255764334,285774255764335 ,285774255764367,285774255764369,285774255764371,285774255764382,2857742 55764394,285774255764418,285774255764420,285774255764430,285774255764486 ,285774255764490,285774255764498,285774255764616,285774255764683,2857742 55764787,285774255764802,285774255765031,285774255765043,285774255765052 ,285774255765066,285774255765081,285774255765145,285774255766471,2857742 55767469,285774255767809,285774255767971,285774255768111,285774255768151 ,285774255768193,285774255768199,285774255768220,285774255769244,2857742 55769317,285774255770269,285774255770343,285774255770373,285774255770374 ,285774255770475,285774255770488,285774255772471,285774255773974,2857742 55773977,285774255773981,285774255774003,285774255774012,285774255774018 ,285774255774079,285774255774080,285774255774098,285774255774106,2857742 55774110,285774255774130,285774255774775,285774255777173,285774255777188 ,285774255777205,285774255777219,285774255777241,285774255777242,2857742 55777243,285774255777245,285774255777260,285774255777299,285774255777337 ,285774255777422,285774255777445,285774255777446,285774255778669,2857742 55778671,285774255778672,285774255779069,285774255779070,285774255781196 ,285774255782209,285774255782221,285774255782224,285774255782226,2857742 55782325,285774255782430,285774255783469,285774255783470,285774255783575 ,285774255783576,285774255783577,285774255785169,285774255785170,2857742 55785173,285774255785174,285774255785177,285774255785178,285774255785189 ,285774255785190,285774255785197,285774255785198,285774255785209,2857742 55785210,285774255785238,285774255785239,285774255788781,285774255788784 ,285774255788821,285774255788827,285774255788830,285774255788852,2857742 55788867,285774255788889,285774255789671,285774255789852,285774255790150 ,285774255790369,285774255790370,285774255790373,285774255790569,2857742 55790571,285774255790572,285774255790573,285774255790645,285774255790655 ,285774255793470,285774255793517,285774255793647,285774255793650,2857742 55793687,285774255795211,285774255797003,285774255798195,285774255798234 ,285774255798242,285774255800551,285774255800689,285774255800696,2857742 55800751,285774255800821,285774255809954,285774255809981,285774255810032 ,285774255810033,285774255812694,285774255812706,285774255812708,2857742 55812713,285774255812746,285774255812747,285774255812752,285774255812761 ,285774255812765,285774255812768,285774255812771,285774255812774,2857742 55812857,285774255813980,285774255814277,285774255814296,285774255814313 ,285774255814314,285774255814333,285774255814357,285774255814368,2857742 55814385,285774255815169,285774255816279,285774255816675,285774255817669 ,285774255817688,285774255817699,285774255817793,285774255817874,2857742 55817952,285774255817960,285774255817981,285774255818045,285774255818052 ,285774255818067,285774255818068,285774255818106,285774255820418,2857742 55821169,285774255821224,285774255821232,285774255821303,285774255821387 ,285774255821393,285774255821468,285774255821481,285774255826269,2857742 55826980,285774255826985,285774255826994,285774255827971,285774255827999 ,285774255828050,285774255828168,285774255828171,285774255828172,2857742 55828173,285774255828174,285774255828205,285774255828213,285774255828221 ,285774255832360,285774255832381,285774255832500,285774255832534,2857742 55832551,285774255832590,285774255832611,285774255832641,285774255832726 ,285774255832782,285774255833369,285774255833477,285774255833490,2857742 55833532,285774255833537,285774255833669,285774255834874,285774255834950 ,285774255835014,285774255835035,285774255836198,285774255836199,2857742 55837674) ORDER BY objid, attrid, aggrid, lineid; When we use 20 as default_statistics_target the retrieval of the data takes 7.5 seconds - with 25 as default_statistics_target (with restart and analyze) it takes 0.6 seconds. The query plan is identical in both situations (row estimation differs a little bit) - the query is always fast when it is executed without a cursor. The problem is the last of the 16 fetches - it takes about 7 seconds when using 20 as default_statistics_target. During the fetch there is no disk IO - the backend which is running the query uses 100 % of one cpu core during the seven seconds. The following shows OProfile output for the seven seconds: samples % symbol name 200318 41.0421 ExecEvalScalarArrayOp 106214 21.7616 int8eq 36031 7.3822 ExecMakeFunctionResultNoSets 17894 3.6662 ExecEvalAnd 16518 3.3843 ExecEvalScalarVar 13282 2.7213 ExecEvalConst 9980 2.0448 HeapTupleSatisfiesSnapshot 9696 1.9866 SyncOneBuffer 8643 1.7708 slot_getattr 6792 1.3916 int8le 6232 1.2768 hash_search_with_hash_value 6032 1.2359 heap_release_fetch 5690 1.1658 ExecEvalOr 5442 1.1150 _bt_checkkeys 5430 1.1125 LWLockAcquire 5228 1.0711 PinBuffer Does anyone has an explanation for this behavior? Regards, Robert Hell
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> When we use 20 as default_statistics_target the retrieval of the data
> takes 7.5 seconds - with 25 as default_statistics_target (with restart
> and analyze) it takes 0.6 seconds.
> The query plan is identical in both situations (row estimation differs a
> little bit) - the query is always fast when it is executed without a
> cursor.
A cursor doesn't necessarily use the same plan as a straight query does.
Try "EXPLAIN DECLARE curs_285058224 CURSOR FOR ..." and see if you
aren't getting different plans in these two cases.
regards, tom lane
That's it - I found a more simple statement which has the same problem
(0.02 seconds vs. 6 seconds):
With cursor (6 seconds):
appcooelakdb2=> explain DECLARE curs_1 CURSOR FOR SELECT DISTINCT
t2.objid FROM atobjval t2 WHERE t2.aggrid = 0 AND t2.attrid =
281479288455385 ORDER BY t2.objid;
QUERY PLAN
------------------------------------------------------------------------
----------------------
Unique (cost=0.00..1404823.63 rows=538 width=8)
-> Index Scan using atobjvalix on atobjval t2
(cost=0.00..1404751.32 rows=28925 width=8)
Index Cond: ((attrid = 281479288455385::bigint) AND (aggrid =
0))
Without cursor (0.02 seconds)
appcooelakdb2=> explain SELECT DISTINCT t2.objid FROM atobjval t2 WHERE
t2.aggrid = 0 AND t2.attrid = 281479288455385 ORDER BY t2.objid;
QUERY PLAN
------------------------------------------------------------------------
----------------------
Unique (cost=151717.85..151862.48 rows=538 width=8)
-> Sort (cost=151717.85..151790.17 rows=28925 width=8)
Sort Key: objid
-> Bitmap Heap Scan on atobjval t2 (cost=1692.40..149574.51
rows=28925 width=8)
Recheck Cond: (attrid = 281479288455385::bigint)
Filter: (aggrid = 0)
-> Bitmap Index Scan on ind_atobjval
(cost=0.00..1685.16 rows=59402 width=0)
Index Cond: (attrid = 281479288455385::bigint)
What's the difference between plan calculation for cursors and straight
queries?
Kind regards,
Robert
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Dienstag, 01. April 2008 17:30
To: Hell, Robert
Cc: pgsql-performance@postgresql.org
Subject: Re: [PERFORM] Cursors and different settings for
default_statistics_target
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> When we use 20 as default_statistics_target the retrieval of the data
> takes 7.5 seconds - with 25 as default_statistics_target (with restart
> and analyze) it takes 0.6 seconds.
> The query plan is identical in both situations (row estimation differs
a
> little bit) - the query is always fast when it is executed without a
> cursor.
A cursor doesn't necessarily use the same plan as a straight query does.
Try "EXPLAIN DECLARE curs_285058224 CURSOR FOR ..." and see if you
aren't getting different plans in these two cases.
regards, tom lane
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> That's it - I found a more simple statement which has the same problem
> (0.02 seconds vs. 6 seconds):
This isn't necessarily the very same problem --- what are the plans for
your original case with the two different stats settings?
> What's the difference between plan calculation for cursors and straight
> queries?
The planner is set up to favor fast-start plans a little bit when
planning a cursor, on the theory that you are probably more interested
in getting some of the rows sooner than you are in the total runtime,
and that you might not ever intend to fetch all the rows anyway.
In the example you give here, it likes the indexscan/unique plan because
of the zero startup cost, even though the total cost is (correctly)
estimated as much higher. (Looking at this example, I wonder if the
fast-start bias isn't a bit too strong...)
It's not immediately apparent to me though how that would affect
your original query.
regards, tom lane
Here are the query plans for the original query - looks very similar (to
me):
EXPLAIN SELECT objid, attrid, aggrid, lineid, objval FROM atobjval WHERE
objid IN (281479288456304,<many of them>,285774255837674) ORDER BY
objid, attrid, aggrid, lineid;
QUERY PLAN
------------------------------------------------------------------------
----------------------
Sort (cost=116851.38..117196.22 rows=137935 width=32)
Sort Key: objid, attrid, aggrid, lineid
-> Bitmap Heap Scan on atobjval (cost=4947.40..105076.13
rows=137935 width=32)
Recheck Cond: (objid = ANY ('{281479288456304,<many of
them>,285774255837674}'::bigint[]))
-> Bitmap Index Scan on atobjvalix (cost=0.00..4912.92
rows=137935 width=0)
Index Cond: (objid = ANY ('{281479288456304,<many of
them>,285774255837674}'::bigint[]))
explain DECLARE curs_285058224 CURSOR FOR SELECT objid, attrid, aggrid,
lineid, objval FROM atobjval WHERE objid IN (281479288456304,<many of
them>,285774255837674) ORDER BY objid, attrid, aggrid, lineid;
QUERY PLAN
------------------------------------------------------------------------
----------------------
Index Scan using atobjvalix on atobjval (cost=0.00..1041413.49
rows=137935 width=32)
Filter: (objid = ANY ('{281479288456304,<many of
them>,285774255837674}'::bigint[]))
That's CURSOR_OPT_FAST_PLAN and isn't it? Our application reads the full
results of most cursors.
Regards,
Robert
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Dienstag, 01. April 2008 18:17
To: Hell, Robert
Cc: pgsql-performance@postgresql.org
Subject: Re: [PERFORM] Cursors and different settings for
default_statistics_target
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> That's it - I found a more simple statement which has the same problem
> (0.02 seconds vs. 6 seconds):
This isn't necessarily the very same problem --- what are the plans for
your original case with the two different stats settings?
> What's the difference between plan calculation for cursors and
straight
> queries?
The planner is set up to favor fast-start plans a little bit when
planning a cursor, on the theory that you are probably more interested
in getting some of the rows sooner than you are in the total runtime,
and that you might not ever intend to fetch all the rows anyway.
In the example you give here, it likes the indexscan/unique plan because
of the zero startup cost, even though the total cost is (correctly)
estimated as much higher. (Looking at this example, I wonder if the
fast-start bias isn't a bit too strong...)
It's not immediately apparent to me though how that would affect
your original query.
regards, tom lane
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> That's CURSOR_OPT_FAST_PLAN and isn't it? Our application reads the full
> results of most cursors.
Just out of curiosity, why use a cursor at all then? But anyway, you
might want to consider running a custom build with a higher setting for
tuple_fraction for OPT_FAST_PLAN (look into planner.c). I've
occasionally thought about exposing that as a GUC parameter, but
never gotten motivated to do it.
regards, tom lane
On Tue, Apr 01, 2008 at 12:42:03PM -0400, Tom Lane wrote: >> That's CURSOR_OPT_FAST_PLAN and isn't it? Our application reads the full >> results of most cursors. > Just out of curiosity, why use a cursor at all then? This isn't the same scenario as the OP, but I've used a cursor in cases where I cannot keep all of the dataset in memory at the client at once, but I _can_ coerce it down to a more manageable size as it comes in. I don't know if a cursor is the only way to do this (short of making a custom function inside Postgres of some sort), but it seems to be the simplest way in libpqxx, at least. /* Steinar */ -- Homepage: http://www.sesse.net/
Looks much better when using 0.0 for tuple_fraction in case of a cursor instead of 0.1.
But why are the first 15 fetches (15360 rows) processed in 0.5 seconds and the last fetch (998 rows) takes 7 seconds.
Are we just unlucky that the last fetch takes that long?
EXPLAIN SELECT objid, attrid, aggrid, lineid, objval FROM atobjval WHERE objid IN (281479288456304,<many of
them>,285774255837674)ORDER BY objid, attrid, aggrid, lineid;
QUERY PLAN
----------------------------------------------------------------------------------------------
Sort (cost=116851.38..117196.22 rows=137935 width=32)
Sort Key: objid, attrid, aggrid, lineid
-> Bitmap Heap Scan on atobjval (cost=4947.40..105076.13 rows=137935 width=32)
Recheck Cond: (objid = ANY ('{281479288456304,<many of them>,285774255837674}'::bigint[]))
-> Bitmap Index Scan on atobjvalix (cost=0.00..4912.92 rows=137935 width=0)
Index Cond: (objid = ANY ('{281479288456304,<many of them>,285774255837674}'::bigint[]))
explain DECLARE curs_285058224 CURSOR FOR SELECT objid, attrid, aggrid, lineid, objval FROM atobjval WHERE objid IN
(281479288456304,<manyof them>,285774255837674) ORDER BY objid, attrid, aggrid, lineid;
QUERY PLAN
----------------------------------------------------------------------------------------------
Index Scan using atobjvalix on atobjval (cost=0.00..1041413.49 rows=137935 width=32)
Filter: (objid = ANY ('{281479288456304,<many of them>,285774255837674}'::bigint[]))
Regards,
Robert
-----Ursprüngliche Nachricht-----
Von: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Gesendet: Dienstag, 01. April 2008 18:42
An: Hell, Robert
Cc: pgsql-performance@postgresql.org
Betreff: Re: [PERFORM] Cursors and different settings for default_statistics_target
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> That's CURSOR_OPT_FAST_PLAN and isn't it? Our application reads the full
> results of most cursors.
Just out of curiosity, why use a cursor at all then? But anyway, you
might want to consider running a custom build with a higher setting for
tuple_fraction for OPT_FAST_PLAN (look into planner.c). I've
occasionally thought about exposing that as a GUC parameter, but
never gotten motivated to do it.
regards, tom lane
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> But why are the first 15 fetches (15360 rows) processed in 0.5 seconds and the last fetch (998 rows) takes 7 seconds.
> Are we just unlucky that the last fetch takes that long?
Well, the indexscan plan is going to scan through all the rows in objid
order and return whichever of them happen to match the IN list. So I
think you're just saying that your IN list isn't uniformly dense through
the whole set of objids.
If the real story is that you tend to select only objids within a narrow
range, adding explicit "AND objid >= x AND objid <= y" constraints
(where you compute x and y on the fly from the set of objids you're
asking for) would reduce the overhead of the indexscan.
regards, tom lane
I'm motivated to contribute a patch for that.
I would prefer to make tuple_fraction for cursors configurable as GUC
parameter cursor_tuple_fraction.
Do you agree with that?
Regards,
Robert
-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
Sent: Mittwoch, 02. April 2008 00:24
To: Hell, Robert
Cc: pgsql-performance@postgresql.org
Subject: Re: [PERFORM] Cursors and different settings for
default_statistics_target
"Hell, Robert" <Robert.Hell@fabasoft.com> writes:
> But why are the first 15 fetches (15360 rows) processed in 0.5 seconds
and the last fetch (998 rows) takes 7 seconds.
> Are we just unlucky that the last fetch takes that long?
Well, the indexscan plan is going to scan through all the rows in objid
order and return whichever of them happen to match the IN list. So I
think you're just saying that your IN list isn't uniformly dense through
the whole set of objids.
If the real story is that you tend to select only objids within a narrow
range, adding explicit "AND objid >= x AND objid <= y" constraints
(where you compute x and y on the fly from the set of objids you're
asking for) would reduce the overhead of the indexscan.
regards, tom lane