total execution time as reported by auto_explain

Started by Jaime Casanovaabout 16 years ago2 messages
#1Jaime Casanova
jcasanov@systemguards.com.ec
1 attachment(s)

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

Attachments:

explain_no_entendible.txttext/plain; charset=US-ASCII; name=explain_no_entendible.txtDownload
#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: Jaime Casanova (#1)
Re: total execution time as reported by auto_explain

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