Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1u2WwM-0020i8-1Q for pgsql-performance@arkaria.postgresql.org; Wed, 09 Apr 2025 15:02:10 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1u2WwJ-003t1X-I8 for pgsql-performance@arkaria.postgresql.org; Wed, 09 Apr 2025 15:02:07 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1u2WwJ-003t1P-7z for pgsql-performance@lists.postgresql.org; Wed, 09 Apr 2025 15:02:07 +0000 Received: from sss.pgh.pa.us ([68.162.161.243]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.96) (envelope-from ) id 1u2WwH-004MEc-13 for pgsql-performance@lists.postgresql.org; Wed, 09 Apr 2025 15:02:07 +0000 Received: from sss1.sss.pgh.pa.us (localhost [127.0.0.1]) by sss.pgh.pa.us (8.15.2/8.15.2) with ESMTP id 539F24M5196709; Wed, 9 Apr 2025 11:02:04 -0400 From: Tom Lane To: "Vitale, Anthony, Sony Music" cc: "pgsql-performance@lists.postgresql.org" Subject: Re: Question on what Duration in the log In-reply-to: References: Comments: In-reply-to "Vitale, Anthony, Sony Music" message dated "Wed, 09 Apr 2025 14:27:08 -0000" MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-ID: <196707.1744210924.1@sss.pgh.pa.us> Content-Transfer-Encoding: quoted-printable Date: Wed, 09 Apr 2025 11:02:04 -0400 Message-ID: <196708.1744210924@sss.pgh.pa.us> List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk "Vitale, Anthony, Sony Music" writes: > In my PG Version 14 log I have set to log the duration of sql (Example o= f one log row below). > 2025-04-08 07:31:57 UTC:XXX(55994):XXX:[8949]:LOG: duration: 6555.756 m= s execute S_381: {Actual Parameterized Sql executed} > This Shows the Execution of a JDBC Server Side Prepared statement (i.e S= _381) which took 6.5 seconds. > When I run the Sql using explain analyze it runs shows an execution time= of 73 ms > Planning Time: 0.773 ms > Execution Time: 73.578 ms They're not measuring the same thing really, because EXPLAIN isn't counting the time needed to transmit data to the client. This is not just a matter of network overhead (though that can be substantial) but also the time required to format the values into text. If you are talking about large values, which I bet you are, there is also the time needed to fetch them from out-of-line TOAST storage, which is another thing that doesn't happen in EXPLAIN. Since v17, EXPLAIN has grown a SERIALIZE option that causes it to do everything except the network transmission, which might be of interest in analyzing this further. regards, tom lane