Thread: total execution time as reported by auto_explain

Hi,

I was using auto_explain to log plans (with analyze option on) from
queries that take more than 500ms, something i found i little odd is
that the duration says 779ms but actual time says 269ms (almost 3
times lower), maybe some kind of instrumentation cleanup can explain
this?

2009-11-10 10:32:41 GMTLOG:  duration: 779.938 ms  plan:
    Sort  (cost=1943.99..1967.38 rows=9355 width=466) (actual
time=235.655..269.061 rows=4997 loops=1)

--
Atentamente,
Jaime Casanova
Soporte y capacitación de PostgreSQL
Asesoría y desarrollo de sistemas
Guayaquil - Ecuador
Cel. +59387171157

Jaime Casanova <jcasanov@systemguards.com.ec> writes:
> I was using auto_explain to log plans (with analyze option on) from
> queries that take more than 500ms, something i found i little odd is
> that the duration says 779ms but actual time says 269ms (almost 3
> times lower), maybe some kind of instrumentation cleanup can explain
> this?

Client slow about absorbing the rows, perhaps?  The actual data output
process isn't counted as part of the plan tree's runtime ... but it
would be included in the total elapsed time.
        regards, tom lane