SEO

This was a suggestion made back in March that would dramatically reduce
the overhead of EXPLAIN ANALYZE on queries that loop continuously over
the same nodes.

http://archives.postgresql.org/pgsql...3/msg01114.php

What it does behave normally for the first 50 tuples of any node, but
after that it starts sampling at ever increasing intervals, the
intervals controlled by an exponential function. So for a node
iterating over 1 million tuples it takes around 15,000 samples. The
result is that EXPLAIN ANALYZE has a much reduced effect on the total
execution time.

Without EXPLAIN ANALYZE:

postgres=# select count(*) from generate_series(1,1000000);
count
---------
1000000
(1 row)

Time: 2303.599 ms

EXPLAIN ANALYZE without patch:

postgres=# explain analyze select count(*) from generate_series(1,1000000);
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=15.00..15.01 rows=1 width=0) (actual time=8022.070..8022.073 rows=1 loops=1)
-> Function Scan on generate_series (cost=0.00..12.50 rows=1000 width=0) (actual time=1381.762..4873.369 rows=1000000 loops=1)
Total runtime: 8042.472 ms
(3 rows)

Time: 8043.401 ms

EXPLAIN ANALYZE with patch:

postgres=# explain analyze select count(*) from generate_series(1,1000000);
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=15.00..15.01 rows=1 width=0) (actual time=2469.491..2469.494 rows=1 loops=1)
-> Function Scan on generate_series (cost=0.00..12.50 rows=1000 width=0) (actual time=1405.002..2187.417 rows=1000000 loops=1)
Total runtime: 2496.529 ms
(3 rows)

Time: 2497.488 ms

As you can see, the overhead goes from 5.7 seconds to 0.2 seconds.
Obviously this is an extreme case, but it will probably help in a lot
of other cases people have been complaining about.

- To get this close it needs to get an estimate of the sampling overhead.
It does this by a little calibration loop that is run once per backend.
If you don't do this, you end up assuming all tuples take the same time
as tuples with the overhead, resulting in nodes apparently taking
longer than their parent nodes. Incidently, I measured the overhead to
be about 3.6us per tuple per node on my (admittedly slightly old)
machine.

Note that the resulting times still include the overhead actually
incurred, I didn't filter it out. I want the times to remain reflecting
reality as closely as possible.

- I also removed InstrStopNodeMulti and made InstrStopNode take a tuple
count parameter instead. This is much clearer all round.

- I also didn't make it optional. I'm unsure about whether it should be
optional or not, given the number of cases where it will make a
difference to be very few.

- The tuple counter for sampling restarts every loop. Thus a node that is
called repeatedly only returning one value each time will still measure
every tuple, though its parent node won't. We'll need some field
testing to see if that remains a significant effect.

- I don't let the user know anywhere how many samples it took. Is this
something users should care about?

Any comments?
--
Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/
> From each according to his ability. To each according to his ability to litigate.

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.1 (GNU/Linux)

iD8DBQFEYP1vIB7bNG8LQkwRAtyvAJ9G/fLMi9iyFlGdQIRSx6CVNrjfUQCdGxpL
6CHWVT/WrKf0xT+/LLAlzh0=
=Jt7v
-----END PGP SIGNATURE-----

On Tue, 2006-05-09 at 22:37 +0200, Martijn van Oosterhout wrote:
> This was a suggestion made back in March that would dramatically reduce
> the overhead of EXPLAIN ANALYZE on queries that loop continuously over
> the same nodes.
>
> http://archives.postgresql.org/pgsql...3/msg01114.php
>
> As you can see, the overhead goes from 5.7 seconds to 0.2 seconds.
> Obviously this is an extreme case, but it will probably help in a lot
> of other cases people have been complaining about.

This seems much more useful behaviour than currently. Running an EXPLAIN
ANALYZE for large queries can be a real pain, especially on a production
box which is in live use - so tuning a test tool has a meaningful effect
on other users performance too.

