Re: BUG #14889: explain analyze is taking much more time than actual execution

David Rowley <david(dot)rowley(at)2ndquadrant(dot)com> writes:
> On 6 November 2017 at 21:04, mahmoud alorfaly
> <mahmoud(dot)alorfaly(at)gmail(dot)com> wrote:
>> With EXPLAIN (ANALYZE, TIMING OFF), it is back to normal execution speed.

> Then it's just the TIMING overhead that's causing the slowdown. This
> will vary depending on how long gettimeofday() takes on your system.
> This is known to be an overhead which is one of the reasons the TIMING
> OFF option exists.

The size of the overhead in this case implies that gettimeofday() is doing
a kernel call, which I wouldn't really have expected on any modern Linux
kernel. What hardware is this on? Is there virtualization involved?

For context, on RHEL6 on run-of-the-mill server iron, I get overheads more
like this:

regression=# explain analyze select i from generate_series(1,10000000) i;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------
Function Scan on generate_series i (cost=0.00..10.00 rows=1000 width=4) (actual time=1711.319..3083.864 rows=10000000 loops=1)
Planning time: 0.078 ms
Execution time: 3636.962 ms
(3 rows)

regression=# explain (analyze, timing off) select i from generate_series(1,10000000) i;
QUERY PLAN
---------------------------------------------------------------------------------------------------------
Function Scan on generate_series i (cost=0.00..10.00 rows=1000 width=4) (actual rows=10000000 loops=1)
Planning time: 0.077 ms
Execution time: 2870.410 ms
(3 rows)

regards, tom lane