Thursday, August 01, 2019

PostgreSQL - Sampling pg_stat_statements

Have you ever needed to identify the top queries executed in PostgreSQL over the last 30 seconds or 5 minutes? 

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


Here is a demonstration of the 10-second sampling script running against a production Aurora PostgreSQL RDS instance (note: real names have been masked):


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
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


I hope this post offers a useful approach for your PostgreSQL performance monitoring and troubleshooting needs! 

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.

Tuesday, February 13, 2018

Surviving the Grid Infrastructure Jan 2018 PSU Patch

Lessons from the Trenches: Surviving the Grid Infrastructure Jan 2018 PSU Patch

Recently, I set out on a routine maintenance journey: applying the latest Patch Release Update (GI RU 12.2.0.1.180116) across a fresh Grid Infrastructure 12.2 and RDBMS setup with several RAC databases. What seemed like a straightforward task turned into a great learning experience full of unexpected hurdles, workarounds, and practical troubleshooting insights. Here is the story of how it went and what to look out for on your next patching adventure!

1. Mind the OPatch Version: Avoid the Wallet Trap

Rule number one: always grab the absolute latest version of OPatch before starting. While the patch readme mentioned that OPatch version 12.2.0.1.6 or later was sufficient, using 12.2.0.1.6 threw a surprising error:

OPATCHAUTO-68021: The following argument(s) are required: [-wallet]

A quick check on My Oracle Support (Doc ID 2270185.1) revealed that OPatchauto 12.2.0.1.6 required creating a wallet file with passwords on every single node. Fortunately, upgrading to OPatch version 12.2.0.10 completely removed this mandatory wallet requirement, saving a ton of unnecessary setup time.

2. Clean Up Your Central Inventory

Because opatchauto relies heavily on the inventory.xml file (found in <inventory_loc>/ContentsXML), it is vital to ensure that your inventory only contains active, intended homes—in my case, just the GI 12.2 and RDBMS 12.2 homes.

If you have stale or unneeded homes registered, clean them up beforehand using commands like:

/grid/app/12.2.0/grid/oui/bin/runInstaller -silent -detachHome ORACLE_HOME="/opt/oracle/oraclex/product/12.2.0/db_1"

/grid/app/12.2.0/grid/oui/bin/runInstaller -silent -detachHome ORACLE_HOME="/opt/oracle/agent/agent_13.2.0.0.0"

Double-check that your cluster node lists inside inventory.xml aren't empty. If node entries are missing, update them with:

/grid/app/12.2.0/grid/oui/bin/runInstaller -updateNodeList ORACLE_HOME=/grid/app/12.2.0/grid "CLUSTER_NODES=<node1,node2,node3,...>"

3. Handle ACFS Filesystems with Care

Another critical step involves ACFS (ASM Cluster File System). Per Oracle Support Doc ID 1591616.1, active ACFS filesystems must be manually unmounted before starting opatchauto. Here is the recommended sequence:

1. Locate the ACFS resources:

# crsctl stat res -w "TYPE = ora.acfs.type" -p | grep VOLUME

2. Stop the filesystem resource as root:

# srvctl stop filesystem -d <volume device path> -n <node>

4. What Happens When ACFS Isn't Stopped? (And How to Recover)

In one instance, an ACFS filesystem was left running by mistake. Sure enough, the patch run failed towards the end with ADVM/ACFS uninstallation errors and an exit code 42:

2018/01/31 22:40:44 CLSRSC-205: Failed to uninstall ADVM/ACFS

OPATCHAUTO-68061: The orchestration engine failed with return code 1

opatchauto failed with error code 42

If you encounter this lockup, don't panic! Here is the recovery roadmap that got everything back on track:

1. Disable CRS as root: crsctl disable crs

2. Reboot the node to clear any busy device states.

3. Re-enable CRS once back online: crsctl enable crs

4. Resume patching: opatchauto resume

5. Check cluster resources. If ora.mgmtdb is offline, bring it up using: srvctl start mgmtdb

Summary: Key Takeaways

Patching complex RAC environments can be unpredictable, but taking a proactive approach makes all the difference. Remember these core guidelines for your next GI RU patching cycle:

  • Always update OPatch first: Using the latest build (12.2.0.10+) bypasses unnecessary requirements like wallet creation.
  • Keep your inventory clean: Detach obsolete ORACLE_HOMEs and verify node lists before invoking opatchauto.
  • Unmount ACFS before patching: Safely stop ACFS filesystems to prevent driver uninstallation lockups mid-patch.

