Query Performance Issue ! SQL*Plus v/s Oracle Reports…

Have editted on 1st March to include the Execution Plan of the Modified Query. See at the end.

Recently, got a mail from one of my customer on a Query Performance Issue. The Customer mentioned that the Query, when executed from SQL*Plus, takes around 10 Seconds, whereas, when the pasted in Oracle Reports and run through Concurrent Manager, it runs from around 30-40 minutes and is finally killed. The Customer also confirmed that the Query is exactly same i.e it is purely a Copy-Paste of the Query that was run from SQL*Plus and that the Bind Type & Length too are same. The run time plan for both the executions are totally different, with the plan of SQL*Plus better than the plan generated by Oracle Reports. The Question was, “Why is the plan different between SQL*Plus and Oracle Reports ?”

As usual, I asked for a 10053 trace for both the executions, which is one of the best way in investigating Optimizer Calculations. The 10053 trace revealed some important facts about the Query Performance, and therefore helped resolve the issue. Before we dive into the investigation, let me paste the Query and both the Execution Plans.

This is the Query.

SELECT /*+ INDEX(WDD WSH_DELIVERY_DETAILS_TI4) */
             WDD.ORGANIZATION_ID, 
             COUNT(*) LPNS,
             TRP.TRIP_ID,
             RC.CUSTOMER_NUMBER,
             RC.CUSTOMER_NAME, 
             RAA.ADDRESS1 TO_ADDRESS1, 
             RAA.CITY RAA.STATE TO_CITY_STATE, 
             HLA.DESCRIPTION FROM_DESC, 
             HLA.ADDRESS_LINE_1||' '||HLA.TOWN_OR_CITY||' '||HLA.TOWN_OR_CITY)  FROM_ADDRESS1_CITY, 
             WDA.DELIVERY_ID, 
             WDA.PARENT_DELIVERY_DETAIL_ID,
             WDD.DELIVERY_DETAIL_ID, 
             WDD1.CONTAINER_NAME    CONTAINER_NAME, 
             SUM(WDD.REQUESTED_QUANTITY) REQUESTED_QUANTITY, 
             WDD.REQUESTED_QUANTITY_UOM, 
             SUM(ROUND(WDD.GROSS_WEIGHT,0)) GROSS_WEIGHT, 
             WDD.WEIGHT_UOM_CODE,
             WT.VEHICLE_NUM_PREFIX ||' '||WT.VEHICLE_NUMBER VEHICLE_NUMBER,
             MSI.SEGMENT1 ITEM_CODE, 
	     MSI.ATTRIBUTE10 PRT_DESC 