There's a lot of thought gone in here, so I'd vote yes, though without
having done a detailed code review.

--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com


---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

On Tue, May 09, 2006 at 10:37:04PM +0200, Martijn van Oosterhout wrote:
> Note that the resulting times still include the overhead actually
> incurred, I didn't filter it out. I want the times to remain reflecting
> reality as closely as possible.

If we actually know the overhead I think it'd be very useful at times to
be able to remove it, especially if you're actually trying to compare to
the planner estimates. Maybe worth adding an option to the command?

> - I also didn't make it optional. I'm unsure about whether it should be
> optional or not, given the number of cases where it will make a
> difference to be very few.

The real question is how important it is to have the real data in the
cases where it would make a difference, and I suspect we can't answer
that until this is out in the field. It *might* be worth a #define or
some other way to disable it that doesn't require patching code, but
probably not.
--
Jim C. Nasby, Sr. Engineering Consultant jnasby@pervasive.com
Pervasive Software http://pervasive.com work: 512-231-6117
vcard: http://jim.nasby.net/pervasive.vcf cell: 512-569-9461

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

"Martijn van Oosterhout" <kleptog@svana.org> wrote
>
> What it does behave normally for the first 50 tuples of any node, but
> after that it starts sampling at ever increasing intervals, the
> intervals controlled by an exponential function.
>

I got two questions after scanning the patch:

(1) For a node with 50 loops and another one 50+10^3 loops, the first
one will be measured 50 times and the second one will be measured 50+10
times? I am not sure if this is rational.

(2) Will this patch instruct multinode without interval? This is because
we always use ntuples=0 for multinode, so the tuplecount will not
change.

Maybe another way is to measure the cost of timing, then substruct it
from the result - but this is a hand-waiving only so far ...

Regards,
Qingqing

On Thu, May 11, 2006 at 06:37:03PM -0500, Jim C. Nasby wrote:
> On Tue, May 09, 2006 at 10:37:04PM +0200, Martijn van Oosterhout wrote:
> > Note that the resulting times still include the overhead actually
> > incurred, I didn't filter it out. I want the times to remain reflecting
> > reality as closely as possible.
>
> If we actually know the overhead I think it'd be very useful at times to
> be able to remove it, especially if you're actually trying to compare to
> the planner estimates. Maybe worth adding an option to the command?

It's not quite as easy as that unfortunatly. Each node can estimate how
much overhead was incurred on that node. However, each node also
includes as part of its timing the overhead of all its decendant nodes.
So to really remove the overhead, the top-level would have to recurse
through the whole tree to decide what to remove.

What I'm hoping is that this patch will make the overhead so low in
normal operation that we don't need to go to that kind of effort.

> > - I also didn't make it optional. I'm unsure about whether it should be
> > optional or not, given the number of cases where it will make a
> > difference to be very few.
>
> The real question is how important it is to have the real data in the
> cases where it would make a difference, and I suspect we can't answer
> that until this is out in the field. It *might* be worth a #define or
> some other way to disable it that doesn't require patching code, but
> probably not.

A #define is doable, though messy. The code isn't all that long anyway
so a few #ifdefs might make it confusing. But I'll see what I can do.

Have a ncie day,
--
Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/
> From each according to his ability. To each according to his ability to litigate.

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.1 (GNU/Linux)

iD8DBQFEZGH+IB7bNG8LQkwRAqiqAJ9353HpZx+wKG/1N5w4dHtjTPfDmwCfYVQ2
mDTXj3tWZujgh8oSfO0asjM=
=cMzo
-----END PGP SIGNATURE-----

