Re: Understand time taken by individual SQL statements in a procedure

Hi,

On Sat, Jun 03, 2023 at 12:48:37PM +0530, Satalabaha Postgres wrote:
> Hi Listers,
>
> We would like to determine how long it takes for each SQL statement to
> execute within a long-running procedure. I tried to see if
> pg_stat_statements could offer any insight into the matter. But I was
> unable to locate any. Is this even possible?

pg_stat_statements can tell you about queries executed inside a procedure, as
long as you set pg_stat_statements.track = 'all':

rjuju=# select pg_stat_statements_reset();
pg_stat_statements_reset
--------------------------

(1 row)

rjuju=# set pg_stat_statements.track = 'all';
SET

rjuju=# do
$$
begin
perform count(*) from pg_class;
perform pg_sleep(2);
end;
$$ language plpgsql;
DO

rjuju=# select query, total_exec_time from pg_stat_statements;
query | total_exec_time
--------------------------------------+---------------------
SELECT count(*) from pg_class | 0.13941699999999999
do +| 2001.903792
$$ +|
begin +|
perform count(*) from pg_class; +|
perform pg_sleep(2); +|
end; +|
$$ language plpgsql |
SELECT pg_sleep($1) | 2000.227249
[...]

If that's not enough, and if your procedures are written in plpgsql you could
also look at plpgsql_check: https://github.com/okbob/plpgsql_check. It has an
integrated profiler (see https://github.com/okbob/plpgsql_check#profiler) that
works very well.

> unable to locate any. Is this even possible? How can we also determine the
> precise SQL execution plan used when a SQL is run from an application? The
> query runs without issue when we try to execute it directly, but it takes
> longer to run when an application is used.

You could look at auto_explain for that:
https://www.postgresql.org/docs/current/auto-explain.html.