SQL run time changed after DB upgrade but execution plan did not change

From: Hameed, Amir <Amir.Hameed_at_xerox.com>
Date: Fri, 26 Apr 2013 20:24:53 +0000
Message-ID: <AF02C941134B1A4AB5F61A726D08DCED0AF6592B_at_USA7109MB012.na.xerox.net>

We recently upgraded one of our ERP databases from 11.1.0.7 to 11.2.0.3 on Solaris 10. The following SQL statement, which used to run in a few minutes, is now taking forever to run and is not even finishing (I have fudged the table names and data values for privacy reasons): DECLARE
CURSOR s_cur IS
SELECT * FROM T1 ; TYPE fetch_array IS TABLE OF s_cur%ROWTYPE; s_array fetch_array;
BEGIN   OPEN s_cur;
  LOOP
    FETCH s_cur BULK COLLECT INTO s_array ; --LIMIT 100

    FORALL I IN 1..S_ARRAY.COUNT
   INSERT

        INTO T2
      SELECT 999,
             S_ARRAY(I).SUBINVENTORY_CODE,
             s_array(I).INVENTORY_ITEM_ID,
             (select max(TRANSACTION_DATE)
                from MTL_MATERIAL_TRANSACTIONS MMT
               WHERE MMT.TRANSACTION_TYPE_ID IN (11, 22, 33, 44, 55)
                 AND ORGANIZATION_ID    = 123
                 AND INVENTORY_ITEM_ID  = S_ARRAY(I).INVENTORY_ITEM_ID
                 and SUBINVENTORY_CODE  = s_array(I).SUBINVENTORY_CODE)
        FROM DUAL;

    COMMIT;
    EXIT WHEN s_cur%NOTFOUND;
  END LOOP;
  CLOSE s_cur;
  COMMIT;
END;
/

I have verified that the explain plan of the SELECT statement has NOT changed after the upgrade and is shown below:

---

| Id  | Operation                    | Name                         | Rows  | Bytes | Cost (%CPU)| Time     |


-------------------------------------------------------------------------------------------------------------

|   0 | SELECT STATEMENT             |                              |     1 |    29 |    12   (0)| 00:00:01 |
|   1 |  SORT AGGREGATE              |                              |     1 |    29 |            |          |
|*  2 |   TABLE ACCESS BY INDEX ROWID| MTL_MATERIAL_TRANSACTIONS    |     1 |    29 |    12   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | MTL_MATERIAL_TRANSACTIONS_N1 |    12 |       |     4   (0)| 00:00:01 |


-------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):

---

   2 - filter("SUBINVENTORY_CODE"=:B1 AND ("MMT"."TRANSACTION_TYPE_ID" OR

              "MMT"."TRANSACTION_TYPE_ID"" OR "MMT"."TRANSACTION_TYPE_ID"3 OR "MMT"."TRANSACTION_TYPE_ID"D
              OR "MMT"."TRANSACTION_TYPE_ID"U))

   3 - access("INVENTORY_ITEM_ID"=:B2 AND "ORGANIZATION_ID"3)

However, in 11.1.0.7, it was doing much less IOs than in 11.2.0.3. Below are statistics from 11.1.0.7 when all 1.5 million rows from "T1" table were processed: call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse        1      0.00       0.00          0          0          0           0
Execute      1     67.22      67.20       1280      42104    6500059     1588081
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     67.22      67.20       1280      42104    6500059     1588081


In 11.2.0.3, the statistics look below when processing 100 rows from "T1":
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     89.16     106.70    1417957    1634828        311         100
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     89.16     106.70    1417957    1634828        311         100

I am not sure if this is due to a bug or something else is causing this much IOs.

Thanks,
Amir

--
http://www.freelists.org/webpage/oracle-l

Received on Fri Apr 26 2013 - 22:24:53 CEST