On Fri, 2006-05-12 at 12:22 +0200, Martijn van Oosterhout wrote:
> On Thu, May 11, 2006 at 06:37:03PM -0500, Jim C. Nasby wrote:
> > On Tue, May 09, 2006 at 10:37:04PM +0200, Martijn van Oosterhout wrote:
> > > Note that the resulting times still include the overhead actually
> > > incurred, I didn't filter it out. I want the times to remain reflecting
> > > reality as closely as possible.
> >
> > If we actually know the overhead I think it'd be very useful at times to
> > be able to remove it, especially if you're actually trying to compare to
> > the planner estimates. Maybe worth adding an option to the command?
>
> It's not quite as easy as that unfortunatly. Each node can estimate how
> much overhead was incurred on that node. However, each node also
> includes as part of its timing the overhead of all its decendant nodes.
> So to really remove the overhead, the top-level would have to recurse
> through the whole tree to decide what to remove.

Agreed

--
Simon Riggs
EnterpriseDB http://www.enterprisedb.com


---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

[Sorry for the delay, I'm not subscribed to I didn't see your message
till I checked the archive. Please CC for a quicker response.]

> I got two questions after scanning the patch:
>
> (1) For a node with 50 loops and another one 50+10^3 loops, the first
> one will be measured 50 times and the second one will be measured 50+10
> times? I am not sure if this is rational.

You're miscalculating. For N tuples it samples approximatly 1.5*N^(2/3)
so that would be a bit less than 50+150 samples (my little script
suggests 197 samples).

$ perl -MMath::Complex -e '
for $i (1..1050) {
if( $i < 50 ) { $s++ }
else {
if( $i > $t ) { $s++; $t += cbrt($i); }
}
}; print "$s\n"; '
197

> (2) Will this patch instruct multinode without interval? This is
> because we always use ntuples=0 for multinode, so the tuplecount will
> not change.

Well, if the tuple count always stays under 50 then it will always
sample. At the time it decides whether to sample or not (the beginning
of the node) it obviously has no idea what will be returned.

Have a ncie day,
--
Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/
> From each according to his ability. To each according to his ability to litigate.

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.1 (GNU/Linux)

iD8DBQFEZjTtIB7bNG8LQkwRArL5AJ9NuxB7kTg0lbqYzSdlhd hRqHsGvgCeN/zq
t5zreXz30RAZec4JRu0GAmM=
=/Lho
-----END PGP SIGNATURE-----

On Fri, May 12, 2006 at 12:22:54PM +0200, Martijn van Oosterhout wrote:
> > > - I also didn't make it optional. I'm unsure about whether it should be
> > > optional or not, given the number of cases where it will make a
> > > difference to be very few.
> >
> > The real question is how important it is to have the real data in the
> > cases where it would make a difference, and I suspect we can't answer
> > that until this is out in the field. It *might* be worth a #define or
> > some other way to disable it that doesn't require patching code, but
> > probably not.
>
> A #define is doable, though messy. The code isn't all that long anyway
> so a few #ifdefs might make it confusing. But I'll see what I can do.

If it proves messy, it's probably not worth doing. Presumably anyone
able to tweak a #define could probably apply a patch as well. If you are
going to go through the effort it probably makes the most sense to just
add the remaining syntax to make it dynamic.
--
Jim C. Nasby, Sr. Engineering Consultant jnasby@pervasive.com
Pervasive Software http://pervasive.com work: 512-231-6117
vcard: http://jim.nasby.net/pervasive.vcf cell: 512-569-9461

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

On Mon, May 15, 2006 at 12:09:37AM -0500, Jim C. Nasby wrote:
> On Fri, May 12, 2006 at 12:22:54PM +0200, Martijn van Oosterhout wrote:
> > A #define is doable, though messy. The code isn't all that long anyway
> > so a few #ifdefs might make it confusing. But I'll see what I can do.
>
> If it proves messy, it's probably not worth doing. Presumably anyone
> able to tweak a #define could probably apply a patch as well. If you are
> going to go through the effort it probably makes the most sense to just
> add the remaining syntax to make it dynamic.

Making it configurable via a GUC would be much easier than making ik
optional at compile time because then you just need to skip the tests
for 'to sample or not'. To make it optional at compile time you'd need
to actually take out all the code relating to sampling.

Maybe:

enable_explain_sample (default: yes)

