Re: Large time difference between explain analyze and normal run

On February 10, 2005 10:58 am, Tom Lane wrote:
> Chris Kratz <chris.kratz@vistashare.com> writes:
> > Does anyone have any idea why there be over a 4s difference between
> > running the statement directly and using explain analyze?
> >
> >  Aggregate  (cost=9848.12..9848.12 rows=1 width=0) (actual
> > time=4841.231..4841.235 rows=1 loops=1)
> >    ->  Seq Scan on answer  (cost=0.00..8561.29 rows=514729 width=0)
> > (actual time=0.011..2347.762 rows=530576 loops=1)
> >  Total runtime: 4841.412 ms
>
> EXPLAIN ANALYZE's principal overhead is two gettimeofday() kernel calls
> per plan node execution, so 1061154 such calls here.  I infer that
> gettimeofday takes about 4 microseconds on your hardware ... which seems
> a bit slow for modern machines.  What sort of box is it?

dvl reported the same thing on #postgresql some months back, and neilc
was/is/did looking into it.  I belive he came up with a way to move the
function call outside of the loop  with no ill effects to the rest of the
expected behavior.

>
>             regards, tom lane
>
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Don't 'kill -9' the postmaster

--
Darcy Buskermolen
Wavefire Technologies Corp.
ph: 250.717.0200
fx:  250.763.1759
http://www.wavefire.com