Sunday, November 14, 2021

Performance Tuning : Display Cursor Report

 Performance Tuning : Display Cursor Report

This displays the runtime execution plan of any cursor loaded in the cursor cache.

At a basic level, it shows the runtime execution plan.

However, the format ALL also includes extra information such as pruning, parallel execution, predicate, projection, alias and remote SQL information.

It can be produced by running the dbms_xplan.display_cursor function with the ALL +ALLSTATS option.

The +ALLSTATS option will include actual row source statistics for each execution plan step. ALLSTATS includes IOSTATS and MEMSTATS, e.g. :

  • Elapsed time

  • Physical reads

  • Buffer gets

  • Memory used (in PGA) for memory intensive operations (such as hash joins, sorts, and bitmap operators).

However, this additional information is only provided if STATISTICS_LEVEL=ALL when the SQL is executed.

Setting the initialization parameter "statistics_level" to ALL can be an overhead, so may not be advisable on a production system.

Alternatively the initialization parameter "_rowsource_execution_statistics" can be set to TRUE, which gives a lower overhead.

These parameters can be set for a specific session (e.g. using the profile option "Initialization SQL Statement - Custom").

If testing from SQL*Plus then the hint /*+ gather_plan_statistics*/ can be used to collect row source statistics for a specific SQL (even if "statistics_level" is not ALL and "_rowsource_execution_statistics" is FALSE).

The Display Cursor report should be run as soon as possible. If it is delayed, the cursor may have been flushed from memory or invalidated, and no data will be available.

The SQL ID will be required to be able to run the Display Cursor report.

Obtaining SQLID - 

If querying v$SQL, use the following query:

SELECT sql_id, hash_value, SUBSTR(sql_text,1, 80)
FROM v$sql  
WHERE sql_fulltext LIKE '%<part of SQL text>%';

 Display Cursor Report

Please produce a Display Cursor Report for SQL ID <sql_id>.

For the Display Cursor Report to be useful (i.e. contain actual row source statistics as well as the runtime execution plan).

  • The initialization parameter "statistics_level" must be set to ALL (or "_rowsource_execution_statistics" set to TRUE) at the time the SQL is executed.

  • The SQL must still be loaded in the cursor cache (memory).

The report can be produced by running:

SET pages 0
SET lines 300
SET LONG 10000
SET LONGCHUNKSIZE 10000

SPOOL<report_name>.txt 

SELECT * FROM TABLE(dbms_xplan.display_cursor('<sql_id>', NULL, 'ALL +ALLSTATS')); 

SPOOL OFF;

By default, the plan statistics are shown for all executions of the cursor, however the keyword LAST can be added to the options to see the statistics for the last execution only.

Here is an example of the output from a display cursor report.

