Quick 📸 on 🐘 active SQL from pg_stat_statements

This is a quick query on pg_stat_statements to get a real-time overview of queries within a 30 second snapshot.

Note that it relies on the execution plan running the two CTEs one after the other, and joining pg_sleep() after the left table. I've used it on YugabyteDB 2.9 which is PostgreSQL 11.2 compatible. It is not excluded that it has to be modified one day if the query planner does smart transformations on it. I'll add hints if that's the case.

with 
b as ( -- begin snapshot
select clock_timestamp() as "snap_time",* 
 from pg_stat_statements , pg_sleep(30) --> 30 second snapshots
),
e as ( -- end snapshot
 select clock_timestamp() as "snap_time",* 
 from pg_stat_statements , pg_sleep(0) 
),
u as ( -- union all as timeseries
 select * from e union all select * from b
),
d as ( -- delta values from cumulative metrics
 select
  snap_time
  ,extract( epoch from snap_time-lag(snap_time)
   over(query_cumulative_stats)) as seconds
  ,total_time-lag(total_time)
   over(query_cumulative_stats ) as total_time
  ,calls-lag(calls)
   over(query_cumulative_stats ) as calls
  ,query
 from u 
 window query_cumulative_stats as (
  partition by userid,dbid,queryid,query order by snap_time
  )
) select -- final output
  round((calls/seconds)::numeric,2) as "call/sec",
  round(((total_time/1000)/seconds)::numeric,1) as "AAS",
  date_trunc('second',(total_time/1000)* interval '1 second')
   as total_time,
  calls as "total calls", query 
 from d where calls>0 and total_time >0
 order by "AAS" desc fetch first 15 rows only;

I use CTE to isolate the steps: b is the beginning snapshot, e the end snapshot gathered after a few seconds (by joining to pg_sleep), u is the union of all (snapshots are distinguished by snap_time), d is the "delta" values computed with lag() function.

Here is an example of output:

 call/sec | AAS | total_time | total calls |                                                                                                          query

----------+-----+------------+-------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
     0.70 | 0.5 | 00:00:15   |          21 | SELECT * FROM T4FJ_WORK  WHERE TABLENAME = $1
     0.37 | 0.2 | 00:00:06   |          11 | SELECT RECID FROM T4FJ_PROCESS WHERE TABLEID = $1 AND PROCESSID = $2 AND THREADID = $3
     0.27 | 0.1 | 00:00:04   |           8 | SELECT RECID FROM T4FJ_WORK WHERE STATUS !=$2 AND TABLENAME = $1 FOR UPDATE
     0.07 | 0.0 | 00:00:01   |           2 | SELECT COUNT(RECID) FROM T4FJ_PROCESS WHERE TABLEID = $1 AND STATUS =$2 AND PROCESSID != $3
     0.07 | 0.0 | 00:00:00   |           2 | SELECT MAX(PROCESSEDROWS) FROM T4FJ_PROCESS WHERE TABLEID = $1 AND (STATUS = $2 OR STATUS = $3)
     0.07 | 0.0 | 00:00:00   |           2 | SELECT RECID FROM T4FJ_WORK WHERE STATUS = $1 AND TABLENAME = $2
     0.30 | 0.0 | 00:00:00   |           9 | INSERT INTO T4FJ_PROCESS (TABLEID,  THREADID, HOSTNAME, PROCESSID, PROCESSUSER,THREADSTART,THREADEND,STATUS,PROCESSEDROWS,NOOFRECS,PROCESSTIME,FINISHEDDATE,RECID )  VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13)
     1.50 | 0.0 | 00:00:00   |          45 | ROLLBACK TO SAVEPOINT PGJDBC_AUTOSAVE
     0.30 | 0.0 | 00:00:00   |           9 | UPDATE T4FJ_WORK SET STATUS = $1, NOOFRECS = $2,PROCESSTIME = $3,MAXRECS = $4,FINISHEDDATE = $5 WHERE RECID = $6
     2.46 | 0.0 | 00:00:00   |          74 | BEGIN
     8.56 | 0.0 | 00:00:00   |         257 | SAVEPOINT PGJDBC_AUTOSAVE
     0.07 | 0.0 | 00:00:00   |           2 | SELECT COUNT(*) FROM "D_F_FT_XXX_XXXXXXXXX"
     0.07 | 0.0 | 00:00:01   |           2 | SELECT RECID FROM T4FJ_PROCESS WHERE TABLEID = $1 AND PROCESSID = $2 AND THREADID = $3 AND STATUS = $4
     1.90 | 0.0 | 00:00:00   |          57 | COMMIT
     0.37 | 0.0 | 00:00:00   |          11 | UPDATE T4FJ_PROCESS SET THREADSTART = $1,THREADEND = $2,STATUS = $3,NOOFRECS = $4,PROCESSEDROWS = $5,PROCESSTIME = $6,FINISHEDDATE = $7 WHERE RECID = $8
(15 rows)

yugabyte=#

The first row can be read as: within the 30 seconds (defined in the query), SELECT * FROM T4FJ_WORK WHERE TABLENAME = $1 has been executed 21 times (on average 0.7 calls per second) for a total time of 15 seconds. This means that there were 0.5 Average Active Sessions (AAS) executing this statement.

The goal is to have a quick look when having only psql access. I guess any PostgreSQL database has the pg_stat_statment extension installed. We enable it by default in YugabyteDB.