Example: Listing the time taken by statements executed by a routine

You can use routine monitoring to list the time that is taken by the different statements that are executed by a routine.

Scenario

In this example, a database administrator (DBA) is investigating the performance of a critical stored procedure called TEST.PROC1. The TOTAL_ROUTINE_COORD_EXEC_TIME monitor element that is returned by the MON_GET_ROUTINE table function shows that the stored procedure has a long elapsed execution time. The DBA previously configured the database to track statement information by routine, using the MON_RTN_EXECLIST database configuration parameter. The DBA issues the following query to list the statements that are executed by TEST.PROC1.

SELECT B.EXECUTABLE_ID, 
   100*B.COORD_STMT_EXEC_TIME / A.TOTAL_ROUTINE_COORD_EXEC_TIME 
AS PERCENT_EXEC_TIME,(SELECT SUBSTR(C.STMT_TEXT,1,120)
FROM TABLE(MON_GET_PKG_CACHE_STMT(NULL,B.EXECUTABLE_ID,NULL,-2)) AS C) AS STMT_TEXT
FROM TABLE(MON_GET_ROUTINE('P','TEST',NULL,'PROC1', -2)) AS A,
   TABLE(MON_GET_ROUTINE_EXEC_LIST('P','TEST',NULL,'PROC1', -1)) AS B
WHERE A.TOTAL_ROUTINE_COORD_EXEC_TIME<>0
ORDER BY PERCENT_EXEC_TIME DESC

The result is ordered by percentage of elapsed routine run time.

EXECUTABLE_ID                                                       PERCENT_EXEC_TIME    STMT_TEXT                                                                                                                       
------------------------------------------------------------------- -------------------- ------------------------------------------------------------------------------------------------------------------------
x'01000000000000000C0000000000000000000000020020120801145618138490'                    0 SELECT TABNAME FROM SYSCAT.TABLES  WHERE TABNAME='MY_TABLE' AND  TABSCHEMA='MYSCHEMA'                            
x'01000000000000000B0000000000000000000000020020120801145618127528'                    0 SELECT TABNAME FROM SYSCAT.TABLES  WHERE TABNAME='MY_TABLE_2' AND  TABSCHEMA='MYSCHEMA'                              
x'0100000000000000070000000000000000000000020020120801145618004432'                    0 SELECT COLNAME, TYPENAME FROM  SYSCAT.COLUMNS WHERE TABNAME='MY_TABLE' AND TABSCHEMA='MYSCHEMA'                           

  3 record(s) selected.

With the longest running statements in the routine that is identified, the DBA can refine the investigation and determine why some statements are executing for long periods. The DBA can examine the envelope metrics summed across the executions of the statement during the routine, or use the statement executable_id to look up detailed metrics for all executions of the statement with the MON_GET_PKG_CACHE_STMT table function.