FROM 	apps.WSH_DELIVERY_DETAILS WDD,
     	apps.WSH_DELIVERY_DETAILS WDD1,
        apps.WSH_DELIVERY_ASSIGNMENTS WDA ,
        apps.WSH_DELIVERY_ASSIGNMENTS WDA1,    
        apps.WSH_TRIPS WT, 
        apps.MTL_SYSTEM_ITEMS MSI, 
	TI_RA_ADDRESSES_V RAA,
	TI_RA_CUSTOMERS_V RC ,
        apps.HR_LOCATIONS_ALL HLA,
    	(SELECT DISTINCT  T.TRIP_ID, WDA.DELIVERY_ID 
    	FROM	apps.WSH_DELIVERY_ASSIGNMENTS WDA, 
          	apps.WSH_DELIVERY_LEGS DL,
          	apps.WSH_TRIP_STOPS PICKUP_STOP,  
             	apps.WSH_TRIPS T
	WHERE	WDA.DELIVERY_ID     = DL.DELIVERY_ID 
        AND     DL.PICK_UP_STOP_ID  = PICKUP_STOP.STOP_ID 
        AND     PICKUP_STOP.TRIP_ID = T.TRIP_ID
        AND     T.TRIP_ID  >=  : P_TRIPID_FR
        AND     T.TRIP_ID  = : P_TRIPID_FR 
AND 	TRP.TRIP_ID <= : P_TRIPID_TO 
GROUP BY WDD.ORGANIZATION_ID , TRP.TRIP_ID , RC.CUSTOMER_NUMBER , RC.CUSTOMER_NAME , RAA.ADDRESS1 , 
RAA.CITY , RAA.STATE , HLA.DESCRIPTION , HLA.ADDRESS_LINE_1 , HLA.TOWN_OR_CITY , WDA.DELIVERY_ID , 
WT.VEHICLE_NUM_PREFIX , WT.VEHICLE_NUMBER , WDA.PARENT_DELIVERY_DETAIL_ID , WDD.DELIVERY_DETAIL_ID , 
WDD1.CONTAINER_NAME , WDD.REQUESTED_QUANTITY_UOM , WDD.WEIGHT_UOM_CODE , MSI.SEGMENT1 , MSI.ATTRIBUTE10

The Runtime Plan of the Query when Executed from SQL*Plus.

-----------------------------------------------------------------------------------------------
| Id  | Operation                                       | Name                        | Rows  |
-----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                                |                             |       |
|   1 |  SORT GROUP BY                                  |                             |     1 |
|   2 |   VIEW                                          | VM_NWVW_1                   |     1 |
|   3 |    SORT UNIQUE                                  |                             |     1 |
|*  4 |     FILTER                                      |                             |       |
|   5 |      NESTED LOOPS                               |                             |       |
|   6 |       NESTED LOOPS                              |                             |     1 |
|   7 |        NESTED LOOPS                             |                             |     1 |
|   8 |         NESTED LOOPS                            |                             |     1 |
|   9 |          NESTED LOOPS                           |                             |     5 |
|  10 |           NESTED LOOPS                          |                             |     5 |
|  11 |            NESTED LOOPS                         |                             |     5 |
|  12 |             NESTED LOOPS                        |                             |     5 |
|  13 |              NESTED LOOPS OUTER                 |                             |    27 |
|  14 |               NESTED LOOPS OUTER                |                             |    27 |
|  15 |                NESTED LOOPS                     |                             |    27 |
|  16 |                 NESTED LOOPS                    |                             |  1908 |
|  17 |                  NESTED LOOPS                   |                             |   427 |
|  18 |                   NESTED LOOPS                  |                             |   127 |
|  19 |                    MERGE JOIN                   |                             |    72 |
|  20 |                     TABLE ACCESS BY INDEX ROWID | WSH_TRIP_STOPS              |   187 |
|* 21 |                      INDEX RANGE SCAN           | WSH_TRIP_STOPS_N1           |   187 |
|* 22 |                     SORT JOIN                   |                             |    72 |
|  23 |                      TABLE ACCESS BY INDEX ROWID| WSH_TRIPS                   |    72 |
|* 24 |                       INDEX RANGE SCAN          | WSH_TRIPS_U1                |    72 |
|  25 |                    TABLE ACCESS BY INDEX ROWID  | WSH_DELIVERY_LEGS           |     2 |
|* 26 |                     INDEX RANGE SCAN            | WSH_DELIVERY_LEGS_N2        |     2 |
|* 27 |                   INDEX RANGE SCAN              | WSH_DELIVERY_ASSIGNMENTS_N1 |     3 |
|  28 |                  TABLE ACCESS BY INDEX ROWID    | WSH_DELIVERY_ASSIGNMENTS    |     4 |
|* 29 |                   INDEX RANGE SCAN              | WSH_DELIVERY_ASSIGNMENTS_N1 |     4 |
|* 30 |                 TABLE ACCESS BY INDEX ROWID     | WSH_DELIVERY_DETAILS        |     1 |
|* 31 |                  INDEX RANGE SCAN               | WSH_DELIVERY_DETAILS_TI4    |     1 |
|* 32 |                INDEX RANGE SCAN                 | WSH_DELIVERY_ASSIGNMENTS_N3 |     1 |
|  33 |               TABLE ACCESS BY INDEX ROWID       | WSH_DELIVERY_DETAILS        |     1 |
|* 34 |                INDEX UNIQUE SCAN                | WSH_DELIVERY_DETAILS_U1     |     1 |
|  35 |              TABLE ACCESS BY INDEX ROWID        | MTL_SYSTEM_ITEMS_B          |     1 |
|* 36 |               INDEX UNIQUE SCAN                 | MTL_SYSTEM_ITEMS_B_U1       |     1 |
|  37 |             TABLE ACCESS BY INDEX ROWID         | HZ_CUST_ACCOUNTS            |     1 |
|* 38 |              INDEX UNIQUE SCAN                  | HZ_CUST_ACCOUNTS_U1         |     1 |
|  39 |            TABLE ACCESS BY INDEX ROWID          | HZ_LOCATIONS                |     1 |
|* 40 |             INDEX UNIQUE SCAN                   | HZ_LOCATIONS_U1             |     1 |
|  41 |           TABLE ACCESS BY INDEX ROWID           | HZ_PARTY_SITES              |     1 |
|* 42 |            INDEX RANGE SCAN                     | HZ_PARTY_SITES_N2           |     1 |
|* 43 |          TABLE ACCESS BY INDEX ROWID            | HZ_CUST_ACCT_SITES_ALL      |     1 |
|* 44 |           INDEX RANGE SCAN                      | HZ_CUST_ACCT_SITES_N1       |     1 |
|  45 |         TABLE ACCESS BY INDEX ROWID             | HZ_PARTIES                  |     1 |
|* 46 |          INDEX UNIQUE SCAN                      | HZ_PARTIES_U1               |     1 |
|* 47 |        INDEX UNIQUE SCAN                        | HR_LOCATIONS_PK             |     1 |
|  48 |       TABLE ACCESS BY INDEX ROWID               | HR_LOCATIONS_ALL            |     1 |
-----------------------------------------------------------------------------------------------

Runtime Plan of the Query when Executed from Oracle Reports.

  
  -----------------------------------------------------------------------------------------------
  | Id  | Operation                                       | Name                        | Rows  |
  -----------------------------------------------------------------------------------------------
  |   0 | SELECT STATEMENT                                |                             |       |
  |   1 |  SORT ORDER BY                                  |                             |     1 |
  |   2 |   SORT GROUP BY                                 |                             |     1 |
  |   3 |    VIEW                                         | VM_NWVW_1                   |     1 |
  |   4 |     SORT UNIQUE                                 |                             |     1 |
  |*  5 |      FILTER                                     |                             |       |
  |   6 |       NESTED LOOPS                              |                             |       |
  |   7 |        NESTED LOOPS                             |                             |     1 |
  |   8 |         NESTED LOOPS                            |                             |     1 |
  |   9 |          NESTED LOOPS                           |                             |     4 |
  |  10 |           NESTED LOOPS                          |                             |     4 |
  |  11 |            NESTED LOOPS                         |                             |     1 |
  |  12 |             NESTED LOOPS OUTER                  |                             |     1 |
  |  13 |              NESTED LOOPS OUTER                 |                             |     1 |
  |  14 |               NESTED LOOPS                      |                             |     1 |
  |* 15 |                HASH JOIN                        |                             |     1 |
  |  16 |                 TABLE ACCESS FULL               | HZ_CUST_ACCT_SITES_ALL      | 36983 |
  |* 17 |                 HASH JOIN                       |                             | 23952 |
  |  18 |                  TABLE ACCESS FULL              | HZ_PARTY_SITES              | 76710 |
  |* 19 |                  HASH JOIN                      |                             | 22674 |
  |  20 |                   TABLE ACCESS FULL             | HZ_LOCATIONS                | 72598 |
  |* 21 |                   HASH JOIN                     |                             | 22737 |
  |  22 |                    TABLE ACCESS FULL            | HZ_CUST_ACCOUNTS            | 14291 |
  |* 23 |                    HASH JOIN                    |                             | 22801 |
  |  24 |                     TABLE ACCESS BY INDEX ROWID | MTL_SYSTEM_ITEMS_B          | 11073 |
  |* 25 |                      INDEX RANGE SCAN           | MTL_SYSTEM_ITEMS_B_N16      | 11073 |
  |* 26 |                     HASH JOIN                   |                             |   130K|
  |  27 |                      TABLE ACCESS FULL          | HR_LOCATIONS_ALL            |   919 |
  |* 28 |                      TABLE ACCESS BY INDEX ROWID| WSH_DELIVERY_DETAILS        |   130K|
  |* 29 |                       INDEX RANGE SCAN          | WSH_DELIVERY_DETAILS_TI4    |   143K|
  |* 30 |                TABLE ACCESS BY INDEX ROWID      | WSH_DELIVERY_ASSIGNMENTS    |     1 |
  |* 31 |                 INDEX RANGE SCAN                | WSH_DELIVERY_ASSIGNMENTS_N3 |     1 |
  |* 32 |               INDEX RANGE SCAN                  | WSH_DELIVERY_ASSIGNMENTS_N3 |     1 |
  |  33 |              TABLE ACCESS BY INDEX ROWID        | WSH_DELIVERY_DETAILS        |     1 |
  |* 34 |               INDEX UNIQUE SCAN                 | WSH_DELIVERY_DETAILS_U1     |     1 |
  |  35 |             TABLE ACCESS BY INDEX ROWID         | HZ_PARTIES                  |     1 |
  |* 36 |              INDEX UNIQUE SCAN                  | HZ_PARTIES_U1               |     1 |
  |* 37 |            INDEX RANGE SCAN                     | WSH_DELIVERY_ASSIGNMENTS_N1 |     4 |
  |  38 |           TABLE ACCESS BY INDEX ROWID           | WSH_DELIVERY_LEGS           |     1 |
  |* 39 |            INDEX RANGE SCAN                     | WSH_DELIVERY_LEGS_N1        |     1 |
  |* 40 |          TABLE ACCESS BY INDEX ROWID            | WSH_TRIP_STOPS              |     1 |
  |* 41 |           INDEX UNIQUE SCAN                     | WSH_TRIP_STOPS_U1           |     1 |
  |* 42 |         INDEX UNIQUE SCAN                       | WSH_TRIPS_U1                |     1 |
  |  43 |        TABLE ACCESS BY INDEX ROWID              | WSH_TRIPS                   |     1 |
  -----------------------------------------------------------------------------------------------

Since the investigation is around the Cardinality of each of the row source, I have removed other information (irrelevant for this discussion) from the execution plan. The Query contains a Subquery with alias as TRP. The Tables queried in the Subquery Drives the Good Plan, whereas, the Subquery is unnested and joined at a later stage in the Problematic Plan (Step 37-43). In the Problematic Plan, the Driving table is HR_LOCATIONS_ALL, which is hash joined to WSH_DELIVERY_DETAILS. The Investigation was around the change in the Execution Path. One of the primary goal of Optimizer is to calculate the Number of rows to be returned by each of the Filter Predicate and then evaluate the Access Patch, including the Driving Table, based on the predicate that fetches the least number of rows. It then also evaluates the Join Method, which is to consider Nested Loop Join for small set of rows or Hash Join / Sort Merge Join for larger set of rows.

The text of the TRP Subquery is pasted below

    	(SELECT DISTINCT  T.TRIP_ID, WDA.DELIVERY_ID 
    	FROM	apps.WSH_DELIVERY_ASSIGNMENTS WDA, 
          	apps.WSH_DELIVERY_LEGS DL,
          	apps.WSH_TRIP_STOPS PICKUP_STOP,  
             	apps.WSH_TRIPS T
	WHERE	WDA.DELIVERY_ID     = DL.DELIVERY_ID 
        AND     DL.PICK_UP_STOP_ID  = PICKUP_STOP.STOP_ID 
        AND     PICKUP_STOP.TRIP_ID = T.TRIP_ID
        AND     T.TRIP_ID  >=  : P_TRIPID_FR
        AND     T.TRIP_ID  <=  : P_TRIPID_TO )  TRP

The Good Plan for this subquery is a Sort Merge Join on WSH_TRIPS & WSH_TRIP_STOPS. Both the tables are accessed via an Index on TRIP_ID. Note that though the range predicate is on TRIP_ID of WSH_TRIPS, the column is joined to TRIP_ID of WSH_TRIP_STOPS and therefore, the optimizer scans an Index on these columns to get the relevant rows from the table. The Optimizer calculation says 72 rows from WSH_TRIPS and 187 rows from WSH_TRIP_STOPS, which are merged join to get final 72 rows from the two tables. This calculation is based on the Input values that Optimized peeked into during the hard parse. For the same set of input values, we have a 10053 trace of the Bad Plan and therefore, I immediately concentrated on the cardinality calculation for the two tables mentioned here. Surprisingly, the first caveat that I observed in the 10053 trace was missing Bind Peeked Data and this was enough to get into the Optimizer calculations.

The Peeked Bind Values section of the 10053 trace shows following information.

*******************************************
Peeked values of the binds in SQL statement
*******************************************
----- Bind Info (kkscoacd) -----
 Bind#0
  oacdty=02 mxl=22(01) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000000 frm=00 csi=00 siz=72 off=0
  No bind buffers allocated
 Bind#1
  oacdty=02 mxl=22(01) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000000 frm=00 csi=00 siz=0 off=24
  No bind buffers allocated
 Bind#2
  oacdty=02 mxl=22(01) mxlc=00 mal=00 scl=00 pre=00
  oacflg=00 fl2=1000000 frm=00 csi=00 siz=0 off=48
  No bind buffers allocated
 Bind#3
  No oacdef for this bind.
 Bind#4
  No oacdef for this bind.

When the Query was executed from SQL*Plus, the values for the Binds were populated and were visible in the Peeked Bind values section of 10053 trace. The missing information means, the Optimizer would fall back to the default calculation for a range predicate. From the trace, the computed cardinality for the two tables, WSH_TRIPS & WSH_TRIP_STOPS, are as under :

Access path analysis for WSH_TRIP_STOPS
***************************************
Access path analysis for WSH_TRIP_STOPS
***************************************
SINGLE TABLE ACCESS PATH 
  Single Table Cardinality Estimation for WSH_TRIP_STOPS[PICKUP_STOP] 

  Table: WSH_TRIP_STOPS  Alias: PICKUP_STOP
    Card: Original: 4666397.000000  Rounded: 11666  Computed: 11665.99  Non Adjusted: 11665.99

Access path analysis for WSH_TRIPS
***************************************
SINGLE TABLE ACCESS PATH 
  Single Table Cardinality Estimation for WSH_TRIPS[T] 

  Table: WSH_TRIPS  Alias: T
    Card: Original: 1802653.000000  Rounded: 4507  Computed: 4506.63  Non Adjusted: 4506.63

In the absence of the actual values provided to the Bind Variables, the Optimizer computed the Cardinality based on defaults, which in this case is 0.25% (5% for >= and 5% of = : P_TRIPID_FR and TRIP_ID <= : P_TRIPID_TO is too high. Another predicate in the Outer query is ORGANIZATION_ID and based on this predicate, optimizer generates a plan with the smallest rowsource first. The smallest rowsource is HR_LOCATIONS_ALL with 919 rows and is joined to WSH_DELIVERY_DETAILS table, which is accessed via hinted index WSH_DELIVERY_DETAILS_TI4.

To check and confirm this behaviour, I executed an EXPLAIN PLAN FOR for this query, without setting the values for the bind variables, from SQL*Plus. With no values to the Bind, the EXPLAIN PLAN FOR computed the BAD plan from SQL*Plus. Therefore, now I was sure that the problem occurs when the peeked values to the bind are not available. The next concern was “Why Oracle Report does not peek into the Bind Variables before actually generating the plan ?”.

I assume this to be a default behaviour, where the query is parsed first and then binded. Unfortunately, there is not much written on this. A better option is to write a query in an efficient way or hint the query. To resolve the issue, I modified the query and this modified version worked perfectly well on both the environments i.e. SQL*Plus and Oracle Reports. The modification was in the Subquery TRP. The change is pasted below.

    (SELECT TRIP_ID, DELIVERY_ID FROM 
    (SELECT T.TRIP_ID, WDA.DELIVERY_ID, row_number() over(partition by t.trip_id, wda.delivery_id) rnum 
                FROM   apps.WSH_DELIVERY_ASSIGNMENTS WDA, 
                                apps.WSH_DELIVERY_LEGS DL,
                                apps.WSH_TRIP_STOPS PICKUP_STOP,  
                                apps.WSH_TRIPS T
                WHERE   WDA.DELIVERY_ID     = DL.DELIVERY_ID 
        AND     DL.PICK_UP_STOP_ID  = PICKUP_STOP.STOP_ID 
        AND     PICKUP_STOP.TRIP_ID = T.TRIP_ID
        AND     T.TRIP_ID  >=  : P_TRIPID_FR
        AND     T.TRIP_ID  <=  : P_TRIPID_TO)
     WHERE RNUM=1)  TRP

The modification made sure that the TRP subquery becomes the Driving Query. The relevant portion of the execution plan post modification is attached below. The calculation for WSH_TRIPS is still at 0.25% and is therefore computed as 4507, even then, the Optimizer takes this as a Driving Table, which is what we wanted. This again leads to a common argument, which is, Optimizer is a piece of Code that works on Statistics. It is the way we write a query that dominates the Optimizer.


|* 19 |                  WINDOW SORT PUSHED RANK         |                             | 26689 |
|* 20 |                   FILTER                         |                             |       |
|  21 |                    NESTED LOOPS                  |                             | 26689 |
|  22 |                     NESTED LOOPS                 |                             |  7968 |
|  23 |                      NESTED LOOPS                |                             |  4516 |
|* 24 |                       INDEX RANGE SCAN           | WSH_TRIPS_U1                |  4507 |
|  25 |                       TABLE ACCESS BY INDEX ROWID| WSH_TRIP_STOPS              |     1 |
|* 26 |                        INDEX RANGE SCAN          | WSH_TRIP_STOPS_N1           |     1 |
|  27 |                      TABLE ACCESS BY INDEX ROWID | WSH_DELIVERY_LEGS           |     2 |
|* 28 |                       INDEX RANGE SCAN           | WSH_DELIVERY_LEGS_N2        |     2 |
|* 29 |                     INDEX RANGE SCAN             | WSH_DELIVERY_ASSIGNMENTS_N1 |     3 |

  20 - filter(:P_TRIPID_FR=:P_TRIPID_FR AND "T"."TRIP_ID"=:P_TRIPID_FR AND "PICKUP_STOP"."TRIP_ID"<=:P_TRIPID_TO))
  28 - access("DL"."PICK_UP_STOP_ID"="PICKUP_STOP"."STOP_ID")
  29 - access("WDA"."DELIVERY_ID"="DL"."DELIVERY_ID")
       filter("WDA"."DELIVERY_ID" IS NOT NULL)

Yet another Query Plan Change ! Cost Based Optimization…

Optimizer relies on Statistics to compute an Optimal Plan, which includes : Choice between Index Scan or Table Scan, in case of Index Scan, which index to choose, and more importantly, the Join Order and Join Type. Therefore, it is quite evident that accurate statistics means a good and accurate estimation of Cardinality, which in turn, results in optimal execution plan. But there are cases, when accurate statistics is not good enough for an Optimizer to come out with an Optimal plan. In this blog, I will post a real life issue which is an interesting case, in which, the Optimizer generated plan, impacted the performance of a query whereas the underlying object statistics were accurate. Accurate statistics means the the statistics that reflect the accurate picture of the data in the underlying table.

In many of the events that I presented, one of the common statement that I emphasize is “Differentiate Performance Symptom and Performance Problem”. In this case too, the inhouse team was investigating and focussing more on the Symptom while the problem was somewhere else. We will walk through this as well.

Recently, at a customer site, the performance of one of a critical performance, that runs every few minutes, got impacted. The inhouse adminitrator time could investigate that execution time of one particular query, that usually takes less than a second, changed to 30-40 minutes. Fortunately, the customer maintains Query Baselines and this helped them further delve into the issue and they observed that the plan was changed. While they were investigating the issue and the reason for this plan change, the issue was temporarily fixed using SQL Plan Management. The customer wanted to know the reason for this behaviour, so as to avoid, this in future.

This was a custom process. The original query and the good / bad plan is pasted below.

SELECT WIP_ENTITY_NAME FROM WIP_DJ_CLOSE_TEMP 
WHERE	WIP_ENTITY_ID IN
	(SELECT wdct.WIP_ENTITY_ID            
	FROM	WIP_TRANSACTIONS wt,
		WIP_DJ_CLOSE_TEMP wdct             
	WHERE	wdct.GROUP_ID = :b1             
	AND	wdct.ORGANIZATION_ID = :b2
	AND	wdct.WIP_ENTITY_ID = wt.WIP_ENTITY_ID             
	AND	wt.ORGANIZATION_ID = :b3             
	AND	wt.TRANSACTION_DATE > wdct.ACTUAL_CLOSE_DATE   
	UNION    
	SELECT wdct.WIP_ENTITY_ID            
	FROM	MTL_MATERIAL_TRANSACTIONS mmt,
		WIP_DJ_CLOSE_TEMP wdct             
	WHERE	wdct.GROUP_ID = :b1             
	AND	wdct.ORGANIZATION_ID = :b2
	AND	wdct.WIP_ENTITY_ID = mmt.TRANSACTION_SOURCE_ID            
	AND	mmt.TRANSACTION_SOURCE_TYPE_ID = 5             
	AND	mmt.ORGANIZATION_ID= :b3
	AND mmt.TRANSACTION_DATE > wdct.ACTUAL_CLOSE_DATE)

Good Plan

Plan hash value: 2500423228

----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                               | Name                         | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                        |                              |       |       |  6017 (100)|          |       |       |
|   1 |  NESTED LOOPS                           |                              |       |       |            |          |       |       |
|   2 |   NESTED LOOPS                          |                              |    70 |  1960 |  6017   (1)| 00:00:36 |       |       |
|   3 |    VIEW                                 | VW_NSO_1                     |    70 |   910 |  5947   (1)| 00:00:35 |       |       |
|   4 |     SORT UNIQUE                         |                              |    70 |  3040 |  5947  (92)| 00:00:35 |       |       |
|   5 |      UNION-ALL                          |                              |       |       |            |          |       |       |
|   6 |       NESTED LOOPS                      |                              |       |       |            |          |       |       |
|   7 |        NESTED LOOPS                     |                              |    45 |  1890 |   490   (1)| 00:00:03 |       |       |
|*  8 |         TABLE ACCESS BY INDEX ROWID     | WIP_DJ_CLOSE_TEMP            |    80 |  1920 |     9   (0)| 00:00:01 |       |       |
|*  9 |          INDEX RANGE SCAN               | WIP_DJ_CLOSE_TEMP_N1         |   797 |       |     2   (0)| 00:00:01 |       |       |
|* 10 |         INDEX RANGE SCAN                | WIP_TRANSACTIONS_N1          |    24 |       |     0   (0)|          |       |       |
|* 11 |        TABLE ACCESS BY INDEX ROWID      | WIP_TRANSACTIONS             |     1 |    18 |     6   (0)| 00:00:01 |       |       |
|  12 |       NESTED LOOPS                      |                              |       |       |            |          |       |       |
|  13 |        NESTED LOOPS                     |                              |    25 |  1150 |  5455   (1)| 00:00:32 |       |       |
|* 14 |         TABLE ACCESS BY INDEX ROWID     | WIP_DJ_CLOSE_TEMP            |    80 |  1920 |     9   (0)| 00:00:01 |       |       |
|* 15 |          INDEX RANGE SCAN               | WIP_DJ_CLOSE_TEMP_N1         |   797 |       |     2   (0)| 00:00:01 |       |       |
|  16 |         PARTITION RANGE ITERATOR        |                              |     2 |       |    67   (0)| 00:00:01 |   KEY |    36 |
|* 17 |          INDEX RANGE SCAN               | MTL_MATERIAL_TRANSACTIONS_N2 |     2 |       |    67   (0)| 00:00:01 |   KEY |    36 |
|* 18 |        TABLE ACCESS BY LOCAL INDEX ROWID| MTL_MATERIAL_TRANSACTIONS    |     1 |    22 |    68   (0)| 00:00:01 |     1 |     1 |
|* 19 |    INDEX UNIQUE SCAN                    | WIP_DJ_CLOSE_TEMP_U1         |     1 |       |     0   (0)|          |       |       |
|  20 |   TABLE ACCESS BY INDEX ROWID           | WIP_DJ_CLOSE_TEMP            |     1 |    15 |     1   (0)| 00:00:01 |       |       |
----------------------------------------------------------------------------------------------------------------------------------------

Bad Plan

Plan hash value: 821054275

----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                               | Name                         | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                        |                              |       |       |  7295 (100)|          |       |       |
|   1 |  NESTED LOOPS                           |                              |    19 |   532 |  7295   (1)| 00:00:43 |       |       |
|   2 |   VIEW                                  | VW_NSO_1                     |    19 |   247 |  7276   (1)| 00:00:43 |       |       |
|   3 |    SORT UNIQUE                          |                              |    19 |   826 |  7276  (88)| 00:00:43 |       |       |
|   4 |     UNION-ALL                           |                              |       |       |            |          |       |       |
|*  5 |      TABLE ACCESS BY INDEX ROWID        | WIP_TRANSACTIONS             |     1 |    18 |     6   (0)| 00:00:01 |       |       |
|   6 |       NESTED LOOPS                      |                              |    12 |   504 |   930   (1)| 00:00:06 |       |       |
|*  7 |        TABLE ACCESS BY INDEX ROWID      | WIP_DJ_CLOSE_TEMP            |   152 |  3648 |    16   (0)| 00:00:01 |       |       |
|*  8 |         INDEX RANGE SCAN                | WIP_DJ_CLOSE_TEMP_N1         |  1522 |       |     4   (0)| 00:00:01 |       |       |
|*  9 |        INDEX RANGE SCAN                 | WIP_TRANSACTIONS_N1          |    24 |       |     0   (0)|          |       |       |
|* 10 |      HASH JOIN                          |                              |     7 |   322 |  6344   (1)| 00:00:37 |       |       |
|* 11 |       TABLE ACCESS BY INDEX ROWID       | WIP_DJ_CLOSE_TEMP            |   152 |  3648 |    16   (0)| 00:00:01 |       |       |
|* 12 |        INDEX RANGE SCAN                 | WIP_DJ_CLOSE_TEMP_N1         |  1522 |       |     4   (0)| 00:00:01 |       |       |
|  13 |       PARTITION RANGE ALL               |                              | 25149 |   540K|  6327   (1)| 00:00:37 |     1 |    36 |
|  14 |        TABLE ACCESS BY LOCAL INDEX ROWID| MTL_MATERIAL_TRANSACTIONS    | 25149 |   540K|  6327   (1)| 00:00:37 |     1 |    36 |
|* 15 |         INDEX RANGE SCAN                | MTL_MATERIAL_TRANSACTIONS_N8 | 25149 |       |   207   (1)| 00:00:02 |     1 |    36 |
|  16 |   TABLE ACCESS BY INDEX ROWID           | WIP_DJ_CLOSE_TEMP            |     1 |    15 |     1   (0)| 00:00:01 |       |       |
|* 17 |    INDEX UNIQUE SCAN                    | WIP_DJ_CLOSE_TEMP_U1         |     1 |       |     0   (0)|          |       |       |
----------------------------------------------------------------------------------------------------------------------------------------

Before diving into the analysis, let us compare both the plans and this will be from the customer’s perspective. They compared the plans and noticed that the Tables and Indexes selected by the optimizer, in both the cases, are same except for MTL_MATERIAL_TRANSACTION Table. The good plan uses N2 Index while the bad plan uses N8. Therefore, the customer hinted the query with N2 index and fixed the plan using SPM. Once fixed, they started their investigation on the reason for this change from N2 and N8. As mentioned earlier, this was just a Symptom while the underlying problem was something else. This something triggered the change in Index Selection and we will investigate this next.

Analysis

Comparing both the plans, it was now evident that the problem is with the second part of the Query, therefore, I took this part out for investigation. This is now a simple and small query, as show below :

SELECT wdct.WIP_ENTITY_ID            
FROM	apps.MTL_MATERIAL_TRANSACTIONS mmt,
	wip.WIP_DJ_CLOSE_TEMP wdct             
WHERE	wdct.GROUP_ID = :b1             
AND	wdct.ORGANIZATION_ID = :b2
AND	wdct.WIP_ENTITY_ID = mmt.TRANSACTION_SOURCE_ID            
AND	mmt.TRANSACTION_SOURCE_TYPE_ID = 5             
AND	mmt.ORGANIZATION_ID= :b3             
AND	mmt.TRANSACTION_DATE > wdct.ACTUAL_CLOSE_DATE

The another change that I noticed here was the change of Nested Loop Join to Hash Join. The customer had a clone environment of this database which was 2 months old and I executed this query on the clone enviroment. The Query executed in less than a second on this and therefore, the investigation wa further made simpler for me. The Query plan on the clone and production is pasted below :

Production Plan : BAD
Plan hash value: 3088015387

------------------------------------------------------------------------------------
| Id  | Operation                           | Name                         | Rows  |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                    |                              |       |
|*  1 |  HASH JOIN                          |                              |    49 |
|*  2 |   TABLE ACCESS BY INDEX ROWID       | WIP_DJ_CLOSE_TEMP            |   155 |
|*  3 |    INDEX RANGE SCAN                 | WIP_DJ_CLOSE_TEMP_N1         |  1552 |
|   4 |   PARTITION RANGE ALL               |                              | 24662 |
|   5 |    TABLE ACCESS BY LOCAL INDEX ROWID| MTL_MATERIAL_TRANSACTIONS    | 24662 |
|*  6 |     INDEX RANGE SCAN                | MTL_MATERIAL_TRANSACTIONS_N8 | 24662 |
------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("WDCT"."WIP_ENTITY_ID"="MMT"."TRANSACTION_SOURCE_ID")
       filter("MMT"."TRANSACTION_DATE">"WDCT"."ACTUAL_CLOSE_DATE")
   2 - filter("WDCT"."ORGANIZATION_ID"=:ORGANIZATION_ID)
   3 - access("WDCT"."GROUP_ID"=:GROUP_ID)
   6 - access("MMT"."TRANSACTION_SOURCE_TYPE_ID"=5 AND "MMT"."ORGANIZATION_ID"=:ORGANIZATION_ID)

Clone DB Plan : GOOD
Plan hash value: 569619275

-----------------------------------------------------------------------------------
| Id  | Operation                          | Name                         | Rows  |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                              |       |
|   1 |  NESTED LOOPS                      |                              |       |
|   2 |   NESTED LOOPS                     |                              |    26 |
|*  3 |    TABLE ACCESS BY INDEX ROWID     | WIP_DJ_CLOSE_TEMP            |    80 |
|*  4 |     INDEX RANGE SCAN               | WIP_DJ_CLOSE_TEMP_N1         |   798 |
|   5 |    PARTITION RANGE ITERATOR        |                              |     2 |
|*  6 |     INDEX RANGE SCAN               | MTL_MATERIAL_TRANSACTIONS_N2 |     2 |
|*  7 |   TABLE ACCESS BY LOCAL INDEX ROWID| MTL_MATERIAL_TRANSACTIONS    |     1 |
-----------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------

   3 - filter("WDCT"."ORGANIZATION_ID"=:ORGANIZATION_ID)
   4 - access("WDCT"."GROUP_ID"=:GROUP_ID)
   6 - access("WDCT"."WIP_ENTITY_ID"="MMT"."TRANSACTION_SOURCE_ID" AND "MMT"."ORGANIZATION_ID"=:ORGANIZATION_ID AND
              "MMT"."TRANSACTION_DATE">"WDCT"."ACTUAL_CLOSE_DATE")
   7 - filter("MMT"."TRANSACTION_SOURCE_TYPE_ID"=5)

Notice the estimated rows calculated by the optimizer for the driving Index and Table. In clone db, the optimizer says 798 rows from an Index TEMP_N1 and then 80 Rows from the Table Access component. On production, the optimizer computes 1552 rows from the driving Index TEMP_N1 and then 155 rows from the Table Access. The optimizer further computes that 155 Iteration of MTL_MATERIAL_TRANSACTION (Nested Loop) will be a costly affair and therefore opts for a Hash Join. Since the clone db was 2 months old, the statistics were also old. Once I was convinced that estimated cardinality for the driving table seems to be an issue, I imported the production stats to clone and simulated the issue. I imported the stats of only the WIP_DJ_CLOSE_TEMP table on clone and could simulate the performance impact. The Table and relevant Column Level statistics of WIP_DJ_CLOSE_TEMP is pasted below. I have removed unwanted column stats from this post. This is from the clone and production.

Clone Stats - Performance Optimal

SQL> @table_stats
Enter value for 1: WIP_DJ_CLOSE_TEMP
old   2: where table_name='&1'
new   2: where table_name='WIP_DJ_CLOSE_TEMP'

OWNER                          PAR   NUM_ROWS     BLOCKS LAST_ANAL GLO T
------------------------------ --- ---------- ---------- --------- --- -
WIP                            NO      118836        829 26-SEP-10 YES N

Elapsed: 00:00:00.23
SQL> @column_stats
Enter value for 1: WIP
old   3: where owner='&1'
new   3: where owner='WIP'
Enter value for 2: WIP_DJ_CLOSE_TEMP
old   4: and   table_name='&2'
new   4: and   table_name='WIP_DJ_CLOSE_TEMP'

COLUMN_NAME                    NUM_DISTINCT  NUM_NULLS    DENSITY HISTOGRAM
------------------------------ ------------ ---------- ---------- ---------------
GROUP_ID                                149          0 .006711409 NONE
ORGANIZATION_ID                          10          0         .1 NONE

Production Stats - Performance sub-optimal

OWNER                          PAR   NUM_ROWS     BLOCKS LAST_ANAL GLO
------------------------------ --- ---------- ---------- --------- ---
WIP                            NO      116383        829 28-NOV-10 YES

COLUMN_NAME                    NUM_DISTINCT  NUM_NULLS    DENSITY HISTOGRAM
------------------------------ ------------ ---------- ---------- ---------------
GROUP_ID                                 75          0 .013333333 NONE
ORGANIZATION_ID                          10          0         .1 NONE

Index Details of MTL_MATERIAL_TRANSACTIONS

INDEX_NAME                     COLUMN_NAME                    COLUMN_POSITION
------------------------------ ------------------------------ ---------------
MTL_MATERIAL_TRANSACTIONS_N2   TRANSACTION_SOURCE_ID                        1
                               ORGANIZATION_ID                              2
                               TRANSACTION_DATE                             3

MTL_MATERIAL_TRANSACTIONS_N8   TRANSACTION_SOURCE_TYPE_ID                   1
                               ORGANIZATION_ID                              2
                               TRANSACTION_DATE                             3
                               TRANSACTION_SOURCE_NAME                      4

Issue

As mentioned at the start of this post, while the statistics are relevant for selection between an Index Scan and Table Scan and in case of Index Scan, which Index to select; the most important factor is the Computed Cardinality of the driving table as this has an impact on the Join Order and Join Type. Further, the Join Type dictates the selection of an Index for the other tables. The difference between the Nested Loop Join and Hash Join, in terms of Index Selection is : Nested Loop Join will select rows from the driving table and then use an Index on the Join Column, if it exists (else it will be an hash join), of the second table. Therefore, in case of a good plan, with the Nested Loop Join in place, the optimizer opted for N2 Index of MTL_MATERIAL_TRANSACTION table which is an Index on Join Column. In case of Hash Join, the Optimizer will try to filter out as many rows as possible for both the tables using an Index on filter predicates and once the rows are filtered, will join these using hash function on the Join Columns. Therefore, in case of the Hash Join, the index N8 of MTL_MATERIAL_TRANSACTION is on filter column and then the rows filtered were joined using hash function on the Join Column. See the PREDICATE INFORMATION for both the Good and Bad Plans above and the Index Column details for MTL_MATERIAL_TRANSACTION pasted above.

The Calculation : Clone Old Stats

Let us get into the computed cardinality calculation for the driving table, as this had an impact on the Join Type. On clone the number of Rows are : 118836 and the WHERE predicate for this table is as under :

WHERE	wdct.GROUP_ID = :b1             
AND	wdct.ORGANIZATION_ID = :b2

The Table has an Index on GROUP_ID column and the calculation says 118836*1/149 = 797.55, rounded off to 798. Further, it has to filter based on non-indexed column, which is Organization_ID and the calculation says 798*1/10=79.8 rounded off to 80. The clone db (good) plan shows the same.

The Calculation : Production Stats

On Production, the computed cardinality calculation for the index scan step is 116383*1/75 = 1551.77, rounded off to 1552. Further, the filter based on non-indexed column is 1552*1/10 = 155.2, rounded off to 155. The production plan shows the same.

In the case of production statistics, the statistics were collected on Sunday and this triggered the change in plan. Further, these stats were accurate, even then, the optimizer came out with a plan that was sub-optimal. As mentioned, we could simulate the issue on Clone DB after importing the statistics of the driving table – WIP_DJ_CLOSE_TEMP. As a resolution and to check the impact, we modified the column level statistics of GROUP_ID column on clone db to 200 and the plan changed to good.

As the name of the driving table implies – WIP_DJ_CLOSE_TEMP, this is an interface table and the rows are deleted and inserted into this table. The table usually contain More or Less 0.1 Million Rows. Therefore, as a final action, once the column level statistics for GROUP_ID column was fixed on production, we locked the statistics of this table. This was to ensure that the plan of this query will not be impacted after periodic statistics generation and remains stable.

After manually setting the column level statistics for GROUP_ID column to 200, the plan is as under :

Plan hash value: 569619275

-----------------------------------------------------------------------------------
| Id  | Operation                          | Name                         | Rows  |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                              |       |
|   1 |  NESTED LOOPS                      |                              |       |
|   2 |   NESTED LOOPS                     |                              |    18 |
|*  3 |    TABLE ACCESS BY INDEX ROWID     | WIP_DJ_CLOSE_TEMP            |    58 |
|*  4 |     INDEX RANGE SCAN               | WIP_DJ_CLOSE_TEMP_N1         |   582 |
|   5 |    PARTITION RANGE ITERATOR        |                              |     2 |
|*  6 |     INDEX RANGE SCAN               | MTL_MATERIAL_TRANSACTIONS_N2 |     2 |
|*  7 |   TABLE ACCESS BY LOCAL INDEX ROWID| MTL_MATERIAL_TRANSACTIONS    |     1 |
-----------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   3 - filter("WDCT"."ORGANIZATION_ID"=:ORGANIZATION_ID)
   4 - access("WDCT"."GROUP_ID"=:GROUP_ID)
   6 - access("WDCT"."WIP_ENTITY_ID"="MMT"."TRANSACTION_SOURCE_ID" AND "MMT"."ORGANIZATION_ID"=:ORGANIZATION_ID AND
              "MMT"."TRANSACTION_DATE">"WDCT"."ACTUAL_CLOSE_DATE")
   7 - filter("MMT"."TRANSACTION_SOURCE_TYPE_ID"=5)

Production Stats - Performance sub-optimal

OWNER                          PAR   NUM_ROWS     BLOCKS LAST_ANAL GLO
------------------------------ --- ---------- ---------- --------- ---
WIP                            NO      116383        829 28-NOV-10 YES

COLUMN_NAME                    NUM_DISTINCT  NUM_NULLS    DENSITY HISTOGRAM
------------------------------ ------------ ---------- ---------- ---------------
GROUP_ID                                200          0 .013333333 NONE
ORGANIZATION_ID                          10          0         .1 NONE

The calculation now stands as Index Step : 116383*1/200 = 581.91, rounded off to 582. Table Access : 582*1/10 = 58.2, rounded off to 58. This resolved the issue.

In this scenario, Investigating the statistics on MTL_MATERIAL_TRANSACTIONS table would have resulted futile,as this change was just a symptom due to the problem with stats on the driving table.

Cardinality Feedback ! 11g New Auto Optimization feature..

Few days back, I was working on a minor performance issue post 11g upgrade. The reason I mention minor issue because the customer did extensive testing, as a result the performance and execution plan of all, except 1 or 2, queries were optimal. While I was working on the optimizer behaviour in 11g that would have caused this plan change for the two sql’s, I came across “Cardinality Feedback used for this statement” message just under the runtime plan. This was something new to me and therefore, I started my investigation on this. While I was still on the job of investigation, the onsite dba asked me whether I have made some changes at the db level. He wanted to confirm this because all of a sudden the Execution Plan for these 2 queries changed from worse to good. This was a surprise. This change in plan was due to the Cardinality Feedback, introduced in 11g.

Today, I was at another customer site for a small round of discussion when someone mentioned that post 11g Upgrade, one of their batch processes takes longer and they have found out that the plan for one main query has changed for bad. I logged in to the system and again noticed “Cardinality Feedback used for this statement” message. I made a small change in the query (this change was just a change of select to Select) so that it is hard parsed. The Query came out in less than a minute, which was the case earlier i.e 10g. I re-executed the query and this time I had to cancel it after 10 minutes. The plan changed at runtime and this change made this query change the execution time from less than a minute to more than 10 minute and still executing. This time, at this customer site, the runtime plan change was from good to bad.

What is Cardinality Feedback ?

As of now, there is not much documentation available on this optimization strategy or feature and therefore, whatever I write on this is purely a guesswork. I am still investigating on this and something, if available, will feature in my next blogs.

I assume that the strategy works on the internal mechanism of GATHER_PLAN_STATISTICS hint that calculates the Estimated Rows and Actual Rows. In this case, when the Query is Hard Parsed, the optimizer generates an execution plan based on the estimated rows. As usual, this estimation is from the object and column statistics. At the end of the query execution, the Optimizer also retains the Actual rows fetched by each of the steps. If a huge difference is observed between the two statistics (E-Rows and A-Rows), during subsequent executions of the same query, the optimizer generates another child cursor with a new execution plan.

This optimization strategy is controlled by an underscore parameter _optimizer_use_feedback that defaults to true.

Cost based Optimizer ! Inefficient input yields inefficient Output…

Since the time my old blog went inaccessible, and still is, I have been receiving several mails on my previous blogs that helped some of my readers relate and resolve their performance issues. They wanted access to my previous blogs and I have been requesting them to let me know any particular blog that was of interest and I may publish them right here. There were many requests to publish blogs on Cost Based Optimizer and therefore, thought of publishing some of them. While these blogs may not be relevant for the current versions of Oracle, there are still some production systems that are still on Oracle 8i and 9i, and these blogs may be of help for those instances. Wherever any of the Cost Based Optimization blog that are relevant for certain versions of Oracle, I will specifically mention them for the benefits of the readers.

This blog is relevant for Oracle 8i and 9i (without System Statistics)

Cost Based Optimizer has always been a mystery for most of the Database Administrators and Developers. The calculation made by the Optimizer to come-up with an Execution Plan has been doubted by many of the Oracle users, especially, when (to name a few) :

  1. The Application Performance Degrades after Version Upgrade
  2. Plan of a Query change after gathering of fresh Statistics, and
  3. The Performance of a Query with higher cost is much better that the plan with a least cost

Cost Based Optimizer has improved a lot in previous few versions. Therefore, it can be said that CBO is still undergoing some enhancements. With these enhancements, Oracle Users have accepted the fact that the Application Performance might degrade after version upgrade and leave no room with rigorous testing of the application before production upgrade. It is fact no.2 and 3 that raises a doubt over Cost Based Optimization.

Cost Based Optimizer is a piece of code, wherein, you provide Inputs, by way of Optimizer Parameters, Statistics and it computes and generates an Output which is seen as an Execution Plan. It is not only the Optimizer Parameters and Statistics, which is passed as an Input. There is one more component, which is mostly overlooked, a QUERY. The initial input passed is the Query and based on the way it is written, optimizer does its cost calculation by taking into account the other two : Parameters and Statistics. In this blog, I will address the last two facts stated above, plus, a common misconception that Index Scan is better that Full Table Scan and finally, the issue with the critical first component passed as an input to CBO, A Query.

Recently, was working on a performance issue, related to a critical process. The overall performance of the system was OK, but one critical process started taking 18-20 hours, failing several times with ora-1555. This process, usually takes 1 hour 30 minutes. Therefore, all of a sudden, why this degradation ?, was the question raised by the customer.

The Database version is 8174. This is one of a critical process and a part of seeded application. It connects to a user, dedicated for this process, therefore, when this process is running, it is very easy to get the sid of the session executing this process. While monitoring the performance of this process, by querying v$session_wait for the sid, I could see one particular query doing exorbitant amount of Logical Reads. The text of the query and execution plan is as under :

explain plan for
select CS.CO_ID ,CS.SPCODE ,CS.SNCODE ,CS.TMCODE ,CS.CS_SEQNO ,CS.CS_STAT_CHNG ,
to_char(CS.TRIAL_END_DATE,'YYYYMMDDHH24MISS')
from       CR_SERVICES CS
where      (CS.CO_ID not  in (select CO_ID
                             from CO_ALL
                             where (CO_ID=CS.CO_ID and CUSTOMER_ID=DEALER_ID))
and        CS.SNCODE in (select distinct SNCODE  from MPV
                     where (SNCODE=CS.SNCODE and RATING_IND='Y')));

Explained.

SQL> @?/rdbms/admin/utlxpls

Plan Table
------------------------------------------------------------------------------------------
| Operation                 |  Name    |  Rows | Bytes|  Cost  | Pstart| Pstop |
--------------------------------------------------------------------------------
| SELECT STATEMENT          |                    |     1K|   77K| 141575 |       |       |
|  FILTER                   |                    |       |      |        |       |       |
|   NESTED LOOPS            |                    |     1K|   77K| 141575 |       |       |
|    TABLE ACCESS FULL      |MPV                 |    74 |  444 |     13 |       |       |
|    TABLE ACCESS BY INDEX R|CR_SERVICES         |     3M|  120M|   1913 |       |       |
|     INDEX RANGE SCAN      |I1_CR_SERVICES      |     3M|      |   1616 |       |       |
|   FILTER                  |                    |       |      |        |       |       |
|    INDEX RANGE SCAN       |IDX_CUST_CO_DEALER  |     1 |   14 |      2 |       |       |
--------------------------------------------------------------------------------

There are three tables in the query. The Driving Table, from the explain plan, MPV is a small table with 220 rows and 80 Blocks, while the other two are huge tables with 69 Million and 30 Million Rows. Usually, such situation can crop-up due to following reasons :

  1. Change in Optimizer Parameters
  2. Change in Statistics
  3. Creation of New Index

Initial Investigation revealed that the Statistics of CR_SERVICES table and indexes were gathered the previous night. Once this was confirmed, Cost Based Optimization was at the receiving end. This is quite natural as without any change in the application query, the plan changed for bad, due to CBO. Therefore, thorough investigation was required about the cause of this plan change. Seeing the query and other optimizer statistics, Full Table Scan on CR_SERVICES would have been a better choice and therefore, my investigation was around this. Let us revisit the relevant portion of the Execution Plan, the statistics and the Query.

## Table Statistics of CR_SERVICES

OWNER                          PAR   NUM_ROWS     BLOCKS 
------------------------------ --- ---------- ---------- 
SM                             NO    69875510    1107733 

## Column Stats of the Columns used on the Query

COLUMN_NAME                    NUM_DISTINCT  NUM_NULLS    DENSITY
------------------------------ ------------ ---------- ----------
CO_ID                               6863377          0 1.4570E-07
SNCODE                                  370          0 .002702703  @?/rdbms/admin/utlxpls

Plan Table
------------------------------------------------------------------------------------------
| Operation                 |  Name    |  Rows | Bytes|  Cost  | Pstart| Pstop |
--------------------------------------------------------------------------------
|   NESTED LOOPS            |                    |     1K|   77K| 141575 |       |       |
|    TABLE ACCESS FULL      |MPV                 |    74 |  444 |     13 |       |       |
|    TABLE ACCESS BY INDEX R|CR_SERVICES         |     3M|  120M|   1913 |       |       |
|     INDEX RANGE SCAN      |I1_CR_SERVICES      |     3M|      |   1616 |       |       |

The Query is using an Index on SNCODE column, which is a very low cardinality column. Therefore, this was my primary target and I worked on the Optimizer Calculation to get the possible cause of this Index Scan.

Optimizer Calculation


The Cost Calculation of an Index Scan and Table Scan via Index is

Index Cost = Blevel+ceil(leaf_blocks*ix_selectivity) 
Table Scan = ceil(clustering_factor*table_selectivity) 

select 3+ceil(596745*1/370) "Index Scan Cost", ceil(40527179*1/370) from dual;
Index Cost = 1616 ## This matches the execution plan
Table Scan = 109533
Final Cost = 1616+109533=111149

select 3+ceil(596745*1/370) "Index Scan Cost", ceil(40527179*1/370*1/370) from dual;
Index Cost = 1616
Table Scan = 297
Final Cost = 1616+297=1913 ## This Matches with the Cost calculated by the Optimizer

This additional 1/370, was due to the fact that SNCODE column is used twice in the query. One for Index Filter, therefore considered only once for an index cost, and twice for Table cost due to SNCODE=CS.SNCODE join. The final Nested Loop Cost is 141575 and this is calculated as

NL Cost = Cost of an Outer Table + (Cost of Inner Table * Cardinality of Outer Table)
NL Cost = 13 + (1913*74)
NL Cost = 141575

Cost of Full Table Scan = Num Blocks / 6.59 (8k block size)
Cost of Full Table Scan = 1107733 / 6.59
Cost of Full Table Scan = 168093.02

Clearly, the cost of a Full Table Scan is higher than the Nested Loop Join and optimizer opted for the cheaper costed plan, which is, a Nested Loop Join and this requires an Index Scan of an Inner Table. When I checked the execution plan of this query with a FULL hint on CR_SERVICES, the FTS cost was 168200. I am yet to figure out the difference between my calculation and optimizer calculation, but for investigation purpose, I considered the calculation done by the optimizer. Based on this calculation, I came out with three possible solutions, these are :

  1. Modify the Query (Immediately Not possible, as it is a seeded query)
  2. Change Optimizer Statistics
  3. Change Optimizer Parameters

The first optimization was a better and safe approach, but was not possible immediately. The other two required some testing, as change in Optimizer Statistis can have negative impact on other queries using these objects and, change in optimizer parameters at db level can have an global impact on the overall performance. As mentioned earlier, this process connects to a user dedicated for this process, therefore, ON-LOGON trigger with the Optimizer Parameter change at session level was thought of as a better option without impacting overall application performance. The parameter, I could immediately think of was, OPTIMIZER_INDEX_COST_ADJ. This parameter was default i.e.100. For this query, to force Index Cost be Costlier than FTS, the calculation is OICA = (FTS Cost/NL Cost)*100 = (168200/141575)*100 = 118.80. Any value above this, would compute the NL cost be costlier than Full Table Cost and would opt for FTS and Hash Join. Initially, the Change was done at session level and the plan changed.

Plan Table
------------------------------------------------------------------------------------------
| Operation                 |  Name    |  Rows | Bytes|  Cost  | Pstart| Pstop |
--------------------------------------------------------------------------------
| SELECT STATEMENT          |                    |     1K|   77K| 168219 |       |       |
|  FILTER                   |                    |       |      |        |       |       |
|   HASH JOIN               |                    |     1K|   77K| 168219 |       |       |
|    TABLE ACCESS FULL      |MPV                 |    74 |  444 |     13 |       |       |
|    TABLE ACCESS FULL      |CR_SERVICES         |     3M|  120M| 168200 |       |       |
|   FILTER                  |                    |       |      |        |       |       |
|    INDEX RANGE SCAN       |IDX_CUST_CO_DEALER  |     1 |   14 |      2 |       |       |
--------------------------------------------------------------------------------

Finally, ON-LOGON trigger was created to set this parameter to 120, whenever, this user logged on to the database. The process, when re-executed, completed in 1 Hour 15 minutes and the desired performance was achieved.

Optimizer Calculation with OICA as 120


NL Table Scan Cost = (Current Cost of Inner Table Scan * Outer Table Card)*OICA/100
NL Table Scan Cost = (1913*74)*120/100
NL Table Scan Cost = (1913*74)*120/100
NL Table Scan Cost = 169874.4 > 168200 (FTS)

With this setting, the plan changed. Now for the reverse engineering. I wanted to check for any of the Index Statistics, say Clustering Factor, that would have calculated NL Join costlier than Full Table Scan. The Cost of NL Join with OICA is 169874.4. The cost of Table Scan via Index should be round(169874.4/74), which is 2296. Index Scan Cost is 1616, so the Table Scan cost component should be 2296-1616 is 680. Based on this, I calculated that if the Clustering Factor is changed to 93092000, then without any parameter setting, the query would go for a Full Table Scan. 

SQL> exec dbms_stats.SET_INDEX_STATS('SM','I1_CR_SERVICES',CLSTFCT=>93092000);

PL/SQL procedure successfully completed.

SQL> @index_stats
Enter value for o: SM
old   3: where table_owner='&O'
new   3: where table_owner='SM'
Enter value for t: CR_SERVICES
old   4: and   table_name='&T'
new   4: and   table_name='CR_SERVICES'

INDEX_NAME                       NUM_ROWS     BLEVEL LEAF_BLOCKS DISTINCT_KEYS CLUSTERING_FACTOR
------------------------------ ---------- ---------- ----------- ------------- -----------------
I1_CR_SERVICES                   70724121          3      596745      11207514          93092000 

12 rows selected.

explain plan for
select CS.CO_ID ,CS.SPCODE ,CS.SNCODE ,CS.TMCODE ,CS.CS_SEQNO ,CS.CS_STAT_CHNG ,
to_char(CS.TRIAL_END_DATE,'YYYYMMDDHH24MISS')
from       CR_SERVICES CS
where      (CS.CO_ID not  in (select CO_ID
                             from CO_ALL
                             where (CO_ID=CS.CO_ID and CUSTOMER_ID=DEALER_ID))
and        CS.SNCODE in (select distinct SNCODE  from MPV
                     where (SNCODE=CS.SNCODE and RATING_IND='Y')));

Explained.

SQL> @?/rdbms/admin/utlxpls

Plan Table
------------------------------------------------------------------------------------------
| Operation                 |  Name    |  Rows | Bytes|  Cost  | Pstart| Pstop |
--------------------------------------------------------------------------------
| SELECT STATEMENT          |                    |     1K|   77K| 168219 |       |       |
|  FILTER                   |                    |       |      |        |       |       |
|   HASH JOIN               |                    |     1K|   77K| 168219 |       |       |
|    TABLE ACCESS FULL      |MPV                 |    74 |  444 |     13 |       |       |
|    TABLE ACCESS FULL      |CR_SERVICES         |     3M|  120M| 168200 |       |       |
|   FILTER                  |                    |       |      |        |       |       |
|    INDEX RANGE SCAN       |IDX_CUST_CO_DEALER  |     1 |   14 |      2 |       |       |
--------------------------------------------------------------------------------

11 rows selected.

Back to the problem, does it look like to be an Optimizer Issue ? This table has a very high growth rate. While the num_blocks value of a table grows faster, the statistics of Leaf Blocks, BLevel and Clustering Factor does not change significantly. This is enough to blow up the cost of a Full Table Scan. If you see the query and the relevant portion of the query, pasted above, the join on SNCODE is really not required as it uses an IN clause. This unwanted join, forced the optimizer to consider the Density of SNCODE twice in Table Scan cost calculation.

## Relevant portion of the Query and Plan

and        CS.SNCODE in (select distinct SNCODE  from MPV
                     where (SNCODE=CS.SNCODE and RATING_IND='Y')));

## Optimizer Calculation (1/370 is considered twice to get Table Scan cost of 297, thus making it cheaper).
Index Cost = Blevel+ceil(leaf_blocks*ix_selectivity) 
Table Scan = ceil(clustering_factor*table_selectivity) 

select 3+ceil(596745*1/370) "Index Scan Cost", ceil(40527179*1/370*1/370) from dual;
Index Cost = 1616
Table Scan = 297
Final Cost = 1616+297=1913 

If this portion of the query is modified as :


and        CS.SNCODE in (select distinct SNCODE  from MPV
                     where (RATING_IND='Y')));

## Optimizer Calculation, with this change
Index Cost = Blevel+ceil(leaf_blocks*ix_selectivity) 
Table Scan = ceil(clustering_factor*table_selectivity) 

select 3+ceil(596745*1/370) "Index Scan Cost", ceil(40527179*1/370) from dual;
Index Cost = 1616
Table Scan = 109533
Final Cost = 1616+109533= 111149

## With this Cost, the cost of NL Join would have been

NL Cost = Cost of an Outer Table + (Cost of Inner Table * Cardinality of Outer Table)
NL Cost = 13 + (111149*74)
NL Cost = 8225039 > 168200 (FTS)

One unwanted Join Condition made Cost based Optimizer to come up with an in-efficient plan. Therefore, as mentioned earlier, my Initial and Crucial input to the optimizer is a Query and if these are not optimally written, Cost Based Optimizer is bound to compute an sub-optimal plan. The Query, modified by removing unwanted join and no parameter change or statistics change, gave the desired and better plan (see below ).

explain plan for
select CS.CO_ID ,CS.SPCODE ,CS.SNCODE ,CS.TMCODE ,CS.CS_SEQNO ,CS.CS_STAT_CHNG ,
to_char(CS.TRIAL_END_DATE,'YYYYMMDDHH24MISS')
from       CR_SERVICES CS  
where      (CS.CO_ID not  in (select CO_ID
                               from CO_ALL
                               where (CO_ID=CS.CO_ID and CUSTOMER_ID=DEALER_ID))
and        CS.SNCODE in (select distinct SNCODE  from MPV
                       where (RATING_IND='Y')));

Explained.

SQL> @?/rdbms/admin/utlxpls

Plan Table
------------------------------------------------------------------------------------------
| Operation                 |  Name    |  Rows | Bytes|  Cost  | Pstart| Pstop |
--------------------------------------------------------------------------------
| SELECT STATEMENT          |                    |     1K|   77K| 168219 |       |       |
|  FILTER                   |                    |       |      |        |       |       |
|   HASH JOIN               |                    |     1K|   77K| 168219 |       |       |
|    TABLE ACCESS FULL      |MPV                 |    74 |  444 |     13 |       |       |
|    TABLE ACCESS FULL      |CR_SERVICES         |     3M|  120M| 168200 |       |       |
|   FILTER                  |                    |       |      |        |       |       |
|    INDEX RANGE SCAN       |IDX_CUST_CO_DEALER  |     1 |   14 |      2 |       |       |
--------------------------------------------------------------------------------

Many developers are of the Opinion that an Execution Plan with cheaper cost is better than a Plan with higher cost, and Index Scans are better than Full Table Scans. This blog demonstrates that these are just misconceptions and it is the application design and knowledge that should be taken into account while writing an effecient code.

To sum up, it is just not the Optimizer Statistics and Parameter that control the Cost Based Optimizer, Queries play an important role too. A well written code should never bother or doubt about Cost Based Optimization.

Cache Buffers Chains Latch Contention…..

Few days back, I got a call from one of my customer about a severe latch contention issue that had been forcing them to restart a database. This phenomenon had been occurring for last past 1 month and for every occurrence the database had to be restarted. This being a critical 24×7 system, for obvious reason, restart was not a solution and when the inhouse dba team gave up on this, I was called upon to investigate the issue.

The database version is 9205 and seeing the statspack during the bad times, it was evident that the contention was on Cache Buffers Chains Latch. In most of the cases, CBC Latch contention come due to inefficient application queries with these consuming huge logical reads per execution. In this case too, as evident from the Statspack, these huge logical reads queries were the primary reason. There were many queries with Millions of Logical Reads and optimizing these would surely give relief as the amount of latching while acquiring block in the cache will come down. While some of the information was available in the Statspack report, I queried x$bh view to check for the block distribution across each CBC Child Latch. For simplicity of the readers, X$BH is an Oracle Internal table that maintains the history of the buffers in the Cache alongwith the hash chains these are allocated to. Usually, the distribution of the blocks or buffers in the cache should be approximately uniform across each hash chain. The Query executed to get the distribution alongwith the output is as under :

This Output is when the system was running perfectly fine without any latch contention.

select * from (
select hladdr, count(*) from x$bh group by hladdr order by 2 desc)
where rownum<=20;

HLADDR             COUNT(*)
---------------- ----------
07000003E2771BA8        197
07000003E661DE70        161
07000003E6305250        157
07000003E661CE90        157
07000003E3F2B0E8        154
07000003E199FA00        153
07000003E4E45FF0        153
07000003E6607150        153
07000003E76A42D0        152
07000003E19A19C0        151
07000003E3DB9F68        151
07000003E5A0F920        151
07000003E78C9D90        151
07000003E76A2310        151
07000003E64E45F0        151
07000003E1A07CE0        150
07000003E4CD7E10        150
07000003E4E45010        150
07000003E4DBA190        150
07000003E3F30048        150

20 rows selected.

As seen from the Good Time output, the buffers protected by each hash chains are nearly uniform. Fortunately, when I was monitoring the system for 2-3 days, I could capture these buffer distribution across each hash chains during Latch Contention and the figures for the top most hash chain looked alarming. The Output captured during the issue is as under :

HLADDR             COUNT(*)
---------------- ----------
07000002570F7300       8734
070000025A786078        364
070000025A5020D8        167
0700000262E9A9E0        167
07000002562DD4D0        164
07000002583D9C00        164
07000002563162C0        161
07000002563BE270        161
07000002571D9AF0        161
0700000262E9C420        161
0700000256341080        161
07000002572C8650        160
07000002583D74A0        160
070000025A838098        160
0700000259557A20        160
07000002562DA010        159
07000002571E2B50        159
07000002582778A0        159
070000025955D600        154
07000002584C1140        151

20 rows selected.

This clearly indicates Hot Block Contention, which means, a block that several processes are trying to access simultaneously. A Long Hash Chain means that a query or set of queries are creating a consistent read image of a particular block and since, a block, even if it has multiple images, will be hashed to a same child latch, a hash chain can grow longer causing latch contention. Next step was to Capture Data relevant to the current issue and therefore the data collected for further investigation was :

  1. Top Blocks / Objects with high Touch Count
  2. Top Running Queries with high Buffer Gets

The First step was to identify the block, and the object it belongs too, with highest Touch Count. This counter is maintained in TCH column of X$BH. The Query used to get this detail is as under :

select a.hladdr, a.file#, a.dbablk, a.tch, a.obj, b.object_name
from   	x$bh a, 
	dba_objects b
where  	(a.obj = b.object_id  or  a.obj = b.data_object_id)
and 	hladdr='07000002570F7300' 
order by 4;

From the output (not mentioned in this blog), I could see two objects S_BRANCH and BA_TMP_HOFF as the top most object. While BA_TMP_HOFF (normal heap table) was contributing to the latch contention with highest touch count, the sessions were waiting on S_BRANCH table due to high concurrency on this table.

The second step was to capture the top running queries with high buffer gets per execution and some of these are mentioned below (I have mentioned only few of them and have cut short the text) :

HASH_VALUE SQL_TEXT                                           EXECUTIONS GETS_PER_EXEC
---------- -------------------------------------------------- ---------- -------------
 603848796 SELECT    FN_NEWBRANCH(A.BRANCH) BRANCH,    A.PROD          1       5294194
           UCT_CODE PRODUCT,    B.PRODUCT_DESCRIPTION PROD_DE
           SCRIPTION,    A.CONTRACT_REF_NO CONTRACT_REF_NO,
             A.USER_REF_NO USER_REF_NO,    C.COLLECTION_REF,
              C.BILL_CCY BILL_CCY,    C.BILL_AMT BILL_AMOUNT,
 
 784509366 SELECT    FN_NEWBRANCH(C.BRANCH) BRANCH,    C.PROD          8       2306090
           UCT_CODE PROD_CODE,    C.CONTRACT_REF_NO,    C.USE
           R_REF_NO,    B.PARTY_ID DRAWER_ID,       B.PARTY_N
           AME DRAWER,    B.PARTY_REFNO DRAWER_REF,    A.PART
           Y_ID DRAWEE_ID,    A.PARTY_NAME DRAWEE,    A.PARTY
 
 322980110 SELECT    FN_NEWBRANCH(CSTBS_CONTRACT.BRANCH),              3        811376
           CSTBS_CONTRACT.PRODUCT_CODE,    CSTMS_PRODUCT.PROD
           UCT_DESCRIPTION,    BCTB_CONTRACT_MASTER.CUSTOMER_
           ID,    STTMS_CUSTOMER.CUSTOMER_NAME1,    CSTBS_CON
           TRACT.CONTRACT_REF_NO,    CSTBS_CONTRACT.USER_REF_

POST-INVESTIGATION DISCUSSION WITH THE APPLICATION OWNER

Further, once the Contending Object (S_BRANCH) and Contributor (BA_TMP_HOFF) was found, during the discussion with the Owner of this Production System it was revealed that the load (number of records processed) by a batch processes that is run in 10 parallel streams has gone up by 3 times and all these batch processes heavily access (select and update) BA_TMP_HOFF table.

During the latch contention, almost 95% of the sessions waiting on CBC Latches query S_BRANCH. The application owner further mentioned that, while this table is static, it is heavily queried as it is a BRANCH Master table and is joined to several other tables to get the Name of the Branch. This input was interesting and is a heart of the this blog. Interestingly, the queries captured for the waiting sessions during the latch free waits were of exactly same type i.e. get the branch name from S_BRANCH and were doing 4 Logical I/O’s per executions using a Table Scan via Primary Key Index. Since these were doing only 4 logical I/O’s per execution, these queries were not on top of the list capture above. The top queries captured were based on the Gets Per Executions.

ANALYSIS AND RESOLUTION

It was time implement some of the changes that would give the customer relief from the ongoing issues. WHile optimization of the Batch Processes involving BA_TMP_HOFF table would have required Understanding the Business Logic, Making Changes, Testing and Implementing and would have taken longer, the emphasis was more to implement a change that does not require extensive testing and therefore may take less time. Therefore, the change that would have given some relief was optimizing Queries on S_BRANCH table. The Concern raised by the Application Owner here was “Will Optimization of a Query with 4 Logical I/O’s per Execution give relief from Latch Contention ?”

To resolve the Latch Contention, my focus was not on reducing the I/O’s of the Queries on S_BRANCH from 4 to lesser but was to reduce the concurrency on this object by way of optimization. If you see the top queries captured above (step 2 of the data collected during the latch contention), these queries call a Function FN_NEWBRANCH. The input to this function is Branch Code from child tables and the output is the branch name fetched from S_BRANCH. A Function, and the queries written in the Function, called from the SELECT Statement is executed once for each row fetched by the main body of the query. This means, if the SELECT Query fetches 1000 rows, then the function called in the SELECT Statement, as well as, the queries written in the function will be executed 1000 times. We all know that Latch Contention is a Concurrency Issue and reducing Concurrency by way of Optimization, results in Scalability of the Application. Therefore, my Goal here was to reduce the concurrency on S_BRANCH table and this was done by way of a Simple Change in the query. Since the change was very simple change, it did not require any Application Testing and was therefore immediately Implemented. Since then, it has been almost 20 days, the performance of the production system is stable with No Latch Contention.

OPTIMIZATION

Let us walk through an example that simulates the production concurrency issue. In this test case, I will create two tables EMP and DEPT. DEPT is a Parent table and EMP is a Child Table that references DEPTNO of DEPT. Further, we will create 2 Functions, both doing the same task, to Get the Department Name for a Deptno and these will be called from a SELECT Statement. Since Deptno is a primary key, a query against DEPT to get DNAME will be of 4 Consistent reads. The text of both the Function is same except the Hint in the Queries to easily identify and differentiate from v$sqlarea.

drop table emp;

drop table dept;

exec dbms_random.seed(0);

create table dept as
select 	rownum deptno, dbms_random.string('A',20) dname
from	all_objects
where 	rownum<=100;

alter table dept add constraint pk_dept primary key(deptno);

create table emp as
select	rownum empno, dbms_random.string('A',30) ename,
	round(dbms_random.value(1,100),0) deptno,
	round(dbms_random.value(1000,10000),0) sal
from	all_objects
where 	rownum<=10000;

alter table emp add constraint pk_emp primary key(empno);

alter table emp add constraint deptno_fk foreign key(deptno) references dept;

exec dbms_stats.gather_table_stats(user,'EMP');

exec dbms_stats.gather_table_stats(user,'DEPT');
create or replace function get_dname(i_deptno in number)
return varchar2 as
i_name varchar2(20);
begin
select /*+ ORIGINAL */ dname into i_name from dept where deptno=i_deptno;
return i_name;
end;
/

create or replace function get_dname_o(i_deptno in number)
return varchar2 as
i_name varchar2(20);
begin
select /*+ OPTIMIZED */ dname into i_name from dept where deptno=i_deptno;
return i_name;
end;
/

set autot trace
select get_dname(deptno) deptno,
        ename, sal
from       emp
where deptno in (10,20);

200 rows selected.


Statistics
----------------------------------------------------------
        505  consistent gets <--- I/O's of the Main Body
	...
	...
        200  rows processed <-- Rows Processed 

Optimized Code (calling of Function using Scalar Subquery)

select (select get_dname_o(deptno) from dual) deptno,
	ename, sal
from	emp
where 	deptno in (10,20);

200 rows selected.

Statistics
----------------------------------------------------------
         21  recursive calls
          0  db block gets
        108  consistent gets <-- I/O's of the Main Body
        ...
        ...
        200  rows processed <-- Rows Processed (same as Original)

column sql_text for a50 wrap
select sql_id, sql_text, buffer_gets, executions, version_count
from v$sqlarea where sql_text like 'select get_dname(dept%';

SQL_ID        SQL_TEXT                                           BUFFER_GETS EXECUTIONS VERSION_COUNT
------------- -------------------------------------------------- ----------- ---------- -------------
90wzvddty11u6 select get_dname(deptno) deptno,  ename, sal from          505          1             1
              emp where deptno in (10,20)


select sql_id, sql_text, buffer_gets, executions, version_count
from v$sqlarea where sql_text like 'SELECT /*+ ORIGINAL%';

SQL_ID        SQL_TEXT                                           BUFFER_GETS EXECUTIONS VERSION_COUNT
------------- -------------------------------------------------- ----------- ---------- -------------
dpbdkb6u525g3 SELECT /*+ ORIGINAL */ DNAME FROM DEPT WHERE DEPTN         400        200             1
              O=:B1


select sql_id, sql_text, buffer_gets, executions, version_count
from v$sqlarea where sql_text like 'select (select get_dname%';

SQL_ID        SQL_TEXT                                           BUFFER_GETS EXECUTIONS VERSION_COUNT
------------- -------------------------------------------------- ----------- ---------- -------------
gufauq4hb8tgq select (select get_dname_o(deptno) from dual) dept         108          1             1
              no,         ename, sal from    emp where deptno in
               (10,20)


select sql_id, sql_text, buffer_gets, executions, version_count
from v$sqlarea where sql_text like 'SELECT /*+ OPTIMIZE%';

SQL_ID        SQL_TEXT                                           BUFFER_GETS EXECUTIONS VERSION_COUNT
------------- -------------------------------------------------- ----------- ---------- -------------
14h9s8atq8u26 SELECT /*+ OPTIMIZED */ DNAME FROM DEPT WHERE DEPT           4          2             1
              NO=:B1

The modification in this case was calling a Function using a SCALAR Subquery using Dual. This change brought down the number of executions of the recursive query “SELECT DNAME FROM DEPT WHERE DEPTNO=:B1” from 200 to 2. This is for each deptno. The Query was executed for Deptno in (10,20) and therefore, the function was called only twice and not for each row fetched by the main body of the query. The Original Implementation called the function 200 times as the main body of the query fetched 200 rows. As for the Logical I/O’s, with both the Implementation The I/O for the recursive query on DEPT was 2 per Execution, but the benefits were on Number of Executions with each of these Implementation. The I/O’s of the Main Query on EMP reduced drastically as the number of times a Query on DEPT reduced drastically and this benefit was passed on to the Main Query.

With this Optimization, the benefits observed were :

  1. Reduction in Logical I/O’s for top queries captured above – This means reduction in Latch Gets.
  2. Reduction in Concurrency against S_BRANCH – This means reduction in Latch Gets.
  3. Improved Scalability

Predicting Performance Impact after adding a New Column to an existing Index

This blog featured on my previous blog URL (still unaccessible) and was published on 7th September 2008. Thought of reposting this, as a similar performance issue was recently reported by one of my customer, where a query had to be fixed by way of an Index Hint. This blog would also help you understanding the way optimizer_index_cost_adj is to be calculated for optimizing a query performance. This calculation was requested by one of a regular reader of my blogs.

Modifying an existing index to optimize multiple queries is a common practice, as this eliminates the overheads of maintaning muliple indexes, by way of INSERTS / UPDATES / DELETES. This modification of an existing index includes, re-arranging column ordering, adding a new column etc. This blog focuses on an issue that may trigger and impact the performance of your production system due to addition of a new column in an existing index.

The scenario that I am going to discuss in this blog is, “Assuming one day you are at a customer site investigating a performance issue or doing a proactive health check of a production system. During investigation, you come across two queries that are almost similar and use same Index. The only difference between the two queries is an additional Filter Predicate.” The two queries may look like :

select * from emp where sal=:b2;
select * from emp where sal=:b2 and deptno=:b1;

Both the queries use an Index on SAL column, which is a Single Column Index. We all know that the logical I/O’s of a query can be reduced if a query can make best use of an Index and scans the table, only when required. Which means, a composite index on (SAL, DEPTNO) would be efficient and should reduce the Logical I/O’s for the second query, without impacting the first query. Therefore, instead of creating a new composite index, the suggestion is put forward to modify an existing index on SAL and add DEPTNO as a second column. This will ensure that both the queries use the same index. After the alteration of this Index on production, won’t you be stunned if the customer comes back and says that the performance is still not OK, and infact, is worst than it was a day before ? This is because, while the alteration improved the performance of the second query, it impacted the performance of the first with the change in optimizer plan as it calculates the cost of an Altered Index to be costlier than Full Table Scan. Let us walk through a test case to understand the issue and the rationale behind optimizer estimation.

TEST CASE

drop table vivek_test;

exec dbms_random.seed(0);

create table vivek_test as
with test as
(select * from all_objects where rownum between 1 and 10000)
select	trunc((rownum-1)/1000) object_id,
	round(dbms_random.value(1,100),0) bad_clustered,
	a.object_name,
	a.temporary,
	a.created
from	test a,
	test b
where  rownum between 1 and 100000; 

create index vivek_test_idx on vivek_test(object_id);

exec dbms_stats.gather_table_stats(user,'VIVEK_TEST',cascade=>true);

Below are the statistics for the table and its index (in my test database) :

select owner, table_name, num_rows, blocks from dba_tables where table_name='VIVEK_TEST';

OWNER                          TABLE_NAME                       NUM_ROWS     BLOCKS
------------------------------ ------------------------------ ---------- ----------
VIVEK                          VIVEK_TEST                          99889        420

select index_name, num_rows, blevel, leaf_blocks, distinct_keys, clustering_factor
from	dba_indexes
where	table_name='VIVEK_TEST';

INDEX_NAME                       NUM_ROWS     BLEVEL LEAF_BLOCKS DISTINCT_KEYS CLUSTERING_FACTOR
------------------------------ ---------- ---------- ----------- ------------- -----------------
VIVEK_TEST_IDX                     100000          1         195           100               420

Now, I will run two queries (assume these to be application queries) against the table and both of these queries use the Index created on Object_ID. The queries and their Runtime Execution Plans are pasted below :

variable b1 number;
variable b2 number;
exec :b1:=0;
exec :b2:=57;
select /*+ QUERY1 */ * from vivek_test where object_id=:b1;

SQL_ID  99ss8hxuax3q2, child number 0
-------------------------------------
select /*+ QUERY1 */ * from vivek_test where object_id=:b1

Plan hash value: 3696163677

----------------------------------------------------------------------------------------------
| Id  | Operation                   | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                |       |       |     7 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| VIVEK_TEST     |   981 | 24525 |     7   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | VIVEK_TEST_IDX |   990 |       |     2   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("OBJECT_ID"=:B1)

select /*+ QUERY2 */ * from vivek_test where object_id=:b1 and bad_clustered=:b2;

Plan hash value: 3696163677

----------------------------------------------------------------------------------------------
| Id  | Operation                   | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                |       |       |     7 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID| VIVEK_TEST     |    10 |   250 |     7   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | VIVEK_TEST_IDX |   990 |       |     2   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("BAD_CLUSTERED"=:B2)
   2 - access("OBJECT_ID"=:B1)

Based on the queries executed against this table, it is decided to drop the exisiting index on OBJECT_ID and recreate it on OBJECT_ID, BAD_CLUSTERED. This is to optimize the second query (eliminate unwanted logical I/O’s) and with an assumption that this change will not impact the first query, with QUERY1 hint.

drop index vivek_test_idx;
create index vivek_test_idx on vivek_test(object_id, bad_clustered);
exec dbms_stats.gather_table_stats(user,'VIVEK_TEST',cascade=>true);
SQL> select owner, table_name, num_rows, blocks from dba_tables where table_name='VIVEK_TEST';

OWNER                          TABLE_NAME                       NUM_ROWS     BLOCKS
------------------------------ ------------------------------ ---------- ----------
VIVEK                          VIVEK_TEST                         102477        420

Elapsed: 00:00:00.11
SQL> select index_name, num_rows, blevel, leaf_blocks, distinct_keys, clustering_factor
  2  from dba_indexes 
  3  where table_name='VIVEK_TEST';

INDEX_NAME                       NUM_ROWS     BLEVEL LEAF_BLOCKS DISTINCT_KEYS CLUSTERING_FACTOR
------------------------------ ---------- ---------- ----------- ------------- -----------------
VIVEK_TEST_IDX                     100000          1         237          9998             41509

On a production system, these changes are normally done during the downtime and the system is released for the users. The impact is usually visible when the users start executing these queries concurrently. Let us re-execute the queries with the change in the index implemented. We will execute the second query first (with QUERY2 hint) and then the first query and compare the runtime execution plan.

variable b1 number;
variable b2 number;
exec :b1:=0;
exec :b2:=57;

select /*+ QUERY2 */ * from vivek_test where object_id=:b1 and bad_clustered=:b2;

Plan hash value: 3696163677

----------------------------------------------------------------------------------------------
| Id  | Operation                   | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                |       |       |     6 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| VIVEK_TEST     |    10 |   250 |     6   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | VIVEK_TEST_IDX |    10 |       |     1   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("OBJECT_ID"=:B1 AND "BAD_CLUSTERED"=:B2)

select /*+ QUERY1 */ * from vivek_test where object_id=:b1;

Plan hash value: 3275957777

--------------------------------------------------------------------------------
| Id  | Operation         | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |            |       |       |    97 (100)|          |
|*  1 |  TABLE ACCESS FULL| VIVEK_TEST |  1015 | 25375 |    97   (4)| 00:00:02 |
--------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("OBJECT_ID"=:B1)

While the cost of the second query, and the logical I/O’s as well, has gone down, the change has impacted the first query, that was working absolutely fine before the change. This can lead to a greater impact when these are run concurrently. To check for the impact, I simulated concurrency by way of spawning 20 sessions, each running the impacted query. With these 20 concurrent sessions, my 2 CPU laptop choked up with 100% utilization and 95% waits on CBC Latches. The code to simulate the concurrency is pasted below with an explanation :

  1. Create a Staging table and populate the object id’s in random order to be queried.
  2. The staging table holds 20000 object id’s with 10 parallel streams (PSTREAMS).
  3. The procedure will be scheduled from dbms_job, with pstreams as an Input parameter (10 Streams).
drop table staging;

create table staging as
select object_id, mod(rownum,10) pstreams  
from vivek_test where rownum between 1 and 20000
order by dbms_random.random;

create or replace procedure process_job(ps in number) as
l_cnt	number;
begin
for i in (select object_id from staging where pstreams=ps)
loop
select count(distinct temporary) into l_cnt from vivek_test
where	object_id=i.object_id;
end loop;
end;
/


variable jobno number;
variable hrs number;
variable mns number;
exec :hrs:=14;
exec :mns:=35;

begin
for i in 1..10
loop
BEGIN
     DBMS_JOB.SUBMIT(:jobno,'process_job('||i||');', 
         trunc(sysdate)+:hrs/24+:mns/(24*60));
     COMMIT;
END;
end loop;
end;
/

What could have triggered the change in plan ?

Before getting into the cause of this change, let us execute the query with an Index Hint. This will help us investigate the issue.

select /*+ INDEX(VIVEK_TEST,VIVEK_TEST_IDX) */ * from vivek_test where object_id=:b1;

Plan hash value: 3696163677

----------------------------------------------------------------------------------------------
| Id  | Operation                   | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                |       |       |   420 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| VIVEK_TEST     |  1015 | 25375 |   420   (0)| 00:00:06 |
|*  2 |   INDEX RANGE SCAN          | VIVEK_TEST_IDX |  1015 |       |     4   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("OBJECT_ID"=:B1)

