Обсуждение: timing != log duration

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hello

I am wondering why the time reported by \timing in psql is not the same
as the time reported by duration in the log file when log_duration or
log_min_duration_statement are on?. I can not find any information about
this in the documentation.

e.g.
- -----------------------------------
ver=# SELECT * from version ;
Time: 0.450 ms

2012-03-20 16:10:16 CET 29119 LOG:  duration: 0.313 ms  statement:
SELECT * from version ;
- -----------------------------------

ver=# PREPARE foo AS SELECT * from version ;
PREPARE
Time: 0.188 ms

ver=# EXECUTE foo;
Time: 0.434 ms

ver=# DEALLOCATE foo;
DEALLOCATE
Time: 0.115 ms

2012-03-20 16:12:21 CET 29119 LOG:  duration: 0.127 ms  statement:
PREPARE foo AS SELECT * from version ;
2012-03-20 16:12:37 CET 29119 LOG:  duration: 0.303 ms  statement:
EXECUTE foo;
2012-03-20 16:13:24 CET 29119 LOG:  duration: 0.055 ms  statement:
DEALLOCATE foo;
- -----------------------------------

Thanks in advance
regards,
- --
 Rafael Martinez Guerrero
 Center for Information Technology
 University of Oslo, Norway

 PGP Public Key: http://folk.uio.no/rafael/
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAk9pvoUACgkQBhuKQurGihRf3gCfRMv5dQnNA8f/gjcPMv6OPrGz
qHoAn0PPgN1OYMBDQqJes3kRBxH//Y95
=rsAY
-----END PGP SIGNATURE-----

On Wed, Mar 21, 2012 at 13:42, Rafael Martinez <r.m.guerrero@usit.uio.no> wrote:
> I am wondering why the time reported by \timing in psql is not the same
> as the time reported by duration in the log file when log_duration or
> log_min_duration_statement are on?

psql's \timing measures time on the client -- which includes the
network communication time (time to send the query to the server, and
receive back the results)

log_min_duration_statement measures time on the server, so it doesn't
know how long network transmission takes.

Regards,
Marti

Rafael Martinez <r.m.guerrero@usit.uio.no> writes:
> I am wondering why the time reported by \timing in psql is not the same
> as the time reported by duration in the log file when log_duration or
> log_min_duration_statement are on?

Network transmission delays, perhaps?  psql reports the elapsed time
seen at the client, which is necessarily going to be somewhat more than
the time taken by the server.

            regards, tom lane

Rafael Martinez wrote:
> I am wondering why the time reported by \timing in psql is not the
same
> as the time reported by duration in the log file when log_duration or
> log_min_duration_statement are on?. I can not find any information
about
> this in the documentation.

\timing measures the time on the client, while the log contains the
duration
on the server side.  The client time includes the overhead for
transferring
data to and from the server.

Yours,
Laurenz Albe