Received: from magus.postgresql.org (magus.postgresql.org [87.238.57.229]) by mail.postgresql.org (Postfix) with ESMTP id A88AB2F4276 for ; Wed, 21 Mar 2012 08:42:29 -0300 (ADT) Received: from mail-out1.uio.no ([2001:700:100:10::57]) by magus.postgresql.org with esmtp (Exim 4.72) (envelope-from ) id 1SAJvu-0004jI-KW for pgsql-performance@postgresql.org; Wed, 21 Mar 2012 11:42:28 +0000 Received: from mail-mx1.uio.no ([129.240.10.29]) by mail-out1.uio.no with esmtp (Exim 4.75) (envelope-from ) id 1SAJvi-0002iL-IA for pgsql-performance@postgresql.org; Wed, 21 Mar 2012 12:42:14 +0100 Received: from 84.122.25.226.dyn.user.ono.com ([84.122.25.226] helo=[10.2.2.101]) by mail-mx1.uio.no with esmtpsa (TLSv1:CAMELLIA256-SHA:256) user rafael (Exim 4.76) (envelope-from ) id 1SAJvh-0005kr-W8 for pgsql-performance@postgresql.org; Wed, 21 Mar 2012 12:42:14 +0100 Message-ID: <4F69BE88.30905@usit.uio.no> Date: Wed, 21 Mar 2012 12:42:00 +0100 From: Rafael Martinez User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.2.27) Gecko/20120216 Thunderbird/3.1.19 MIME-Version: 1.0 To: pgsql-performance@postgresql.org Subject: timing != log duration X-Enigmail-Version: 1.1.2 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit X-UiO-Ratelimit-Test: rcpts/h 3 msgs/h 3 sum rcpts/h 6 sum msgs/h 4 total rcpts 3735 max rcpts/h 19 ratelimit 0 X-UiO-Spam-info: not spam, SpamAssassin (score=-8.0, required=5.0, autolearn=disabled, TVD_RCVD_IP=0.001, UIO_MAIL_IS_INTERNAL=-5, UIO_PGP_SIGNED=-3, uiobl=NO, uiouri=NO) X-UiO-Scanned: BD794B65298C18BE4F7E5982CF19B1C9B44A64D4 X-UiO-SPAM-Test: remote_host: 84.122.25.226 spam_score: -79 maxlevel 80 minaction 2 bait 0 mail/h: 3 total 334 max/h 4 blacklist 0 greylist 0 ratelimit 0 X-Pg-Spam-Score: -1.9 (-) X-Archive-Number: 201203/132 X-Sequence-Number: 46582 -----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-----