Re: That EXPLAIN ANALYZE patch still needs work

Simon Riggs <simon(at)2ndquadrant(dot)com> writes:
> On Wed, 2006-06-07 at 17:28 -0400, Tom Lane wrote:
>> The overhead seems to be on the order of a couple tens of percent usually.
>> I don't see how that makes the difference between an EXPLAIN ANALYZE you
>> can run and one you can't.

> Well, thats not my experience and doesn't match others posted on
> -hackers.

> A simple test with pgbench shows the timing overhead of EXPLAIN ANALYZE
> to be consistently above 500% (or more than +400%, depending upon how
> you style those numbers).

I think we ought to find out why your machine is so broken.

Even in this pretty-much-worst-case scenario (a seqscan does about as
little real work per plan node call as possible, especially if the table
is already fully cached), I don't see more than about a 2X degradation.
On queries that are complicated enough to actually need EXPLAIN ANALYZE,
it's not nearly that bad.

Old slow HPUX/HPPA machine, PG 8.1 branch tip:

bench=# \timing
Timing is on.
bench=# select count(*) from accounts;
count
--------
100000
(1 row)

Time: 543.565 ms
-- do it again to ensure fully cached
bench=# select count(*) from accounts;
count
--------
100000
(1 row)

Time: 492.667 ms
bench=# explain analyze select count(*) from accounts;
QUERY PLAN

--------------------------------------------------------------------------------
---------------------------------------
Aggregate (cost=2975.00..2975.01 rows=1 width=0) (actual time=1172.856..1172.8
60 rows=1 loops=1)
-> Seq Scan on accounts (cost=0.00..2725.00 rows=100000 width=0) (actual ti
me=0.175..720.741 rows=100000 loops=1)
Total runtime: 1173.290 ms
(3 rows)

Time: 1176.293 ms
bench=#

Spiffy new Fedora 5/dual Xeon machine, PG 8.1 branch tip:

bench=# \timing
Timing is on.
bench=# select count(*) from accounts;
count
--------
100000
(1 row)

Time: 61.737 ms
-- do it again to ensure fully cached
bench=# select count(*) from accounts;
count
--------
100000
(1 row)

Time: 53.941 ms
bench=# explain analyze select count(*) from accounts;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------
Aggregate (cost=2975.00..2975.01 rows=1 width=0) (actual time=117.881..117.882 rows=1 loops=1)
-> Seq Scan on accounts (cost=0.00..2725.00 rows=100000 width=0) (actual time=0.041..77.628 rows=100000 loops=1)
Total runtime: 117.936 ms
(3 rows)

Time: 118.510 ms
bench=#

I'm too lazy to pull up any of my other machines right now, but this is
generally consistent with my experience ever since EXPLAIN ANALYZE was
written.

So: what's your platform exactly?

regards, tom lane