Know your recovery procedure: If opatchauto fails due to busy devices, a quick CRS disable, node reboot, and opatchauto resume will save the day.

Wednesday, March 09, 2016

MariaDB - a surprise dependent subquery execution plan

Welcome myself into the MySQL world. While working with MariaDB 10.0.21, there are two queries as shown below, one uses alias and the other does not, seems to me they should be no difference in terms of functionality or performance.

-- query 1 with alias a and b
delete a FROM mydb.v_audit_info a 
       WHERE a.api_seq in  
                (SELECT cart_line_seq
                   FROM mydb.v_shopping_cart_item b
                  WHERE cart_seq = 127883 );
-- query 2 without alias a and b
delete  FROM mydb.v_audit_info  
       WHERE api_seq in  
                (SELECT cart_line_seq
                   FROM mydb.v_shopping_cart_item 
                  WHERE cart_seq = 127883 );


However, when I check the execution plan, I get quite different results: -- query 1
+------+-------------+-------+------+-----------------------------------------------------------+---------------------------+---------+-----------------------------+------+-------------+
| id   | select_type | table | type | possible_keys                                             | key                       | key_len | ref                         | rows | Extra       |
+------+-------------+-------+------+-----------------------------------------------------------+---------------------------+---------+-----------------------------+------+-------------+
|    1 | PRIMARY     | b     | ref  | PRIMARY,v_shopping_cart_item_udx1,idx2_shopping_cart_item | v_shopping_cart_item_udx1 | 9       | const                       |    1 | Using index |
|    1 | PRIMARY     | a     | ref  | idx1_audit_info                                           | idx1_audit_info           | 9       | mydb.b.cart_line_seq |    3 |             |
+------+-------------+-------+------+-----------------------------------------------------------+---------------------------+---------+-----------------------------+------+-------------+

-- query 2
+------+--------------------+----------------------+-----------------+-----------------------------------------------------------+---------+---------+------+-------+-------------+
| id   | select_type        | table                | type            | possible_keys                                             | key     | key_len | ref  | rows  | Extra       |
+------+--------------------+----------------------+-----------------+-----------------------------------------------------------+---------+---------+------+-------+-------------+
|    1 | PRIMARY            | v_audit_info         | ALL             | NULL                                                      | NULL    | NULL    | NULL | 60646 | Using where |
|    2 | DEPENDENT SUBQUERY | v_shopping_cart_item | unique_subquery | PRIMARY,v_shopping_cart_item_udx1,idx2_shopping_cart_item | PRIMARY | 8       | func |     1 | Using where |
+------+--------------------+----------------------+-----------------+-----------------------------------------------------------+---------+---------+------

In the execution plan for query 1, we first execute the subquery and obtain a list of cart_line_seq and then access the v_audit_info with primary key.

In the execution plan for query 2, the subquery becomes dependent, we need to scan 60646 rows from v_audit_info and for each row, checking the condition in the subquery.

Using the profiling, it can clearly see the huge difference in Duration:

+----------+------------+--------------------------------------------------------------------+
| Query_ID | Duration   | Query                                                                                                                                                                                                              |
+----------+------------+--------------------------------------------------------------------+
|        1 | 0.00331659 | delete a FROM mydb.v_audit_info a
       WHERE a.api_seq in
                (SELECT cart_line_seq
                   FROM mydb.v_shopping_cart_item b
                  WHERE cart_seq = 127883 ) |
....


|       13 | 0.23299025 | delete  FROM mydb.v_audit_info
       WHERE api_seq in
                (SELECT cart_line_seq
                   FROM mydb.v_shopping_cart_item
                  WHERE cart_seq = 127883 )      |
+----------+------------+-------------------------------------------------------------------

Don't know why,but certainly I will suggest using the alias version.

Sunday, December 13, 2015

MySQL Stored Procedure Programming Best Practices

MySQL Stored Procedure Programming Best Practices

Technical Specification & Development Guidelines

Version: 3.0

Purpose: Establish standard development practices and guidelines for team members writing MySQL stored programs.

