Re: Question on what Duration in the log

From: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
To: "Vitale, Anthony, Sony Music" <anthony(dot)vitale(at)sonymusic(dot)com>
Cc: "pgsql-performance(at)lists(dot)postgresql(dot)org" <pgsql-performance(at)lists(dot)postgresql(dot)org>
Subject: Re: Question on what Duration in the log
Date: 2025-04-09 15:02:04
Message-ID: 196708.1744210924@sss.pgh.pa.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

"Vitale, Anthony, Sony Music" <anthony(dot)vitale(at)sonymusic(dot)com> writes:
> In my PG Version 14 log I have set to log the duration of sql (Example of one log row below).
> 2025-04-08 07:31:57 UTC:XXX(55994):XXX:[8949]:LOG: duration: 6555.756 ms 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

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Vitale, Anthony, Sony Music 2025-04-09 15:47:32 RE: Question on what Duration in the log
Previous Message Vitale, Anthony, Sony Music 2025-04-09 14:27:08 Question on what Duration in the log