Find the statement currently running in my PL/pgSQL code block

Question

Is there a way to figure out which statement from the block is currently running in Postgres? (Even extra extensions or tracing might be an option)

Below is the quick way to reproduce but in real scenario the block is way more complicated.

do
$$ 
declare
  x int;
  c char;
  d int := 3;
begin
  select pg_sleep(d), 11112 into c, x;
   
  select pg_sleep(d), 11113 into c, x;

  select pg_sleep(d), 11114 into c, x;
end
$$;

pg_stat_statements / pg_stat_activity show only the main block, not specific queries.

Answer 1

The simple solution is to throw in, at positions you want to know ...

RAISE NOTICE 'Starting query 2 ...';

Obviously only visible for the same session.

auto_explain

You can achieve that for all statements without altering the code block using auto_explain. It's a bit heavy-handed because it also reports the query plan for each. (Very short for the given example, but may get quite verbose for complex queries.) But I am not aware of a simpler way. See:

• Get query plan for SQL statement nested in a PL/pgSQL function

Demo:

test=> SET ROLE postgres;
SET
test=# LOAD 'auto_explain';
LOAD
test=# SET auto_explain.log_nested_statements = ON; -- statements inside code blocks
SET
test=# SET auto_explain.log_min_duration = 1;       -- exclude queries taking < 1 ms
SET
test=# SET client_min_messages TO log;              -- get log msg in client
SET
test=# do
test-# $$ 
test$# declare
test$#   x int;
test$#   c char;
test$#   d int := 2;
test$# begin
test$#   select pg_sleep(d), 1 into c, x;
test$# 
test$#   select pg_sleep(d), 2 into c, x;
test$# 
test$#   select pg_sleep(d), 3 into c, x;
test$# end
test$# $$;
LOG:  statement: do
$$ 
declare
  x int;
  c char;
  d int := 2;
begin
  select pg_sleep(d), 1 into c, x;

  select pg_sleep(d), 2 into c, x;

  select pg_sleep(d), 3 into c, x;
end
$$;
LOG:  duration: 2002.483 ms  plan:
Query Text: select pg_sleep(d), 1
Result  (cost=0.00..0.01 rows=1 width=8)
LOG:  duration: 2002.134 ms  plan:
Query Text: select pg_sleep(d), 2
Result  (cost=0.00..0.01 rows=1 width=8)
LOG:  duration: 2002.423 ms  plan:
Query Text: select pg_sleep(d), 3
Result  (cost=0.00..0.01 rows=1 width=8)
LOG:  duration: 6009.303 ms
DO
test=#

Answer 2

In fact, pg_stat_statements does have info about statements inside the block (when pg_stat_statements.track = all). However, they are normalized so we cannot see actual values. Anyway, we can monitor what is going on by checking calls.

postgres=# select queryid, query, calls from pg_stat_statements where query ~ 'pg_sleep' and not query ~ 'do';
       queryid        |         query          | calls 
----------------------+------------------------+-------
 -2604025637555979379 | select pg_sleep(d), $5 |    43
(1 row)

The ideal solution though is to use pgsentinel.

It shows what is running at the moment as well associated top level block.

postgres=# select ash_time, query, queryid --, top_level_query
postgres-# from pg_active_session_history
postgres-# where ash_time > timestamp '2024-10-26 13:40:00';
           ash_time            |           query           |       queryid        
-------------------------------+---------------------------+----------------------
 2024-10-26 13:41:00.726212+01 | select pg_sleep(d), 11112 | -2604025637555979379
 2024-10-26 13:41:01.730933+01 | select pg_sleep(d), 11112 | -2604025637555979379
 2024-10-26 13:41:02.733903+01 | select pg_sleep(d), 11112 | -2604025637555979379
 2024-10-26 13:41:03.737171+01 | select pg_sleep(d), 11113 | -2604025637555979379
 2024-10-26 13:41:04.74009+01  | select pg_sleep(d), 11113 | -2604025637555979379
 2024-10-26 13:41:05.742954+01 | select pg_sleep(d), 11113 | -2604025637555979379
 2024-10-26 13:41:06.748392+01 | select pg_sleep(d), 11114 | -2604025637555979379
 2024-10-26 13:41:07.75082+01  | select pg_sleep(d), 11114 | -2604025637555979379
 2024-10-26 13:41:08.754098+01 | select pg_sleep(d), 11114 | -2604025637555979379
(9 rows)