Thread: explain analyze taking longer than executing the query?

explain analyze taking longer than executing the query?

From
Jeff Davis
Date:
Version 8.2beta3.

If I EXPLAIN ANALYZE the query, it reports a time of about 2600 ms. If I
run the query in psql, I can tell visibly that the query takes less time
to execute than 2 seconds. Even stranger, if I wrap the query in a SQL
function and EXPLAIN ANALYZE a query that selects from the SQL function
(which returns the exact same results), that takes about 500 ms.

What am I missing about EXPLAIN ANALYZE that is causing that much
overhead? The query returns 10K rows exactly, out of a 1M record test
dataset.

I attached my queries below.

Regards,
    Jeff Davis

jdavis=# explain analyze select id from mytable group by id;
                                                       QUERY PLAN

-------------------------------------------------------------------------------------------------------------------------
 HashAggregate  (cost=18393.38..18395.38 rows=200 width=4) (actual
time=2603.204..2615.503 rows=10000 loops=1)
   ->  Seq Scan on mytable  (cost=0.00..15988.70 rows=961870 width=4)
(actual time=0.033..1291.057 rows=1000000 loops=1)
 Total runtime: 2625.892 ms
(3 rows)

jdavis=# create or replace function mytable_query() returns setof int
language sql as $$ select id from mytable group by id $$;
CREATE FUNCTION
jdavis=# explain analyze select * from mytable_query();
                                                       QUERY PLAN

------------------------------------------------------------------------------------------------------------------------
 Function Scan on mytable_query  (cost=0.00..12.50 rows=1000 width=4)
(actual time=501.459..513.624 rows=10000 loops=1)
 Total runtime: 524.288 ms
(2 rows)

jdavis=#



Re: explain analyze taking longer than executing the query?

From
Tom Lane
Date:
Jeff Davis <pgsql@j-davis.com> writes:
> What am I missing about EXPLAIN ANALYZE that is causing that much
> overhead?

Instrumentation overhead?  In this case you've got 2 million more
gettimeofday() calls in the one case than the other, which says that
gettimeofday() takes about 1 microsecond on your machine, which is not
too surprising for typical consumer PC gear.  See discussions in the
pghackers archives back in May or so ... we tried to cut the overhead,
and failed miserably :-(

            regards, tom lane