In Oracle, you can conveniently retrieve this information using an ASH report. In PostgreSQL, the pg_stat_statements view is analogous to Oracle's v$sqlarea, as it stores query execution statistics since the last reset. Because these statistics are cumulative, answering the question requires sampling pg_stat_statements twice—at the beginning and end of a chosen interval—and then calculating the delta metrics.
I developed a SQL script to implement this concept by leveraging PostgreSQL's temporary table feature. The script samples pg_stat_statements twice over a specific interval (10 seconds in the example below), saves the results into temporary tables, and runs a query to identify the top SQL statements based on total execution time.
The sample script named pss.sql is shown as follows:
someip.vpc.myco.com:/misc/denis/pgcheck [] $ cat sql/pss.sql
create temp table tmp_pss_ as select 1 as snap_id, now() as sample_time, d.* from pg_stat_statements d where 1=0;
insert into tmp_pss_ select 1, now(), d.* from pg_stat_statements d ;
select pg_sleep(10);
insert into tmp_pss_ select 2, now(), d.* from pg_stat_statements d ;
\pset format wrapped
\pset columns 150
\x
select usename, queryid, query_text, duration_s, num_calls, num_rows, total_elapsed_time_ms,
case num_calls
when 0 then total_elapsed_time_ms
else total_elapsed_time_ms/num_calls end as ms_per_call
, (num_blk_hits + num_blk_read)/nullif(num_calls,0) as logical_reads_per_call
, 100*num_blk_hits/nullif(num_blk_hits + num_blk_read,0) as hit_percent
from
(
select u.usename, b.queryid
, b.query as query_text
, extract ( epoch from (e.sample_time - b.sample_time) ) as duration_s
, e.calls - b.calls as num_calls
, e.rows - b.rows as num_rows
, e.shared_blks_hit - b.shared_blks_hit as num_blk_hits
, e.shared_blks_read - b.shared_blks_read as num_blk_read
, round(e.total_time - b.total_time) as total_elapsed_time_ms
from ( select * from tmp_pss_ where snap_id=1 ) b join
( select * from tmp_pss_ where snap_id=2 ) e on e.userid=b.userid and e.queryid=b.queryid and e.dbid=b.dbid join
pg_user u on u.usesysid=b.userid
order by total_elapsed_time_ms desc limit 10
) t;
\x
someip.vpc.myco.com:/misc/denis/pgcheck [] $ pgconn.sh ini/appa_prusr.ini sql/pss.sql
---------------------------Your connection inputs---------------------------
Endpoint: vcm-appa-east1a-postgre-prod-tpa-2.cxocijv8i513.us-east-1.rds.amazonaws.com
Port : 5432
User : appadbusr1
Database: prusrprdrds
---------------------------------------------------------------------------
------------------- You run the following sql statments ------------
create temp table tmp_pss_ as select 1 as snap_id, now() as sample_time, d.* from pg_stat_statements d where 1=0;
insert into tmp_pss_ select 1, now(), d.* from pg_stat_statements d ;
select pg_sleep(10);
insert into tmp_pss_ select 2, now(), d.* from pg_stat_statements d ;
\pset format wrapped
\pset columns 150
\x
select usename, queryid, query_text, duration_s, num_calls, num_rows, total_elapsed_time_ms,
case num_calls
when 0 then total_elapsed_time_ms
else total_elapsed_time_ms/num_calls end as ms_per_call
, (num_blk_hits + num_blk_read)/nullif(num_calls,0) as logical_reads_per_call
, 100*num_blk_hits/nullif(num_blk_hits + num_blk_read,0) as hit_percent
from
(
select u.usename, b.queryid
, b.query as query_text
, extract ( epoch from (e.sample_time - b.sample_time) ) as duration_s
, e.calls - b.calls as num_calls
, e.rows - b.rows as num_rows
, e.shared_blks_hit - b.shared_blks_hit as num_blk_hits
, e.shared_blks_read - b.shared_blks_read as num_blk_read
, round(e.total_time - b.total_time) as total_elapsed_time_ms
from ( select * from tmp_pss_ where snap_id=1 ) b join
( select * from tmp_pss_ where snap_id=2 ) e on e.userid=b.userid and e.queryid=b.queryid and e.dbid=b.dbid join
pg_user u on u.usesysid=b.userid
order by total_elapsed_time_ms desc limit 10
) t;
\x
------------------- end -------------------------------------------
Timing is on.
SELECT 0
Time: 8.773 ms
INSERT 0 4816
Time: 12.022 ms
pg_sleep
----------
(1 row)
Time: 10004.895 ms (00:10.005)
INSERT 0 4952
Time: 11.980 ms
Output format is wrapped.
Target width is 150.
Expanded display is on.
-[ RECORD 1 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 2553995311
query_text | (SELECT * FROM PRUSR.COMP_REVENUE_NONCONTRACT WHERE ACCOUNT_NUM= I_ACCT_NUM AND COMP_TYPE = ? ORDER BY CRTD_TIMESTAMP)
duration_s | 10.017147
num_calls | 30
num_rows | 75
total_elapsed_time_ms | 55
ms_per_call | 1.83333333333333
logical_reads_per_call | 171
hit_percent | 100
-[ RECORD 2 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 3783259900
query_text | select * from prusr.SEL_ACCT_DTL2($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13) as result
duration_s | 10.017147
num_calls | 38
num_rows | 38
total_elapsed_time_ms | 45
ms_per_call | 1.18421052631579
logical_reads_per_call | 17
hit_percent | 100
-[ RECORD 3 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 274367736
query_text | (Select +
| A.ACCOUNT_NUM , +
| ACCOUNT_NAME, +
| ACCOUNT_TYPE , +
| CONTACT_FIRST_NAME , +
| CONTACT_LAST_NAME , +
| CONTACT_NUM , +
| EMAIL_ID , +
| PARENT_ID , +
| FIBER_READY_FLAG , +
| COMP_POINT , +
| BILLING_POINT , +
| ADDR_TYPE_FLAG, +
| COMP_ACCOUNT_ID , +
| BILLING_ACCOUNT_ID , +
| CAN , +
| MASTER_ORDER_NUM , +
| A.MSTR_AGREEMENT_NUM, +
| ORDER_ID , +
| ACCOUNT_STATUS , +
| VENDOR_ADDRESS_TYPE, +
| ACCOUNT_ACTIVE_DATE, +
| ACCOUNT_ACTVN_STATUS, +
| ACCOUNT_VALDN_STATUS, +
| AGREEMENT_SOURCE , +
| STATUS , +
| CONTACT_NUM_EXT , +
| ACCOUNT_ADDRESS_ID, +
| ADDRESS_TYPE , +
| STREET_ADDRESS_1, +
| STREET_ADDRESS_2 , +
| UNIT_TYPE , +
| UNIT_VALUE, +
| CITY , +
| STATE , +
| ZIP_CODE , +
| W9_FORM_ID, +
| VENDOR_ID , +
| VENDOR_SEQ_NUM , +
| LEASING_OFFICE_FLAG , +
| WF.VENDOR_ID AS LO_VENDOR_ID , +
| WF.VENDOR_SEQ_NUM AS LO_VENDOR_SEQ_NUM, +
| A.COMP_PROJECT_CODE AS PROJECT_CODE, +
| DIFF_PRD_STATUS, +
| CONTRACT_UNITS, +
| MDU_PROPERTY_ID, +
| BILL_CONTACT_FIRST_NAME , +
| BILL_CONTACT_LAST_NAME , +
| BILL_CONTACT_NUM , +
| BILL_EMAIL_ID, +
| BILL_CONTACT_NUM_EXT, +
| MARKETING_STATUS, +
| STATE_CODE, +
| ACTIVE_TO_PAY_COMM, +
| COMMISSION_START_DATE, +
| COMMISSION_END_DATE, +
| COMMISSION_SCHEDULE, +
| (SELECT COUNT(SRVC_ADDR_ID) FROM PRUSR.SERVICE_ADDRESS SA WHERE A.ACCOUNT_NUM=SA.HOA_ACCOUNT_NUM +
| AND VALDN_CODE >= ? AND SA.VALDN_CODE <= ?) AS VALID_ADDRESS_COUNT +
| FROM PRUSR.ACCOUNT A +
| LEFT JOIN PRUSR.ACCOUNT_ADDRESS AD ON A.ACCOUNT_NUM=AD.ACCOUNT_NUM +
| LEFT JOIN PRUSR.W9_FORM WF ON A.ACCOUNT_NUM=WF.ACCOUNT_NUM +
| WHERE A.ACCOUNT_NUM=I_ACCOUNT_NUM +
| order by ADDRESS_TYPE desc)
duration_s | 10.017147
num_calls | 38
num_rows | 19
total_elapsed_time_ms | 42
ms_per_call | 1.10526315789474
logical_reads_per_call | 158
hit_percent | 100
-[ RECORD 4 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 1011339641
query_text | select sv4.C41 ,sv4.O_SQLCODE ,sv4.O_SQLSTATE ,sv4.O_MESSAGE From PRUSR.SEL_COMM_DTL_V4(I_ACCOUNT_NUM) sv4
duration_s | 10.017147
num_calls | 36
num_rows | 36
total_elapsed_time_ms | 18
ms_per_call | 0.5
logical_reads_per_call | 9
hit_percent | 100
-[ RECORD 5 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 1590377131
query_text | SELECT TERM_DATE AS AGREEMENT_END_DATE , +
| (TERM_DATE - cast($1 as interval)) AS DUEL_MODE_PERIOD_BEGIN_DATE, +
| (TERM_DATE+ cast($2 as interval)) AS SERVICE_TERMINATION_DATE +
| FROM +
| PRUSR.TEMP_TERM_AGREEMENT WHERE ACCOUNT_NUM=$3 UNION SELECT +
| DATE_AGREEMENT_TERMINATED AS AGREEMENT_END_DATE , +
| (DATE_AGREEMENT_TERMINATED -cast($4 as interval) ) AS +
| DUEL_MODE_PERIOD_BEGIN_DATE, +
| (DATE_AGREEMENT_TERMINATED+cast($5 as interval)) AS SERVICE_TERMINATION_DATE FROM +
| PRUSR.TEMP_TERM_AGREEMENT_HIST +
| WHERE ACCOUNT_NUM= $6 UNION SELECT +
| DATE_REQUESTED AS AGREEMENT_END_DATE +
| , +
| (DATE_REQUESTED -cast($7 as interval)) AS DUEL_MODE_PERIOD_BEGIN_DATE, +
| (DATE_REQUESTED+cast($8 as interval)) AS SERVICE_TERMINATION_DATE FROM +
| PRUSR.TEMP_TERM_AGREEMENT_FALLOUT WHERE ACCOUNT_NUM= $9
duration_s | 10.017147
num_calls | 19
num_rows | 0
total_elapsed_time_ms | 12
ms_per_call | 0.631578947368421
logical_reads_per_call | 68
hit_percent | 100
-[ RECORD 6 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 1137626341
query_text | select sv5.C41, sv5.C7 ,sv5.O_SQLCODE ,sv5.O_SQLSTATE ,sv5.O_MESSAGE From PRUSR.SEL_COMM_DTL_V4(I_ACCOUNT_NUM) sv5
duration_s | 10.017147
num_calls | 10
num_rows | 10
total_elapsed_time_ms | 3
ms_per_call | 0.3
logical_reads_per_call | 8
hit_percent | 100
-[ RECORD 7 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 3486729767
query_text | SELECT GRACE_PERIOD FROM PRUSR.AGREEMENT WHERE MSTR_AGREEMENT_NUM IN (SELECT MSTR_AGREEMENT_NUM FROM PRUSR.ACCOUNT WHERE ACC.
|.OUNT_NUM=$1)
duration_s | 10.017147
num_calls | 38
num_rows | 38
total_elapsed_time_ms | 2
ms_per_call | 0.0526315789473684
logical_reads_per_call | 7
hit_percent | 100
-[ RECORD 8 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 168909306
query_text | SELECT AP.* FROM PRUSR.AGREEMENT_PRODUCTS +
| AP , PRUSR.ACCOUNT A WHERE A.MSTR_AGREEMENT_NUM = +
| AP.MSTR_AGREEMENT_NUM AND A.ACCOUNT_NUM = $1 AND AP.ACTIVE +
| = ? ORDER +
| BY PRODUCT_ID
duration_s | 10.017147
num_calls | 19
num_rows | 0
total_elapsed_time_ms | 1
ms_per_call | 0.0526315789473684
logical_reads_per_call | 6
hit_percent | 100
-[ RECORD 9 ]----------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 3140360803
query_text | SELECT +
| COMMSN_AUTO_UPD FROM PRUSR.AGREEMENT AG ,PRUSR.ACCOUNT A +
| WHERE A.MSTR_AGREEMENT_NUM=AG.MSTR_AGREEMENT_NUM +
| AND A.ACCOUNT_NUM= I_ACCOUNT_NUM
duration_s | 10.017147
num_calls | 38
num_rows | 19
total_elapsed_time_ms | 1
ms_per_call | 0.0263157894736842
logical_reads_per_call | 5
hit_percent | 100
-[ RECORD 10 ]---------+-----------------------------------------------------------------------------------------------------------------------------
usename | prusradm
queryid | 2723406496
query_text | SELECT COUNT(*) FROM PRUSR.COMP_AGREEMENT WHERE ACCOUNT_NUM=I_ACCT_NUM
duration_s | 10.017147
num_calls | 47
num_rows | 47
total_elapsed_time_ms | 1
ms_per_call | 0.0212765957446809
logical_reads_per_call | 3
hit_percent | 100
Time: 5204.974 ms (00:05.205)
Expanded display is off.
I have also incorporated this logic into pgcheck, a tool I developed. Using pgcheck makes it even easier to specify the sampling duration and the number of top queries to retrieve. The example below shows a 5-minute sample for the top 5 queries:
someip.vpc.myco.com:/misc/denis/pgcheck [] $ pgcheck.py ini/appa_prusr.ini -psss --limit 5 --delta 300
Trying to obtain connection info from the configuation file ini/appa_prusr.ini ...
**************************** SQL TEXT ********************************
select usename, queryid, query_text, duration_s, num_calls, num_rows, total_elapsed_time_ms,
case num_calls
when 0 then total_elapsed_time_ms
else total_elapsed_time_ms/num_calls end as ms_per_call,
(num_blk_hits + num_blk_read)/nullif(num_calls,0) as logical_reads_per_call,
100*num_blk_hits/nullif(num_blk_hits + num_blk_read,0) hit_percent
,num_blk_hits
,num_blk_read
,begin_snap_time
from
(
select u.usename, b.queryid
, substr(b.query, 1,500) query_text
, extract ( epoch from (e.sample_time - b.sample_time) ) as duration_s
, e.calls - b.calls as num_calls
, e.rows - b.rows as num_rows
, e.shared_blks_hit - b.shared_blks_hit as num_blk_hits
, e.shared_blks_read - b.shared_blks_read as num_blk_read
, round(e.total_time - b.total_time) as total_elapsed_time_ms
, b.sample_time as begin_snap_time
from ( select * from tmp_pss_ where snap_id=1 ) b join
( select * from tmp_pss_ where snap_id=2 ) e on e.userid=b.userid and e.queryid=b.queryid and e.dbid=b.dbid join
pg_user u on u.usesysid=b.userid
order by total_elapsed_time_ms desc limit 5) t
***********************************************************************
================= Sampling top 5 SQLs from pg_stat_statment view for duration 300s order by total elapsed time =====================
usename | prusradm
queryid | 2553995311
begin_snap_time | 2019-07-30 21:36:34.001250+00:00
duration secs | 300.07
num_calls | 571
num_row | 1519
total elapsed_time_ms | 1050.0
ms_per_call | 1.83887915937
logical_reads_per_call | 170
num_blk_hits | 97335
num_blk_reads | 0
hit_percent | 100
query_text |
(SELECT * FROM PRUSR.COMP_REVENUE_NONCONTRACT WHERE ACCOUNT_NUM= I_ACCT_NUM AND COMP_TYPE = ? ORDER BY CRTD_TIMESTAMP)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
usename | prusradm
queryid | 274367736
begin_snap_time | 2019-07-30 21:36:34.001782+00:00
duration secs | 300.07
num_calls | 716
num_row | 394
total elapsed_time_ms | 787.0
ms_per_call | 1.09916201117
logical_reads_per_call | 123
num_blk_hits | 88139
num_blk_reads | 0
hit_percent | 100
query_text |
(Select
A.ACCOUNT_NUM ,
ACCOUNT_NAME,
ACCOUNT_TYPE ,
CONTACT_FIRST_NAME ,
CONTACT_LAST_NAME ,
CONTACT_NUM ,
EMAIL_ID ,
PARENT_ID ,
FIBER_READY_FLAG ,
COMP_POINT ,
BILLING_POINT ,
ADDR_TYPE_FLAG,
COMP_ACCOUNT_ID ,
BILLING_ACCOUNT_ID ,
CAN ,
MASTER_ORDER_NUM ,
A.MSTR_AGREEMENT_NUM,
ORDER_ID ,
ACCOUNT_STATUS ,
VENDOR_ADDRESS_TYPE,
ACCOUNT_ACTIVE_DATE,
ACCOUNT_ACTVN_STATUS,
ACCOUNT_VALDN_STATUS,
AGREEMENT_SOURCE ,
STATUS ,
CONTACT_NUM_EXT ,
ACCOUNT_ADDRESS_ID,
ADDRESS_TYPE ,
STREET_ADDRESS_1,
STR
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
usename | prusradm
queryid | 3783259900
begin_snap_time | 2019-07-30 21:36:34.003112+00:00
duration secs | 300.07
num_calls | 716
num_row | 716
total elapsed_time_ms | 567.0
ms_per_call | 0.791899441341
logical_reads_per_call | 18
num_blk_hits | 12934
num_blk_reads | 0
hit_percent | 100
query_text |
select * from prusr.SEL_ACCT_DTL2($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13) as result
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
usename | prusradm
queryid | 1011339641
begin_snap_time | 2019-07-30 21:36:34.001504+00:00
duration secs | 300.07
num_calls | 643
num_row | 643
total elapsed_time_ms | 223.0
ms_per_call | 0.346811819596
logical_reads_per_call | 11
num_blk_hits | 7226
num_blk_reads | 0
hit_percent | 100
query_text |
select sv4.C41 ,sv4.O_SQLCODE ,sv4.O_SQLSTATE ,sv4.O_MESSAGE From PRUSR.SEL_COMM_DTL_V4(I_ACCOUNT_NUM) sv4
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
usename | prusradm
queryid | 1590377131
begin_snap_time | 2019-07-30 21:36:34.000081+00:00
duration secs | 300.07
num_calls | 358
num_row | 0
total elapsed_time_ms | 216.0
ms_per_call | 0.603351955307
logical_reads_per_call | 68
num_blk_hits | 24344
num_blk_reads | 0
hit_percent | 100
query_text |
SELECT TERM_DATE AS AGREEMENT_END_DATE ,
(TERM_DATE - cast($1 as interval)) AS DUEL_MODE_PERIOD_BEGIN_DATE,
(TERM_DATE+ cast($2 as interval)) AS SERVICE_TERMINATION_DATE
FROM
PRUSR.TEMP_TERM_AGREEMENT WHERE ACCOUNT_NUM=$3 UNION SELECT
DATE_AGREEMENT_TERMINATED AS AGREEMENT_END_DATE ,
(DATE_AGREEMENT_TERMINATED -cast($4 as interval) ) AS
DUEL_MODE_PERIOD_BEGIN_DATE,
(DATE_AGREEMENT_TERMINATED+cast($5 as interval)) AS SERVICE_TERMINATION_DATE FROM
PRUSR.TEMP_TERM_AGREEMENT_HIST
WHERE ACC
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Summary
PostgreSQL's pg_stat_statements view tracks cumulative statistics; therefore, by sampling this view twice over a specific interval, you can calculate delta metrics to identify the most resource-intensive SQL queries. This offers an effective troubleshooting approach similar to Oracle's ASH reports.
No comments:
Post a Comment