Document History

  • 11/10/2015 (v3.0): Updated guidelines and examples (Denis)
  • 09/21/2015 (v1.0): Initial draft (Denis)

References

1. Lightweight Debugging Interface

When dedicated commercial or open-source debugging tools are unavailable, use a simple logging approach consisting of a debug table and logging routines (see Appendix A).

  1. Setup: Create a debug table and logging procedures (Appendix A).
  2. Usage: Call the debug_msg or debug_msg_f routine inside stored programs to log output (Appendices B and C).

2. Unit Testing via Command-Line Client

For every stored program, maintain a corresponding SQL script containing unit tests executable via the MySQL command-line client. Only integrate routines into application code (e.g., Java) after all command-line tests pass successfully.

For example, a test script for get_geocode_by_zip (Appendix B) can be structured as follows:

//*

  Test script: get_geocode_by_zip.tst

  Procedure signature:

    CREATE PROCEDURE myapp_admin.get_geocode_by_zip(

      IN  p_zip         VARCHAR(10),

      IN  p_range       VARCHAR(10),

      OUT p_geocode_o   VARCHAR(20)

    )

*/

SET @p_geocode_o = '0';

-- Test 1: Valid inputs

CALL myapp_admin.get_geocode_by_zip('01066', '0601', @p_geocode_o);

SELECT @p_geocode_o;

-- Test 2: Null range parameter (allowed)

CALL myapp_admin.get_geocode_by_zip('01096', NULL, @p_geocode_o);

SELECT @p_geocode_o;

-- Test 3: Null zip parameter (invalid input validation check)

CALL myapp_admin.get_geocode_by_zip(NULL, NULL, @p_geocode_o);

SELECT @p_geocode_o;

Executing this script produces console debug output confirming behavior:

$$ mysql -u root myapp_admin < get_geocode_by_zip.tst

** DEBUG:

** p_range is 0601

@p_geocode_o

US2501500000

** DEBUG:

** p_range is NULL

@p_geocode_o

US2501500000

** DEBUG:

** p_range is NULL

@p_geocode_o

NULL

3. Exception Handling

In MySQL 5.6 and later, leverage GET DIAGNOSTICS within exception handlers to extract detailed error metadata:

DECLARE EXIT HANDLER FOR SQLEXCEPTION

BEGIN

  GET DIAGNOSTICS CONDITION 1

    @sqlstate = RETURNED_SQLSTATE,

    @errno    = MYSQL_ERRNO,

    @text     = MESSAGE_TEXT;

  SET @full_error = CONCAT('ERROR ', @errno, ' (', @sqlstate, '): ', @text);

  SELECT @full_error;

  -- CALL debug_msg(@enabled, @full_error);

END;

4. Package Emulation using Dedicated Schemas

Because MySQL does not natively support Oracle PL/SQL packages, emulate package logical grouping by creating a dedicated schema (database) to group related procedures, functions, and shared objects.

5. Naming Conventions & Style Guide

  • Casing: All database, table, column, procedure, and function identifiers must be in lowercase.
  • Word Separation: Use snake_case (underscores) to improve readability (e.g., get_geocode_by_zip).
  • Parameters: Prefix with p_:
  • Input parameters: p_<name>
  • Output parameters: p_<name>_o
  • Input/Output parameters: p_<name>_io
  • Local Variables: Prefix with l_ (e.g., l_geocode).
  • Cursors: Maintain consistency across the project by using either a cur_ prefix or a _cur suffix (e.g., cur_customer or customer_cur).
  • Functions: Prefix function names with f_ (e.g., f_geocode_by_zip).
  • Loop Labels: Append _loop or prepend loop_ (e.g., dept_loop).
  • Temporary Tables: Use _gtt for global temporary tables shared across multiple routines, and _tmp for tables scoped to a single routine.
  • Header Comments: Include a standard header comment block for every routine containing Purpose, Inputs, Outputs, Dependencies, and Modifications.
  • Code Formatting: Use standard SQL formatters (e.g., Toad for MySQL) to maintain consistent indentation and layout.

6. Best Practices

  • Reset Cursor Handlers: Always reset the NOT FOUND flag variable after completing a cursor loop.

DECLARE CONTINUE HANDLER FOR NOT FOUND SET l_last_row_fetched = 1;

OPEN cursor1;

cursor_loop: LOOP

  FETCH cursor1 INTO l_customer_name, l_contact_surname, l_contact_firstname;

  IF l_last_row_fetched = 1 THEN

    LEAVE cursor_loop;

  END IF;

END LOOP cursor_loop;

CLOSE cursor1;

-- Always reset the loop termination state flag after closing

SET l_last_row_fetched = 0;

  • Avoid Shadowing: Do not override or shadow outer variable declarations inside nested blocks.
  • Strict Mode: Ensure stored programs are developed and executed in SQL strict mode (STRICT_TRANS_TABLES or STRICT_ALL_TABLES) to prevent silent data truncation or invalid inputs.
  • Bind Parameters in Dynamic SQL: Use parameter placeholders (?) instead of concatenating variables directly into dynamic SQL strings to prevent SQL injection and improve plan caching.

CREATE PROCEDURE update_anything(

  IN p_table     VARCHAR(60),

  IN p_where_col VARCHAR(60),

  IN p_set_col   VARCHAR(60),

  IN p_where_val VARCHAR(60),

  IN p_set_val   VARCHAR(60)

)

BEGIN

  SET @dyn_sql = CONCAT(

    'UPDATE ', p_table,

    ' SET ', p_set_col, ' = ?',

    ' WHERE ', p_where_col, ' = ?'

  );

  PREPARE s1 FROM @dyn_sql;

  SET @where_val = p_where_val;

  SET @set_val   = p_set_val;

  EXECUTE s1 USING @set_val, @where_val;

  DEALLOCATE PREPARE s1;

END;

  • Encapsulate Business Rules: Hide complex logical expressions and calculations behind named deterministic functions (e.g., validation checks or tax calculations).
  • Clean Codebase: Regularly audit stored code to remove unused variables, unreachable blocks, and dead code.
  • Exhaustive CASE Statements: Ensure CASE structures cover all possible conditional paths, or include an ELSE clause to trap unhandled cases.
  • Guaranteed Loop Termination: Verify that all loops reach explicit termination conditions under every execution branch.
  • Single Exit Point in Loops: Prefer using a single LEAVE statement per loop construct to maintain structured control flow.
  • Concurrence Control: Use SELECT ... FOR UPDATE when fetching rows that will be modified in subsequent steps.
  • Modularization: Limit execution body size to approximately 50–60 lines per routine by breaking down larger tasks into smaller subroutines.

Appendix A: Debug Infrastructure Setup

          `msg_text` varchar(255) DEFAULT NULL,

--- 1. Create debug log table

CREATE TABLE `debug_tab` (

  `seq`      BIGINT(20) NOT NULL AUTO_INCREMENT,

  `msg_time` DATETIME DEFAULT NULL,

  `cid`      INT(11) DEFAULT NULL,

  `msg_text` VARCHAR(255) DEFAULT NULL,

  PRIMARY KEY (`seq`)

) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=latin1;

-- 2. Debug procedure for stored procedures

DROP PROCEDURE IF EXISTS debug_msg;

DELIMITER //

CREATE PROCEDURE debug_msg(

  IN p_enabled INTEGER,

  IN p_msg     VARCHAR(255)

)

label1: BEGIN

  /*

   | Purpose: Display or save debug message

   | Inputs : p_enabled - 0: Off, 1: Console, 2: Table, 3: Both

   | Note   : Result sets are prohibited in stored functions; use debug_msg_f instead.

  */

  IF p_enabled = 0 THEN

    LEAVE label1;

  ELSEIF p_enabled = 1 THEN

    SELECT CONCAT('** ', p_msg) AS '** DEBUG:';

  ELSEIF p_enabled = 2 THEN

    INSERT INTO debug_tab

      SELECT NULL, CURRENT_TIMESTAMP, CONNECTION_ID(), p_msg;

  ELSEIF p_enabled = 3 THEN

    SELECT CONCAT('** ', p_msg) AS '** DEBUG:';

    INSERT INTO debug_tab

      SELECT NULL, CURRENT_TIMESTAMP, CONNECTION_ID(), p_msg;

  END IF;

END label1 //

DELIMITER ;

-- 3. Debug procedure for stored functions

DROP PROCEDURE IF EXISTS debug_msg_f;

DELIMITER //

CREATE PROCEDURE myapp_admin.debug_msg_f(

  IN p_enabled INTEGER,

  IN p_msg     VARCHAR(255)

)

BEGIN

  /*

   | Purpose: Save debug message to debug_tab (function-compatible)

   | Inputs : p_enabled - 0: Off, 2: Table logging

  */

  IF p_enabled = 2 THEN

    INSERT INTO debug_tab

      SELECT NULL, CURRENT_TIMESTAMP, CONNECTION_ID(), p_msg;

  END IF;

END //

DELIMITER ;

Appendix B: Sample Stored Procedure Using Debugging

DROP PROCEDURE IF EXISTS myapp_admin.get_geocode_by_zip;

CREATE PROCEDURE myapp_admin.get_geocode_by_zip(

  IN  p_zip       VARCHAR(10),

  IN  p_range     VARCHAR(10),

  OUT p_geocode_o VARCHAR(20)

)

BEGIN

  /*

   | Purpose: Retrieve geocode concatenated from country, state, county, and block

   | Inputs : p_zip - ZIP code; p_range - High range offset

   | Outputs: p_geocode_o - Formatted geocode string (e.g., US2501500000)

   | Table  : v_tax_plus4

  */

  SET @enabled = 1; -- Debug mode: 0: Off, 1: Console, 2: Table, 3: Both

  SET p_geocode_o = NULL;

  IF p_range IS NULL THEN

    CALL debug_msg(@enabled, 'p_range is NULL');

    SELECT CONCAT(

      IFNULL(TRIM(country), ''),

      IFNULL(TRIM(state), ''),

      IFNULL(TRIM(county), ''),

      IFNULL(TRIM(block), '')

    )

    INTO p_geocode_o

    FROM v_tax_plus4

    WHERE zip = p_zip AND main_range = 1;

  ELSE

    CALL debug_msg(@enabled, CONCAT('p_range is ', p_range));

    SELECT CONCAT(

      IFNULL(TRIM(country), ''),

      IFNULL(TRIM(state), ''),

      IFNULL(TRIM(county), ''),

      IFNULL(TRIM(block), '')

    )

    INTO p_geocode_o

    FROM v_tax_plus4

    WHERE zip = p_zip

      AND p_range BETWEEN low_range AND high_range

      AND main_range = 0;

  END IF;

END;

Appendix C: Sample Stored Function Using Debugging

DROP FUNCTION IF EXISTS myapp_admin.f_geocode_by_zip;

CREATE FUNCTION myapp_admin.f_geocode_by_zip(

  p_zip   VARCHAR(10),

  p_range VARCHAR(10)

) RETURNS VARCHAR(10) CHARSET latin1

  DETERMINISTIC

BEGIN

  /*

   | Purpose: Return geocode concatenated string from v_tax_plus4

   | Inputs : p_zip - ZIP code; p_range - High range offset

   | Outputs: Returns geocode string

  */

  DECLARE l_geocode VARCHAR(10);

  SET @enabled = 2; -- Debug mode: 2: Table log, 0: Off

  SET l_geocode = NULL;

  CALL debug_msg_f(@enabled, 'Inside function f_geocode_by_zip');

  IF p_range IS NULL THEN

    SELECT CONCAT(

      IFNULL(TRIM(country), ''),

      IFNULL(TRIM(state), ''),

      IFNULL(TRIM(county), ''),

      IFNULL(TRIM(block), '')

    )

    INTO l_geocode

    FROM v_tax_plus4

    WHERE zip = p_zip AND main_range = 1;

  ELSE

    CALL debug_msg_f(@enabled, CONCAT('p_range is ', p_range));

    SELECT CONCAT(

      IFNULL(TRIM(country), ''),

      IFNULL(TRIM(state), ''),

      IFNULL(TRIM(county), ''),

      IFNULL(TRIM(block), '')

    )

    INTO l_geocode

    FROM v_tax_plus4

    WHERE zip = p_zip

      AND p_range BETWEEN low_range AND high_range

      AND main_range = 0;

  END IF;

  RETURN l_geocode;

END;

Tuesday, April 14, 2015

Monitoring Oracle GoldenGate Latency

Today I've implemented an approach to monitor OGG latency. Here I will describe what I've done.  