SQL_ID  8d9ny4cf9qmvm, child number 1 
     ------------------------------------- 
     INSERT INTO HZ_CUST_SITE_USES_ALL ( SITE_USE_ID , CUST_ACCT_SITE_ID, 
     SITE_USE_CODE , PRIMARY_FLAG , STATUS , LOCATION , ORG_ID , 
     OBJECT_VERSION_NUMBER, CREATED_BY_MODULE, LAST_UPDATE_DATE , 
     CREATION_DATE , LAST_UPDATED_BY , CREATED_BY , LAST_UPDATE_LOGIN) 
     SELECT HZ_CUST_SITE_USES_S.NEXTVAL, L.CUST_ACCT_SITE_ID, 'LATE_CHARGE', 
     'Y', 'A', TO_CHAR(HZ_CUST_SITE_USES_S.CURRVAL), L.ORG_ID, 1, 
     'AR_LATE_CHARGE_UPG', :B3 , :B3 , -1551, -1551, -1551 FROM (SELECT 
     CAS.CUST_ACCT_SITE_ID, CAS.ORG_ID FROM HZ_CUST_ACCT_SITES_ALL CAS, 
     HZ_CUST_SITE_USES_ALL CSU WHERE CAS.ROWID >= :B2 AND CAS.ROWID <= :B1 
     AND CAS.STATUS = 'A' AND CAS.CUST_ACCT_SITE_ID = CSU.CUST_ACCT_SITE_ID 
     AND CSU.STATUS = 'A' AND (( CSU.SITE_USE_CODE = 'STMTS' AND NOT EXISTS 
     (SELECT NULL FROM HZ_CUST_SITE_USES_ALL B WHERE B.CUST_ACCT_SITE_ID = 
     CAS.CUST_ACCT_SITE_ID AND B.SITE_USE_CODE = 'DUN' AND B.STATUS = 'A')) 
     OR CSU.SITE_USE_CODE = 'DUN')) L 
     
     Plan hash value: 1449143904 
     
     ----------------------------------------------------------------------------------------------------------------------------------
     | Id  | Operation                        | Name                   | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem |  O/1/M   | 
     --------------------------------------------------------------------------------------------------------------------------------
     |   0 | INSERT STATEMENT                 |                        |    655 |        |       | 52008 (100)|          |      0 |15:49:30.79 |     147M|    101K|       |       |          | 
     |   1 |  LOAD TABLE CONVENTIONAL         |                        |    655 |        |       |            |          |      0 |15:49:30.79 |     147M|    101K|       |       |          | 
     |   2 |   SEQUENCE                       | HZ_CUST_SITE_USES_S    |    655 |        |       |            |          |    109K|15:20:52.78 |     145M|  98825 |       |       |          | 
     |*  3 |    FILTER                        |                        |    655 |        |       |            |          |    109K|15:19:30.01 |     145M|  98825 |       |       |          | 
     |*  4 |     FILTER                       |                        |    655 |        |       |            |          |   5920K|15:02:20.32 |     144M|  80273 |       |       |          | 
     |*  5 |      HASH JOIN                   |                        |    655 |  42541 |  1744K| 52008   (1)| 00:18:18 |   5920K|15:01:52.29 |     144M|  80273 |   963K|   963K|   655/0/0| 
     |*  6 |       TABLE ACCESS BY ROWID RANGE| HZ_CUST_ACCT_SITES_ALL |    655 |  30763 |   751K| 14546   (1)| 00:05:07 |   3507K|00:02:21.51 |   93535 |  80273 |       |       |          | 
     |*  7 |       TABLE ACCESS FULL          | HZ_CUST_SITE_USES_ALL  |    655 |   3356K|    54M| 37454   (1)| 00:13:11 |   4050M|06:58:51.26 |     144M|      0 |       |       |          | 
     |*  8 |     TABLE ACCESS BY INDEX ROWID  | HZ_CUST_SITE_USES_ALL  |    109K|      1 |    17 |     4   (0)| 00:00:01 |      0 |00:20:29.26 |     328K|  18552 |       |       |          | 
     |*  9 |      INDEX RANGE SCAN            | HZ_CUST_SITE_USES_N1   |    109K|      1 |       |     3   (0)| 00:00:01 |      0 |00:20:28.15 |     328K|  18552 |       |       |          | 
     ----------------------------------------------------------------------------------------------------------------------------------
     Query Block Name / Object Alias (identified by operation id): 
     ------------------------------------------------------------- 
     
     1 - SEL$F5BB74E1 
     6 - SEL$F5BB74E1 / CAS@SEL$2 
     7 - SEL$F5BB74E1 / CSU@SEL$2 
     8 - SEL$3        / B@SEL$3 
     9 - SEL$3        / B@SEL$3 
   
     Predicate Information (identified by operation id): 
     --------------------------------------------------- 
   
     3 - filter((("CSU"."SITE_USE_CODE"='STMTS' AND  IS NULL) OR "CSU"."SITE_USE_CODE"='DUN')) 
     4 - filter(CHARTOROWID(:B2)<=CHARTOROWID(:B1)) 
     5 - access("CAS"."CUST_ACCT_SITE_ID"="CSU"."CUST_ACCT_SITE_ID") 
     6 - access("CAS".ROWID>=CHARTOROWID(:B2) AND "CAS".ROWID<=CHARTOROWID(:B1)) 
     filter("CAS"."STATUS"='A') 
     7 - filter("CSU"."STATUS"='A') 
     8 - filter("B"."STATUS"='A') 
     9 - access("B"."CUST_ACCT_SITE_ID"=:B1 AND "B"."SITE_USE_CODE"='DUN') 
   
     Column Projection Information (identified by operation id): 
     ----------------------------------------------------------- 
   
     2 - "CAS"."CUST_ACCT_SITE_ID"[NUMBER,22], "CSU"."CUST_ACCT_SITE_ID"[NUMBER,22], "CAS".ROWID[ROWID,10], "CAS"."ORG_ID"[NUMBER,22], "CAS"."STATUS"[VARCHAR2,1], 
   "CSU"."STATUS"[VARCHAR2,1], "CSU"."SITE_USE_CODE"[VARCHAR2,30] 
     3 - "CAS"."CUST_ACCT_SITE_ID"[NUMBER,22], "CSU"."CUST_ACCT_SITE_ID"[NUMBER,22], "CAS".ROWID[ROWID,10], "CAS"."ORG_ID"[NUMBER,22], "CAS"."STATUS"[VARCHAR2,1], 
   "CSU"."STATUS"[VARCHAR2,1], "CSU"."SITE_USE_CODE"[VARCHAR2,30] 
     4 - "CAS"."CUST_ACCT_SITE_ID"[NUMBER,22], "CSU"."CUST_ACCT_SITE_ID"[NUMBER,22], "CAS".ROWID[ROWID,10], "CAS"."ORG_ID"[NUMBER,22], "CAS"."STATUS"[VARCHAR2,1], 
   "CSU"."STATUS"[VARCHAR2,1], "CSU"."SITE_USE_CODE"[VARCHAR2,30] 
     5 - (#keys=1) "CAS"."CUST_ACCT_SITE_ID"[NUMBER,22], "CSU"."CUST_ACCT_SITE_ID"[NUMBER,22], "CAS".ROWID[ROWID,10], "CAS"."ORG_ID"[NUMBER,22], "CAS"."STATUS"[VARCHAR2,1], 
   "CSU"."STATUS"[VARCHAR2,1], "CSU"."SITE_USE_CODE"[VARCHAR2,30] 
     6 - "CAS".ROWID[ROWID,10], "CAS"."CUST_ACCT_SITE_ID"[NUMBER,22], "CAS"."STATUS"[VARCHAR2,1], "CAS"."ORG_ID"[NUMBER,22] 
     7 - "CSU"."CUST_ACCT_SITE_ID"[NUMBER,22], "CSU"."SITE_USE_CODE"[VARCHAR2,30], "CSU"."STATUS"[VARCHAR2,1] 
     8 - "B".ROWID[ROWID,10], "B"."CUST_ACCT_SITE_ID"[NUMBER,22], "B"."SITE_USE_CODE"[VARCHAR2,30], "B"."STATUS"[VARCHAR2,1] 
     9 - "B".ROWID[ROWID,10], "B"."CUST_ACCT_SITE_ID"[NUMBER,22], "B"."SITE_USE_CODE"[VARCHAR2,30] 
   
     Note 
     ----- 
     - dynamic sampling used for this statement (level=7)
     
     150 rows selected. 
   

In the above example, it can clearly be seen that the performance issue is related to a full table scan of HZ_CUST_SITE_USES_ALL (alias CSU) and the subsequent hash join.

The columns Starts, A-Rows, A-Time, Buffers, Reads, OMem, 1Mem and O/1/M are actual statistics. The columns E-Rows, E-Bytes, Cost (%CPU) and E-Time are estimates (calculated by the Cost Based Optimizer).


No comments: