few days back i have came across with one of the worst execution plan that i have ever seen in whole life. Query talking 999 Hours – 59 Minutes and 59 Seconds to complete.
Look at this shock below.
1. Elapsed Time to complete PARENT Operation ‘UPDATE’ – 999:59:59
2. With only 167k rows to be processed.
3. Cost is coming huge too – 32G
ORIGINALPLAN:
——————
Plan hash value: 2191276670
--------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------
| 0 | UPDATE STATEMENT | | 167K| 7685K| 32G (1)|999:59:59 |
| 1 | UPDATE | XXXXX | | | | |
| 2 | NESTED LOOPS OUTER | | 167K| 7685K| 16333 (1)| 00:03:49 |
| 3 | TABLE ACCESS FULL | XXXXX | 167K| 5069K| 16317 (1)| 00:03:49 |
|* 4 | INDEX UNIQUE SCAN | IBXXXX | 1 | 16 | 0 (0)| 00:00:01 |
|* 5 | TABLE ACCESS BY INDEX ROWID| TXXXX | 1 | 43 | 194K (1)| 00:45:17 |
|* 6 | INDEX SKIP SCAN | IXXXX_490008000_1 | 191K| | 2261 (1)| 00:00:32 |
--------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
—————————————————
4 – access(“H”.”C1″=”BXXXX”.”C1″(+))
5 – filter(“XXXX01238500″=:B1 AND “XXXX00426800″=’Incident Resolution Time’)
6 – access(“XXXX00365100″=4)
filter(“XXXX00365100″=4)
I tried below mentioned steps to eradicate the problem.
1. Tried to restructure SQL statement but was of no use.
2. Made a composite index on the impacted table XXXXX, But with that i has only reduced to 2 hours and 40 minutes. Although we have considered the execution time but team still want to reduce the CHANGE WINDOW of as low as possible because in total it would take 5 hours 20 minutes during the run of 2 queries.
2. With a thought in our mind and after reading few of the performance documents we tried to apply some fixes in case if we have any bug during the run of queries.
After applying all possible fixes problems endures.
SQL> select optimizer_feature_enable,count(*) from v$system_fix_control group by optimizer_feature_enable order by 1 asc;
OPTIMIZER_FEATURE_ENABLE COUNT(*)
------------------------- ----------
10.1.0 3
10.1.0.3 1
10.1.0.5 2
10.2.0.1 7
10.2.0.2 12
10.2.0.3 11
10.2.0.4 73
10.2.0.5 112
11.1.0.6 40
11.1.0.7 19
11.2.0.1 67
OPTIMIZER_FEATURE_ENABLE COUNT(*)
------------------------- ----------
11.2.0.2 106
11.2.0.3 75
8.0.0 63
8.1.6 1
8.1.7 2
9.2.0 8
9.2.0.8 3
47
19 rows selected.
I tried some blind-applies to get the exact bug and have ended applying few of the bug fixes.
Note: I advocate always execute the same on your test servers first or perform impact analysis before using hidden parameters.
SQL> select * from v$system_fix_control where optimizer_feature_enable=’11.2.0.3′ and description like ‘%skip%’;
BUGNO VALUE SQL_FEATURE DESCRIPTION OPTIMIZER_FEATURE_ENABLE EVENT IS_DEFAULT
---------- ---------- ---------------------------------------- ---------------------------------------------------------------- ------------------------- ---------- ----------
10080014 1 QKSFM_CBO_10080014 allow skip scan costing for PRIOR join in CONNECT BY query 11.2.0.3 0 1
9569678 1 QKSFM_CBO_9569678 skip identity operator when generating NULL IS NOT NULL 11.2.0.3 0 1
11744086 1 QKSFM_PLACE_GROUP_BY_11744086 skip SCG for query block with no aggregating columns 11.2.0.3 0 1
9227576 1 QKSFM_CBO_9227576 allow skip scan costing for semi/anti-join 11.2.0.3 0 1
SQL> alter session set “_fix_control”=’9814067:OFF’;
Session altered.
SQL> alter session set “_fix_control”=’10038373:OFF’;
Session altered.
SQL> alter session set “_fix_control”=’8893626:OFF’;
Session altered.
Ended up with no impact on the queries.
3. Used one SQL HINT — optimizer_features_enable(‘10.1.0’)
Forcing the query optimizer to use compatible old version while creating the plan — version 10.1.0
Look at the plan soon after the change.
-------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 728359962
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | UPDATE STATEMENT | | 167K| 7685K| 16361 (1)| 00:03:50 |
| 1 | UPDATE | XXXXX | | | | |
| 2 | NESTED LOOPS OUTER| | 167K| 7685K| 16361 (1)| 00:03:50 |
| 3 | TABLE ACCESS FULL| XXXXX | 167K| 5069K| 16268 (1)| 00:03:48 |
|* 4 | INDEX UNIQUE SCAN| IBXXXX | 1 | 16 | 0 (0)| 00:00:01 |
|* 5 | TABLE ACCESS FULL | TXXXX | 1 | 43 | 7099 (1)| 00:01:40 |
------------------------------------------------------------------------------
WHOA!!! execution time with some realistic values — and the query got completed in only 3 minutes after using the HINT.
Thanks
Prashant Dixit
Tales From A Lazy Fat DBA 