IBM Support

Time Spent Optimizing

Troubleshooting


Problem

This document provides information about finding the time spent in optimization.

Resolving The Problem

The estimated query processing time displayed in message CPA4259 - Estimated query processing time N exceeds limit Y (C, I) does not include the time taken to make the estimate.

Finding the time spent making the estimate can be done in two ways: using an SQL Performance Monitor (DBMON) or using the debug job log.

Using SQL Performance Monitor (DBMON)
See this TechNote for more information on Database Monitor impacts:  www.ibm.com/support/docview.wss?uid=ibm10882914

Do the following:
1 Collect an SQL Performance Monitor (DBMON) of the query.
2 Run the following SQL:

SELECT a.qqjnum, a.qqucnt, a.QQI5, b.qq1000
FROM dbmon a, dbmon b
WHERE a.qqrid = 3014 and
a.qqjnum = b.qqjnum and
a.qqucnt = b.qqucnt and
b.qqrid = 1000

Using the Debug Job Log

Note: This assumes an interactive SQL session runs the query.
1 On an IBM® OS/400® or IBM® i5/OS® command line, type the following:

CHGJOB LOG(4 00 *SECLVL) LOGCLPGM(*YES)

Press the Enter key.
2 On an OS/400 or i5/OS command line, type the following:

STRDBG UPDPROD(*YES)

Press the Enter key.
3 On an OS/400 or i5/OS command line, type the following:

CHGQRYA LIMIT(0)

Press the Enter key.
4 Issue the STRSQL command.
To better emulate a normal query workload environment, issue an F13, option 1 and change
    • Data Refresh to *FORWARD
    • ALLOW COPY DATA to *OPTIMIZE
    • Send the query output (Select Output) to a database file or printer or add the OPTIMIZE FOR ALL ROWS clause to the end of the query statement
Run the query you are studying
5 Reply with C to cancel or I to ignore.
6 Exit interactive SQL.
7 Issue the DSPJOBLOG OUTPUT(*PRINT) command.
8 Find the spooled output and display it.
9 Search for AFTER_OPTIM in the spooled output. This will have located the msgCPA4259 of interest. Record the time stamp of this message in the job log.
10 Find the timestamp of the first msgCPI4339 prior to the CPA4259. Record that timestamp.
11 Subtract the CPI4339 timestamp from the CPA4259 timestamp to get the elapsed time the query took to be optimized.

For example, consider the following job log:

 MSGID      TYPE                    SEV   DATE       TIME       FROM PGM       LIBRARY     INST    
CPI4339    Information             00    09/08/13   17:12:57   QQQSRVI1       QSYS        *STMT    
                                     From module . . . . . . . . :   QQQAINI                                                      
                                     From procedure  . . . . . . :   GETMSGTXT                                                    
                                     Statement . . . . . . . . . :   5592                                                          
                                     To module . . . . . . . . . :   QQQSETUP                                                      
                                     To procedure  . . . . . . . :   SETQIS                                                        
                                     Statement . . . . . . . . . :   7133                                                          

                                      Message . . . . :   Query options retrieved file QAQQINI in library QUSRSYS.                  
                                     Recovery  . . . :   Query options retrieved file QAQQINI in library QUSRSYS.                  
CPA4259    Inquiry                 99    09/08/13   17:13:08   QQQQUERY       QSYS        *STMT    *EXT     *N    
                                     From module . . . . . . . . :   QQQQUERY                                                      
                                     From procedure  . . . . . . :   AFTER_OPTIM                                                  
                                     Statement . . . . . . . . . :   8264                                                          
                                     Message . . . . :   Estimated query processing time 6122 exceeds limit 0 (C I)                
                                     Cause . . . . . :   The database query time limit attribute has been specified.



The time spent optimizing in this case is 17:13:08 - 17:12:57 = 0 hours, 0 minutes, 13 seconds.

[{"Business Unit":{"code":"BU058","label":"IBM Infrastructure w\/TPS"},"Product":{"code":"SWG60","label":"IBM i"},"Component":"Db2 for i","Platform":[{"code":"PF012","label":"IBM i"}],"Version":"All Versions","Edition":"","Line of Business":{"code":"LOB57","label":"Power"}}]

Historical Number

20843444

Document Information

Modified date:
18 December 2019

UID

nas8N1017643