Have a nice day,
--
Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/
> From each according to his ability. To each according to his ability to litigate.

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.1 (GNU/Linux)

iD8DBQFEaDunIB7bNG8LQkwRAt/AAJ9ioxgajV3FdqQxZa5zWCr/tvlJqwCfe2W6
YpAug5QT5NOkINA1Uac3mkk=
=Mptj
-----END PGP SIGNATURE-----

Patch applied. Thanks.

---------------------------------------------------------------------------


Martijn van Oosterhout wrote:
-- Start of PGP signed section.
> This was a suggestion made back in March that would dramatically reduce
> the overhead of EXPLAIN ANALYZE on queries that loop continuously over
> the same nodes.
>
> http://archives.postgresql.org/pgsql...3/msg01114.php
>
> What it does behave normally for the first 50 tuples of any node, but
> after that it starts sampling at ever increasing intervals, the
> intervals controlled by an exponential function. So for a node
> iterating over 1 million tuples it takes around 15,000 samples. The
> result is that EXPLAIN ANALYZE has a much reduced effect on the total
> execution time.
>
> Without EXPLAIN ANALYZE:
>
> postgres=# select count(*) from generate_series(1,1000000);
> count
> ---------
> 1000000
> (1 row)
>
> Time: 2303.599 ms
>
> EXPLAIN ANALYZE without patch:
>
> postgres=# explain analyze select count(*) from generate_series(1,1000000);
> QUERY PLAN
> ------------------------------------------------------------------------------------------------------------------------------------
> Aggregate (cost=15.00..15.01 rows=1 width=0) (actual time=8022.070..8022.073 rows=1 loops=1)
> -> Function Scan on generate_series (cost=0.00..12.50 rows=1000 width=0) (actual time=1381.762..4873.369 rows=1000000 loops=1)
> Total runtime: 8042.472 ms
> (3 rows)
>
> Time: 8043.401 ms
>
> EXPLAIN ANALYZE with patch:
>
> postgres=# explain analyze select count(*) from generate_series(1,1000000);
> QUERY PLAN
> ------------------------------------------------------------------------------------------------------------------------------------
> Aggregate (cost=15.00..15.01 rows=1 width=0) (actual time=2469.491..2469.494 rows=1 loops=1)
> -> Function Scan on generate_series (cost=0.00..12.50 rows=1000 width=0) (actual time=1405.002..2187.417 rows=1000000 loops=1)
> Total runtime: 2496.529 ms
> (3 rows)
>
> Time: 2497.488 ms
>
> As you can see, the overhead goes from 5.7 seconds to 0.2 seconds.
> Obviously this is an extreme case, but it will probably help in a lot
> of other cases people have been complaining about.
>
> - To get this close it needs to get an estimate of the sampling overhead.
> It does this by a little calibration loop that is run once per backend.
> If you don't do this, you end up assuming all tuples take the same time
> as tuples with the overhead, resulting in nodes apparently taking
> longer than their parent nodes. Incidently, I measured the overhead to
> be about 3.6us per tuple per node on my (admittedly slightly old)
> machine.
>
> Note that the resulting times still include the overhead actually
> incurred, I didn't filter it out. I want the times to remain reflecting
> reality as closely as possible.
>
> - I also removed InstrStopNodeMulti and made InstrStopNode take a tuple
> count parameter instead. This is much clearer all round.
>
> - I also didn't make it optional. I'm unsure about whether it should be
> optional or not, given the number of cases where it will make a
> difference to be very few.
>
> - The tuple counter for sampling restarts every loop. Thus a node that is
> called repeatedly only returning one value each time will still measure
> every tuple, though its parent node won't. We'll need some field
> testing to see if that remains a significant effect.
>
> - I don't let the user know anywhere how many samples it took. Is this
> something users should care about?
>
> Any comments?
> --
> Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/
> > From each according to his ability. To each according to his ability to litigate.

[ Attachment, skipping... ]
-- End of PGP section, PGP failed!

--
Bruce Momjian http://candle.pha.pa.us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings