Thread: sql execution time in pg_stat_statements

sql execution time in pg_stat_statements

From
"Michel SALAIS"
Date:

Hi all,

 

I think that total_time in pg_stat_statements is cpu time + possible waits. So, can I say that:

Total_sql_time = total_time + blk_read_time + blk_write_time

 

Documentation is not clear at all on that.

 

Thanks in advance

 

Michel SALAIS

RE: sql execution time in pg_stat_statements

From
"Michel SALAIS"
Date:

Just to say that for PostgreSQL 13, total_time is replaced by “total_exec_time + total_plan_time”

 

Michel SALAIS

De : Michel SALAIS <msalais@msym.fr>
Envoyé : jeudi 9 septembre 2021 20:14
À : pgsql-performance@postgresql.org
Objet : sql execution time in pg_stat_statements

 

Hi all,

 

I think that total_time in pg_stat_statements is cpu time + possible waits. So, can I say that:

Total_sql_time = total_time + blk_read_time + blk_write_time

 

Documentation is not clear at all on that.

 

Thanks in advance

 

Michel SALAIS

Re: sql execution time in pg_stat_statements

From
Julien Rouhaud
Date:
On Fri, Sep 10, 2021 at 2:49 AM Michel SALAIS <msalais@msym.fr> wrote:
>
> I think that total_time in pg_stat_statements is cpu time + possible waits. So, can I say that:
>
> Total_sql_time = total_time + blk_read_time + blk_write_time
>
> Documentation is not clear at all on that.

In version 12 and below, total_time is the elapsed time between the
execution start and stop, so it includes all underlying events. That
includes any IO activity, wait events or nested statements (if
pg_stat_statemetns.track is set to all).  This corresponds to the new
total_exec_time field in version 13 and later.


> Just to say that for PostgreSQL 13, total_time is replaced by “total_exec_time + total_plan_time”

Indeed, as this version also tracks planning activity.



RE: sql execution time in pg_stat_statements

From
"Michel SALAIS"
Date:

-----Message d'origine-----
De : Julien Rouhaud <rjuju123@gmail.com>
Envoyé : vendredi 10 septembre 2021 07:18
À : Michel SALAIS <msalais@msym.fr>
Cc : postgres performance list <pgsql-performance@postgresql.org>
Objet : Re: sql execution time in pg_stat_statements

On Fri, Sep 10, 2021 at 2:49 AM Michel SALAIS <msalais@msym.fr> wrote:
>
> I think that total_time in pg_stat_statements is cpu time + possible waits. So, can I say that:
>
> Total_sql_time = total_time + blk_read_time + blk_write_time
>
> Documentation is not clear at all on that.

In version 12 and below, total_time is the elapsed time between the execution start and stop, so it includes all
underlyingevents. That includes any IO activity, wait events or nested statements (if pg_stat_statemetns.track is set
toall).  This corresponds to the new total_exec_time field in version 13 and later. 


> Just to say that for PostgreSQL 13, total_time is replaced by “total_exec_time + total_plan_time”

Indeed, as this version also tracks planning activity.
--------------------------------------------------------------------------------
Hi,

I thaught that total_time (total_exec_time + total_plan_time) included I/O but when we have blk_read_time +
blk_write_time equals several times total_time it is difficult to continue to think that... 

So What is really total_time (total_exec_time + total_plan_time) ?




Re: sql execution time in pg_stat_statements

From
Tom Lane
Date:
"Michel SALAIS" <msalais@msym.fr> writes:
> I thaught that total_time (total_exec_time + total_plan_time) included I/O but when we have blk_read_time +
blk_write_time equals several times total_time it is difficult to continue to think that... 

That's an interesting report, but on the whole I'd be more inclined
to disbelieve the I/O timings than the overall time.  Can you create
a reproducible test case where this happens?  Also, exactly what
PG version and pg_stat_statements version are you using?

            regards, tom lane



Re: sql execution time in pg_stat_statements

From
Julien Rouhaud
Date:
On Sat, Sep 11, 2021 at 1:12 AM Michel SALAIS <msalais@msym.fr> wrote:
>
> I thaught that total_time (total_exec_time + total_plan_time) included I/O but when we have blk_read_time +
blk_write_time equals several times total_time it is difficult to continue to think that...
 

Maybe not that difficult.  If the queries use parallelism, the query
total execution time may be say 1 second, but if there were X workers
it could actually cumulate X+1 seconds of execution time, and
therefore reach more than 1 second of cumulated read/write time.



RE: sql execution time in pg_stat_statements

From
"Michel SALAIS"
Date:
Hi Tom,

I was out of this list for a while.
Unfortunately, I have now no access to the server where I have seen this.

Best regards

Michel SALAIS

-----Message d'origine-----
De : Tom Lane <tgl@sss.pgh.pa.us>
Envoyé : vendredi 10 septembre 2021 19:42
À : Michel SALAIS <msalais@msym.fr>
Cc : 'Julien Rouhaud' <rjuju123@gmail.com>; 'postgres performance list'
<pgsql-performance@postgresql.org>
Objet : Re: sql execution time in pg_stat_statements

"Michel SALAIS" <msalais@msym.fr> writes:
> I thaught that total_time (total_exec_time + total_plan_time) included I/O
but when we have blk_read_time + blk_write_time  equals several times
total_time it is difficult to continue to think that...

That's an interesting report, but on the whole I'd be more inclined to
disbelieve the I/O timings than the overall time.  Can you create a
reproducible test case where this happens?  Also, exactly what PG version
and pg_stat_statements version are you using?

            regards, tom lane