Thread: 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.