With an Index Hint, the cost of step TABLE ACCESS BY INDEX ROWID step is 420 as against 97 for the unhinted query (TABLE SCAN FULL). Optimizer, while generating an optimal execution plan, compares cost of each available access path and selects the one with least cost. In this case, the cost of a TABLE SCAN FULL was assumed to be cheaper than the cost of an INDEX SCAN. The Index can be considered costlier due to two reasons : by way of Cost and / or, due to huge number of Logical I/O’s. TABLE ACCESS BY INDEX ROWID is always followed by INDEX RANGE SCAN, and as can be seen from the plan, the cost of an INDEX SCAN is mere 4, while the cost of TABLE ACCESS step is 420. While the former is calculated from BLEVEL and LEAF_BLOCKS, the later is calculated based on CLUSTERING_FACTOR (CF).

Compare the CF of the Index, before and after change. Before the change, CF was 420 (near to the num_blocks of the table), after the change it changed drastically to 41509. This was due to the bad clustering of the additional column bad_clustered and this change was enough to blow up the cost. The cost calculation before and after the change is as under :

BEFORE THE CHANGE
Index Cost = BLEVEL + CEIL(LEAF_BLOCKS * SELECTIVITY)
Table Scan = CEIL(CF * SELECTIVITY)
Total Cost of TABLE ACCESS BY INDEX ROWID = Index Cost + Table Scan

While BLEVEL is considered for Index Cost Calculation, optimizer ignores this if the BLEVEL of an Index is 1 and all the columns of an Index are used as an EQUALITY Predicate in the query. Therefore, in our case too, since the columns are used as an Equality predicate and the blevel is 1, this value will be ignored.

SQL> select ceil(195*1/100), ceil(420*1/100) from dual;

CEIL(195*1/100) CEIL(420*1/100)
--------------- ---------------
              2               5

The cost of the first query, before the change is 7. Now, after the change :

SQL> select 1+ceil(237*1/100), ceil(41509*1/100) from dual;

1+CEIL(237*1/100) CEIL(41509*1/100)
----------------- -----------------
                4               416

With Index Hint, the cost is 420 and this is costlier than 97. There are two solutions for this issue. These are :

  1. Chnage the value for OPTIMIZER_INDEX_COST_ADJ (OICA) and set this globally.
  2. Fix the Query with an Index Hint.

The first change (i.e.OICA), would require application testing as setting this globally can impact other queries. The second change was a feasible solution and could be applied without impacting other queries. Let us visit the formula to calculate the value of OICA.

OPTIMIZER_INDEX_COST_ADJ

This is calculated as COST OF A FTS divided by TABLE ACCESS BY INDEX ROWID. In our case, the cost of FTS is 97 and Table Access by Index Rowid is 420. Therefore 97/420*100 is 23.09. This means, if the value of OICA is set to less than 23, the query should use an Index, without modification.

SQL> alter session set optimizer_index_cost_adj=22;

Session altered.
select /*+ OICA_22 */ * from vivek_test where object_id=:b1

Plan hash value: 3696163677

----------------------------------------------------------------------------------------------
| Id  | Operation                   | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                |       |       |    92 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| VIVEK_TEST     |  1015 | 25375 |    92   (0)| 00:00:02 |
|*  2 |   INDEX RANGE SCAN          | VIVEK_TEST_IDX |  1015 |       |     1   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("OBJECT_ID"=:B1)

As mentioned earlier, a better option would be to hint the query. Once the query is modified with an Index Hint, I spawned the Concurrency jobs and could see that gain, with less than 5% waits on CBC latches, as against, more than 95% and 100% CPU Utilization.

How do we predict the impact of this change before implementing it ?

Before making these changes, the impact can be predicated. This prediction should help estimate the cost change, before and after. Following query can be modified and run (for a bigger table, should be run in parallel during less load period). The only change in the query will be the ordering of the columns in an Index. For this, I will recreate the Index on a Single Column and then execute the query to check for the Change in the CF after adding another column.

SQL> drop index vivek_test_idx;

Index dropped.

Elapsed: 00:00:00.07
SQL> create index vivek_test_idx on vivek_test(object_id);

SQL> select  sum(block_change) from (
  2  select  block_fno, object_id, bad_clustered, prev_bfno,        
  3   (case when nvl(prev_bfno,0)!=block_fno then 1 else 0 end) block_change from (
  4  select  block_fno, object_id, bad_clustered, lag(block_fno) over (order by object_id) prev_bfno from (
  5  select    dbms_rowid.rowid_block_number(rowid)||'.'||
  6    dbms_rowid.ROWID_TO_ABSOLUTE_FNO(rowid,'VIVEK','VIVEK_TEST') block_fno, 
  7    object_id, bad_clustered
  8  from  VIVEK_TEST
  9  order by object_id, bad_clustered, block_fno)));

SUM(BLOCK_CHANGE)
-----------------
            41509

The output of this query should approximately match the CF calculated by the Optimizer and should be enough to proactively arrive at the impact due to the change before making the change.

ppi.sql

The Power of System Statistics / CPU Costing

An Example from my Blog on “DBA – Developer Relationship ! A fine example of collaboration”

On 20th April 2009, I wrote a blog on DBA-Developer Relationship, and the collaborative effort to optimize the performance of a Business Critical Batch Process. In the blog, I mentioned about the database version, which was 8.1.7.4. For an “All India Oracle User Group”, I was writing an Interesting article for their AIOUG Journal “Oracle Connect” and thought of sharing this experience to the User Group Forum. The article, labeled as “Efficient Indexing Strategy”, mostly concentrated on the issues due to the Number of rows, fetched by an Index and finally discarded during the Table fetch.

As an example, assuming a simple query on a table EMP and an Index on ENAME (no index on deptno). If I execute a Query to check for ENAME=’VIVEK SHARMA’ in deptno=10, the optimizer might opt for an Index on ENAME. Further assuming, since VIVEK SHARMA is a very common name, the Index Scan fetches around 30 rows, but there is only 1 VIVEK SHARMA in deptno 10. Therefore, when the additional predicate is applied during Table Scan, 29 rows from the Index Fetch will be discarded and these 29 rows are the throw-away rows. Efficient Indexing eliminates these throw aways, as these impact the performance of a Production System.

While writing this Article for AIOUG, I came across an Interesting and Amazing Optimization, which was not actually available in Oracle 8i and 9i (without system statistics). With System Statistics, the way Indexes are scanned, have changed and if you create a test case and run this across each of these versions, including Oracle 10g, you would notice this change.

Again, since my previous blog is inaccessible, let me post the content of that blog here and then we would discuss about the change implemented after introduction of system statistics.

The content of my Blog Posted on 20th April 2009 starts here.

Thomas Kyte wrote a very good paragraph on DBA – Developer Relationship in his book “Expert One-on-One”. He truly says that this relationship should be healthy. During my AIOUG presentation, I had a slide on this topic and I went on explaining about the importance of this relationship. I have come across many performance issues, where, the issues come up because Developers work in isolation, without bothering much about the performance of their application queries and this indirectly means, leaving the job of optimization for the DBA’s. This impacts the scalability of an entire production system. This also means that the application queries are revisited for optimization, based on the recommendations by the DBA’s.

Let me present a real life example, wherein, a discussion with the Developer helped me optimizing performance of a critical process. Recently, I was working on one Severity 1 performance issue. The problem summary is overall slowness at the database level and the main contributor to this performance issue being, Hard Parses and Huge Resource Intensive Queries. Surprisingly, The database version is 8.1.7.4.

While optimizing the performance of a critical process, we came across a top query. The entire process use to take almost 11 hours, wherein, this problematic step takes 8 hours or sometimes fails with ora-1555. Therefore, it was evident that optimizing this step would bring down the completion time of the entire process. This particular step had three different queries and based on the inputs from the developers, and 10046 trace files, the contribution of each of these were 7 hours, 25 minutes and 25 minutes respectively. Therefore, it is clearly the first query that takes significant amount of time.

Query Text

SELECT opnamt_gl, entdate, argdate
FROM ORDER_ALL
WHERE customer_id = :b1
AND ((invtype = 5 AND status IN('IN','CM'))
OR (status IN('FC','CO')))
AND opnamt_gl != 0; ## This last predicate is opnamt_gl not equal to 0;

This query executes in a loop and processes almost 1 Million customers. There is a Composite Index on (customer_id, status, invtype) and this query takes almost 2 seconds to process a customer. Based on this data, the next two queries are executed. The table ORDER_ALL is 16 GB in size. Since the last 2 columns of the Index is used as OR or IN predicate, the index scan is only done based on the customer_id. The Query fetches only 1 row for each customer.

A Casual Discussion that helped Optimizing this code

While we were discussing this with the developer of this process, he mentioned that this query takes 2 seconds, whereas, on another database it takes 31 milliseconds. I casually asked him to select all the columns used in the query, commenting all other columns used in the WHERE clause and execute it on both the databases. The query executed was :

SELECT opnamt_gl, entdate, argdate, invtype, status, opnamt_gl
FROM ORDER_ALL
WHERE customer_id = :b1;

Though, the complete query fetches only 1 row on both the databases, when this modified query was executed on each of these, it revealed that on the problematic database, it is fetching approx 115 rows for each customer against 25 rows on another. It is this difference that is taking resource and the additional time.

This 115 rows fetch was taking 2 Seconds. The issue was 2 seconds for each customer and this was not acceptable. The challenge was to reduce this processing time for each customer. As an optimizing technique, we executed the query, only on an indexed column, i.e.customer_id, in the WHERE clause and we got 115 rows. I concentrated on the values in the other columns of the query that were used in the WHERE clause of the Original Query and was surprised to see that only 2 rows had a non zero opnamt_gl. The original query has a predicate opnamt_gl != 0. When asked, the developer replied that for all the customers, there will be only 1 or 2 rows with non zero value and this input helped me in recommending an interesting optimizing technique.

As mentioned earlier, the query fetches only 1 row, which means, out of the (approx) 115 rows for each customers, 114 rows are discarded. TKPROF also showed this behaviour. Therefore, instead of discarding 114 rows, why not get 2 rows from an index and discard 1 row. By now, the developer understood that we are planning to recommend a new composite index on (customer_id, opnamt_gl) and therefore, before we recommend anything, he himself mentioned that they tried creating this index but the response time did not improve. The reason they did not see any performance gain was the condition opnamt_gl != 0. The recommendation provided here gave a major performance relief. The steps involved for optimizing this piece of the code were :

  1. A Function based Index.
  2. Create a View. This is an additional step since the db version is 8174.
  3. Modify the query so that it queries the view.

We primarily targetted the Conditions

WHERE customer_id = :b1 and   opnamt_gl != 0;

We created a function based Index on (customer_id, case when opnamt_gl=0 then null else ‘Y’ end). Since the db version is 8174, CASE statements cannot be used in a pl/sql block, therefore we created a view as :

create view ORDER_ALL_VW as
SELECT opnamt_gl, entdate, argdate, customer_id
FROM ORDER_ALL
WHERE ((invtype = 5
AND status IN(‘IN’,’CM’))
OR (status IN(‘FC’,’CO’)))
AND (case when opnamt_gl=0 then null else ‘Y’ end) = ‘Y’;

Then the Query was modified as

SELECT opnamt_gl, entdate, argdate FROM ORDER_ALL_VW WHERE customer_id = :b1;

With this optimization, the query response time was 3 msec for a customer and with this the completion time of this query for 1 million customer came down from 7 hours to 7 minutes. This optimization also guaranteed that the process would not fail with ora-1555.

Definetely, a discussion on the optimizing strategy with the developer helped us optimize the performance of a critical query. Developers know their data well, and in my view, this recommendation should have come from the developers. For this, developers needs to be well conversant with database features and explore each of these while writing an application query.

The content of my Blog Posted on 20th April 2009 ends here.

Starting Oracle 9i, with System Statistics Collected and Oracle 10g (CPU Stats are Mandatory), a normal composite Index on customer_id, opnamt_gl helped optimizing the performance of this query. The issue, without system stats is, the optimizer cease to use an Index for any search on NOT EQUAL TO predicate and therefore, in 8174, even after creating a normal index yield no performance benefit.

While writing for AIOUG Journal, I created a test case to check for the performance of this query across each version. In Oracle 8i, the query was doing huge Logical Reads, Oracle 9i (with system stats) and 10g, the I/O’s dropped drastically. In Oracle 9i, without System Statistics, the behaviour was same as Oracle 8i.