Obtaining a section explain with actuals to investigate poor query performance
To resolve a SQL query performance slow down, you can begin by obtaining a section explain that includes section actuals information. The section actuals values can then be compared with the estimated access plan values generated by the optimizer to assess the validity of the access plan. This task takes you through the process of obtaining section actuals to investigate poor query performance.
Before you begin
You have completed the diagnosis phase of your investigation and determined that indeed you have a SQL query performance slow down and you have determined which statement is suspected to be involved in the performance slow down.
About this task
This task takes you through the process of obtaining section actuals to investigate poor query performance. The information contained in the sections actuals, when compared with the estimated values generated by the optimizer, can help to resolve the query performance slow down.
Restrictions
See
the limitations in Capturing and accessing section actuals
.
Procedure
To investigate poor query performance for a query executed by the myApp.exe application, complete the following steps:
- Enable section actuals:
DB2 UPDATE DATABASE CONFIGURATION USING SECTION_ACTUALS BASE
- Create the EXPLAIN tables in the MYSCHEMA schema using
the SYSINSTALLOBJECTS procedure:
CALL SYSINSTALLOBJECTS( 'EXPLAIN', 'C', NULL, 'MYSCHEMA' )
Note: This step can be skipped if you have already created the EXPLAIN tables. - Create a workload MYCOLLECTWL to collect activities submitted
by the myApp.exe application and enable collection
of section data for those activities by issuing the following two
commands:
CREATE WORKLOAD MYCOLLECTWL APPLNAME( 'MYAPP.EXE') COLLECT ACTIVITY DATA WITH DETAILS,SECTION
Followed by:
GRANT USAGE ON WORKLOAD MYCOLLECTWL TO PUBLIC
Note: Choosing to use a separate workload limits the amount of information captured by the activity event monitor - Create an activity event monitor, called
ACTEVMON
, by issuing the following statement:CREATE EVENT MONITOR ACTEVMON FOR ACTIVITIES WRITE TO TABLE
- Activate the activity event monitor
ACTEVMON
by executing the following statement:SET EVENT MONITOR ACTEVMON STATE 1
- Run the myApp.exe application.
All statements, issued by the application, are captured by the activity event monitor.
- Query the activity event monitor tables to find the identifier
information for the statement of interest by issuing the following
statement:
The following is an example of the output that was generated as a result of the issued select statement:SELECT APPL_ID, UOW_ID, ACTIVITY_ID, STMT_TEXT FROM ACTIVITYSTMT_ACTEVMON
APPL_ID UOW_ID ACTIVITY_ID STMT_TEXT ------------------------- -------- -------------- --------------- *N2.DB2INST1.0B5A12222841 1 1 SELECT * FROM ...
- Use the activity identifier information as input to the
EXPLAIN_FROM_ACTIVITY procedure to obtain a section explain with actuals,
as shown in the following call statement:
CALL EXPLAIN_FROM_ACTIVITY( '*N2.DB2INST1.0B5A12222841', 1, 1, 'ACTEVMON', 'MYSCHEMA', ?, ?, ?, ?, ? )
The following is a sample output resulting from the EXPLAIN_FROM_ACTIVITY call:Value of output parameters -------------------------- Parameter Name : EXPLAIN_SCHEMA Parameter Value : MYSCHEMA Parameter Name : EXPLAIN_REQUESTER Parameter Value : SWALKTY Parameter Name : EXPLAIN_TIME Parameter Value : 2009-08-24-12.33.57.525703 Parameter Name : SOURCE_NAME Parameter Value : SQLC2H20 Parameter Name : SOURCE_SCHEMA Parameter Value : NULLID Parameter Name : SOURCE_VERSION Parameter Value : Return Status = 0
- Format the explain data using the db2exfmt command
and specifying, as input, the explain instance key that was returned
as output from the EXPLAIN_FROM_ACTIVITY procedure, such as the following:
db2exfmt -d test -w 2009-08-24-12.33.57.525703 -n SQLC2H20 -s NULLID -# 0 -t
The explain instance output was the following:******************** EXPLAIN INSTANCE ******************** DB2_VERSION: 09.07.1 SOURCE_NAME: SQLC2H20 SOURCE_SCHEMA: NULLID SOURCE_VERSION: EXPLAIN_TIME: 2009-08-24-12.33.57.525703 EXPLAIN_REQUESTER: SWALKTY Database Context: ---------------- Parallelism: None CPU Speed: 4.000000e-05 Comm Speed: 0 Buffer Pool size: 198224 Sort Heap size: 1278 Database Heap size: 2512 Lock List size: 6200 Maximum Lock List: 60 Average Applications: 1 Locks Available: 119040 Package Context: --------------- SQL Type: Dynamic Optimization Level: 5 Blocking: Block All Cursors Isolation Level: Cursor Stability ---------------- STATEMENT 1 SECTION 201 ---------------- QUERYNO: 0 QUERYTAG: CLP Statement Type: Select Updatable: No Deletable: No Query Degree: 1 Original Statement: ------------------ select * from syscat.tables Optimized Statement: ------------------- SELECT Q10.$C67 AS "TABSCHEMA", Q10.$C66 AS "TABNAME", Q10.$C65 AS "OWNER", Q10.$C64 AS "OWNERTYPE", Q10.$C63 AS "TYPE", Q10.$C62 AS "STATUS", Q10.$C61 AS "BASE_TABSCHEMA", Q10.$C60 AS "BASE_TABNAME", Q10.$C59 AS "ROWTYPESCHEMA", Q10.$C58 AS "ROWTYPENAME", Q10.$C57 AS "CREATE_TIME", Q10.$C56 AS "ALTER_TIME", Q10.$C55 AS "INVALIDATE_TIME", Q10.$C54 AS "STATS_TIME", Q10.$C53 AS "COLCOUNT", Q10.$C52 AS "TABLEID", Q10.$C51 AS "TBSPACEID", Q10.$C50 AS "CARD", Q10.$C49 AS "NPAGES", Q10.$C48 AS "FPAGES", Q10.$C47 AS "OVERFLOW", Q10.$C46 AS "TBSPACE", Q10.$C45 AS "INDEX_TBSPACE", Q10.$C44 AS "LONG_TBSPACE", Q10.$C43 AS "PARENTS", Q10.$C42 AS "CHILDREN", Q10.$C41 AS "SELFREFS", Q10.$C40 AS "KEYCOLUMNS", Q10.$C39 AS "KEYINDEXID", Q10.$C38 AS "KEYUNIQUE", Q10.$C37 AS "CHECKCOUNT", Q10.$C36 AS "DATACAPTURE", Q10.$C35 AS "CONST_CHECKED", Q10.$C34 AS "PMAP_ID", Q10.$C33 AS "PARTITION_MODE", '0' AS "LOG_ATTRIBUTE", Q10.$C32 AS "PCTFREE", Q10.$C31 AS "APPEND_MODE", Q10.$C30 AS "REFRESH", Q10.$C29 AS "REFRESH_TIME", ... Explain level: Explain from section Access Plan: ----------- Total Cost: 154.035 Query Degree: 1 Rows Rows Actual RETURN ( 1) Cost I/O | 54 396 >^HSJOIN ( 2) 153.056 NA /----------+-----------\ 54 20 396 0 >^HSJOIN TBSCAN ( 3) ( 12) 140.872 11.0302 NA NA (continued below) | 20 NA TABLE: SYSIBM SYSAUDITPOLICIES (continued from above) /---------+----------\ 54 6 396 0 >^HSJOIN IXSCAN ( 4) ( 11) 138.033 2.01136 NA NA /---------+---------\ | 54 6 -1 396 0 NA >^HSJOIN IXSCAN INDEX: SYSIBM ( 5) ( 10) INDCOLLATIONS04 135.193 2.01136 NA NA /-------+--------\ | 54 6 -1 396 0 NA >^HSJOIN IXSCAN INDEX: SYSIBM ( 6) ( 9) INDCOLLATIONS04 132.354 2.01136 NA NA /-----+-----\ | 54 6 -1 396 0 NA TBSCAN IXSCAN INDEX: SYSIBM ( 7) ( 8) INDCOLLATIONS04 129.57 2.01136 NA NA | | 54 -1 NA NA TABLE: SYSIBM INDEX: SYSIBM SYSTABLES INDCOLLATIONS04 ...
- Examine the section actuals information in the explain
output. Compare the section actuals values with the estimated values of the access plan generated by the optimizer. If a discrepancy occurs between the section actuals and estimated values for the access plan, ascertain what is causing the discrepancy and take the appropriate action. As an example for the purposes of discussion, you ascertain that the table statistics are out of date for one of the tables being queried. This leads the optimizer to select an incorrect access plan which might account for the query performance slow down. The course of action to take, in this case, is to run the RUNSTATS command on the table to update the table statistics.
- Retry the application to determine if the query slow down persists.