1. Create a table gg_latency in source and target databases:
create table gg_latency
(
  extr varchar2(10),
  pump varchar2(10),
  repl varchar2(10),
  update_time date
);



alter table gg_latency add constraint gg_latency_pk primary key(extr, pump, repl) using index;

2. Create a procedure that is used to update the latency table: 

create or replace procedure proc_update_gg_latency
is
begin
  for rec in ( select * from gg_latency)
  loop
     update gg_latency set update_time=sysdate where extr=rec.extr and pump=rec.pump and repl = rec.repl;
     commit;
  end loop;
end;
/
3. Populate the table with every possible combination of the processing group names:

For example, in my replication enviroment, at source I have three Extract groups, three Pump groups, at target I have 15 Replicat groups :
insert into gg_latency(extr, pump, repl) values('ECRUDR1', 'PCRUDR1', 'CRURDR1');
insert into gg_latency(extr, pump, repl) values('ECRUDR1', 'PCRUDR1', 'CRURDR1A');
insert into gg_latency(extr, pump, repl) values('ECRUDR1', 'PCRUDR1', 'CRURDR1B');
insert into gg_latency(extr, pump, repl) values('ECRUDR1', 'PCRUDR1', 'CRURDR1C');
insert into gg_latency(extr, pump, repl) values('ECRUDR1', 'PCRUDR1', 'CRURDR1D');
  
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2A');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2B');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2C');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2D');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2F');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2G');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2H');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2M');
insert into gg_latency(extr, pump, repl) values('ECRUDR2', 'PCRUDR2', 'CRURDR2N');

insert into gg_latency(extr, pump, repl) values('ECRUDR3', 'PCRUDR3', 'CRURDR3');

4. For each EXTRACT group parameter file at source, add the TABLE clause with WHERE option for the GG_LATENCY table , e.g.

    TABLE DB_ADMIN.GG_LATENCY WHERE ( EXTR="ECRUDR1");

Note: do this for all the EXTRACT groups


5. For each PUMP group parameter file at source, add the TABLE clause with WHERE option for the GG_LATENCY table , e.g.
    TABLE DB_ADMIN.GG_LATENCY, WHERE (PUMP="PCRUDR1");
Note: add the line before the PASSTHRU if exists, do this for all the PUMP groups


 6. For each REPLICAT group parameter file at target, add MAP clause with WHERE option for the GG_LATENCY table , e.g.

MAP DB_ADMIN.GG_LATENCY, TARGET DB_ADMIN.GG_LATENCY, WHERE (REPL='CRURDR1');
 
Note: do this for all the REPLICAT groups. In 12c OGG, single quotation mark should be used for literal string.

7. Bounce all processes as parameter files are modified 


8. Create a scheduler job to update the latency table every minute
begin
DBMS_SCHEDULER.create_job (
   job_name         => 'UPDATE_GG_LATENCY_TABLE',
    job_type        => 'PLSQL_BLOCK',
    job_action      => 'BEGIN db_admin.proc_update_gg_latency; END;',
    start_date      => trunc(sysdate, 'HH24'),
    repeat_interval => 'freq=minutely',
    end_date        => NULL,
    enabled         => TRUE
    );
end;
/

9. Check latency by the following query at target:
 
SQL> select extr, pump, repl, update_time, round((sysdate - update_time) *24*60) latency_mins from gg_latency;

EXTR       PUMP       REPL       UPDATE_TIME          LATENCY_MINS
---------- ---------- ---------- -------------------- ------------
ECRUDR1    PCRUDR1    CRURDR1D   14-Apr-2015 12:46:00            1
ECRUDR1    PCRUDR1    CRURDR1B   14-Apr-2015 12:46:00            1
ECRUDR1    PCRUDR1    CRURDR1A   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2D   14-Apr-2015 12:46:00            1
ECRUDR1    PCRUDR1    CRURDR1C   14-Apr-2015 12:46:00            1
ECRUDR1    PCRUDR1    CRURDR1    14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2H   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2C   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2N   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2B   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2A   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2M   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2G   14-Apr-2015 12:46:00            1
ECRUDR2    PCRUDR2    CRURDR2F   14-Apr-2015 12:46:00            1
ECRUDR3    PCRUDR3    CRURDR3    14-Apr-2015 12:46:00            1

15 rows selected.

Note: As we update every minute, the smallest unit for latency is a minute.