11gR1 数据字典的 latch: cache buffers chains问题-优快云博客

SQL> select * from v$version;

BANNER
-------------------------------------------------------------------------------

Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
PL/SQL Release 11.1.0.7.0 - Production
CORE 11.1.0.7.0 Production
TNS for HPUX: Version 11.1.0.7.0 - Production
NLSRTL Version 11.1.0.7.0 - Production

4节点 RAC 环境

今天别的项目的ETL 开发人员反映，ETL 的 JOB 跑得很慢，oh，不对，应该是相当慢。

他们也知道去检查等待事件，该等待事件是 latch: cache buffers chains，然后请求我协助处理。

接到该请求之后，我立马登陆数据库，发现确实在等待 latch: cache buffers chains

latch: cache buffers chains 这个等待事件，大家通常理解为遭遇了热点块，或者是 hash bucket 不足。

其实要解决这个问题，很简单，只要你懂得了 buffer cache 原理，那么这个问题就迎刃而解了。但是又有多少人真正懂得 buffer cache原理呢....

latch: cache buffers chains 这个等待事件其实还有另外一个重要的原因，那么就是逻辑读太高，SQL执行计划走错了导致的。

因为逻辑读高了之后，就要去判断大量的block 是否存在于buffer cache中，而判断block是否存在于数据库中就要获得 latch: cache buffers chains .

继续我们的案例：

我利用下面这个SQL查询到底是哪个SQL导致latch: cache buffers chains等待事件的

Select * from table(dbms_xplan.display_cursor('sql_id',sql_child_number,'ALL'));

SQL 和执行计划如下：

SQL> Select * from table(dbms_xplan.display_cursor('fq6j4fh8tfu0x',6));

PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------------------------

SQL_ID fq6j4fh8tfu0x, child number 6
-------------------------------------
SELECT DISTINCT IP.PARTITION_NAME FROM USER_IND_PARTITIONS IP,
USER_INDEXES I, USER_TAB_PARTITIONS P WHERE (IP.STATUS = 'UNUSABLE' OR
:B3 = 1) AND (I.INDEX_TYPE <> 'BITMAP' OR :B2 = 0) AND IP.INDEX_NAME =
I.INDEX_NAME AND I.TABLE_NAME = P.TABLE_NAME AND P.TABLE_NAME =
UPPER(:B1 )

Plan hash value: 1812419801

--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 1188K(100)| |
| 1 | HASH UNIQUE | | 1 | 216 | 1188K (5)| 03:18:04 |
| 2 | NESTED LOOPS OUTER | | 1 | 216 | 1188K (5)| 03:18:04 |
| 3 | NESTED LOOPS OUTER | | 1 | 212 | 1188K (5)| 03:18:04 |
| 4 | NESTED LOOPS OUTER | | 1 | 202 | 1188K (5)| 03:18:04 |
| 5 | NESTED LOOPS | | 1 | 188 | 1188K (5)| 03:18:04 |
| 6 | NESTED LOOPS | | 1 | 184 | 1188K (5)| 03:18:04 |
| 7 | NESTED LOOPS | | 1 | 151 | 55327 (15)| 00:09:14 |
| 8 | NESTED LOOPS OUTER | | 1 | 92 | 55324 (15)| 00:09:14 |
| 9 | NESTED LOOPS | | 1 | 88 | 55323 (15)| 00:09:14 |
|* 10 | HASH JOIN | | 26 | 1300 | 55295 (15)| 00:09:13 |
| 11 | VIEW | USER_TAB_PARTITIONS | 3 | 51 | 49690 (14)| 00:08:17 |
| 12 | UNION-ALL | | | | | |
| 13 | NESTED LOOPS | | 1 | 129 | 16214 (14)| 00:02:43 |
| 14 | NESTED LOOPS | | 1 | 115 | 16212 (14)| 00:02:43 |
| 15 | NESTED LOOPS | | 1 | 111 | 16210 (14)| 00:02:43 |
| 16 | MERGE JOIN CARTESIAN | | 509 | 27995 | 14092 (16)| 00:02:21 |
|* 17 | INDEX RANGE SCAN | I_OBJ2 | 1 | 40 | 3 (0)| 00:00:01 |
| 18 | BUFFER SORT | | 207K| 3043K| 14089 (16)| 00:02:21 |
|* 19 | TABLE ACCESS FULL | TAB$ | 207K| 3043K| 14089 (16)| 00:02:21 |
|* 20 | VIEW PUSHED PREDICATE | TABPARTV$ | 1 | 56 | 4 (0)| 00:00:01 |
| 21 | TABLE ACCESS BY INDEX ROWID| TABPART$ | 14 | 364 | 4 (0)| 00:00:01 |
|* 22 | INDEX RANGE SCAN | I_TABPART_BOPART$ | 14 | | 2 (0)| 00:00:01 |
| 23 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 24 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| |
| 25 | TABLE ACCESS CLUSTER | SEG$ | 1 | 14 | 2 (0)| 00:00:01 |
|* 26 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 1 (0)| 00:00:01 |
| 27 | NESTED LOOPS | | 1 | 98 | 16212 (14)| 00:02:43 |
| 28 | MERGE JOIN CARTESIAN | | 509 | 27995 | 14092 (16)| 00:02:21 |
|* 29 | INDEX RANGE SCAN | I_OBJ2 | 1 | 40 | 3 (0)| 00:00:01 |
| 30 | BUFFER SORT | | 207K| 3043K| 14089 (16)| 00:02:21 |
|* 31 | TABLE ACCESS FULL | TAB$ | 207K| 3043K| 14089 (16)| 00:02:21 |
|* 32 | VIEW PUSHED PREDICATE | TABPARTV$ | 1 | 43 | 4 (0)| 00:00:01 |
|* 33 | TABLE ACCESS BY INDEX ROWID | TABPART$ | 1 | 22 | 4 (0)| 00:00:01 |
|* 34 | INDEX RANGE SCAN | I_TABPART_BOPART$ | 14 | | 2 (0)| 00:00:01 |
| 35 | NESTED LOOPS | | 1 | 89 | 17265 (14)| 00:02:53 |
| 36 | NESTED LOOPS | | 1 | 85 | 17264 (14)| 00:02:53 |
| 37 | MERGE JOIN CARTESIAN | | 509 | 27995 | 14092 (16)| 00:02:21 |
|* 38 | INDEX RANGE SCAN | I_OBJ2 | 1 | 40 | 3 (0)| 00:00:01 |
| 39 | BUFFER SORT | | 207K| 3043K| 14089 (16)| 00:02:21 |
|* 40 | TABLE ACCESS FULL | TAB$ | 207K| 3043K| 14089 (16)| 00:02:21 |
|* 41 | VIEW PUSHED PREDICATE | TABCOMPARTV$ | 1 | 30 | 6 (0)| 00:00:01 |
| 42 | TABLE ACCESS BY INDEX ROWID | TABCOMPART$ | 14 | 224 | 6 (0)| 00:00:01 |
|* 43 | INDEX RANGE SCAN | I_TABCOMPART_BOPART$ | 14 | | 2 (0)| 00:00:01 |
| 44 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 45 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| |
| 46 | INDEX FAST FULL SCAN | I_OBJ2 | 2700K| 84M| 4761 (11)| 00:00:48 |
|* 47 | TABLE ACCESS CLUSTER | IND$ | 1 | 38 | 2 (0)| 00:00:01 |
|* 48 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | 1 (0)| 00:00:01 |
| 49 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 50 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| |
|* 51 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 59 | 3 (0)| 00:00:01 |
|* 52 | INDEX RANGE SCAN | I_OBJ1 | 1 | | 2 (0)| 00:00:01 |
|* 53 | VIEW | USER_IND_PARTITIONS | 1 | 33 | 1133K (4)| 03:08:51 |
| 54 | UNION ALL PUSHED PREDICATE | | | | | |
| 55 | NESTED LOOPS | | 1 | 163 | 1096K (4)| 03:02:50 |
| 56 | NESTED LOOPS | | 1 | 149 | 1096K (4)| 03:02:50 |
| 57 | NESTED LOOPS | | 183K| 13M| 146K (5)| 00:24:27 |
| 58 | MERGE JOIN CARTESIAN | | 128K| 7787K| 14131 (16)| 00:02:22 |
| 59 | MERGE JOIN CARTESIAN | | 1 | 53 | 42 (10)| 00:00:01 |
|* 60 | INDEX RANGE SCAN | I_OBJ2 | 1 | 49 | 3 (0)| 00:00:01 |
| 61 | BUFFER SORT | | 130 | 520 | 39 (11)| 00:00:01 |
| 62 | TABLE ACCESS FULL | TS$ | 130 | 520 | 39 (11)| 00:00:01 |
| 63 | BUFFER SORT | | 207K| 1825K| 14092 (16)| 00:02:21 |
|* 64 | TABLE ACCESS FULL | TAB$ | 207K| 1825K| 14089 (16)| 00:02:21 |
|* 65 | TABLE ACCESS CLUSTER | IND$ | 1 | 18 | 1 (0)| 00:00:01 |
|* 66 | VIEW PUSHED PREDICATE | INDPARTV$ | 1 | 69 | 5 (0)| 00:00:01 |
| 67 | TABLE ACCESS BY INDEX ROWID | INDPART$ | 11 | 330 | 5 (0)| 00:00:01 |
|* 68 | INDEX RANGE SCAN | I_INDPART_BOPART$ | 11 | | 3 (0)| 00:00:01 |
| 69 | TABLE ACCESS CLUSTER | SEG$ | 1 | 14 | 2 (0)| 00:00:01 |
|* 70 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 1 (0)| 00:00:01 |
| 71 | NESTED LOOPS OUTER | | 1 | 110 | 22315 (9)| 00:03:44 |
| 72 | NESTED LOOPS | | 1 | 106 | 22314 (9)| 00:03:44 |
| 73 | NESTED LOOPS | | 1 | 97 | 22313 (9)| 00:03:44 |
| 74 | MERGE JOIN CARTESIAN | | 1400 | 93800 | 13567 (12)| 00:02:16 |
|* 75 | INDEX RANGE SCAN | I_OBJ2 | 1 | 49 | 3 (0)| 00:00:01 |
| 76 | BUFFER SORT | | 293K| 5166K| 13564 (12)| 00:02:16 |
| 77 | TABLE ACCESS FULL | IND$ | 293K| 5166K| 13564 (12)| 00:02:16 |
|* 78 | VIEW PUSHED PREDICATE | INDCOMPARTV$ | 1 | 30 | 6 (0)| 00:00:01 |
| 79 | TABLE ACCESS BY INDEX ROWID | INDCOMPART$ | 19 | 285 | 6 (0)| 00:00:01 |
|* 80 | INDEX RANGE SCAN | I_INDCOMPART_BOPART$ | 19 | | 2 (0)| 00:00:01 |
|* 81 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 1 (0)| 00:00:01 |
| 82 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 83 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| |
| 84 | NESTED LOOPS | | 1 | 119 | 13774 (14)| 00:02:18 |
| 85 | MERGE JOIN CARTESIAN | | 1 | 89 | 13769 (14)| 00:02:18 |
| 86 | NESTED LOOPS | | 1 | 40 | 13767 (14)| 00:02:18 |
| 87 | MERGE JOIN CARTESIAN | | 1 | 31 | 13766 (14)| 00:02:18 |
| 88 | INDEX FULL SCAN | I_INDPART_PARAM | 1 | 13 | 0 (0)| |
| 89 | BUFFER SORT | | 293K| 5166K| 13766 (14)| 00:02:18 |
| 90 | TABLE ACCESS FULL | IND$ | 293K| 5166K| 13766 (14)| 00:02:18 |
|* 91 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 1 (0)| 00:00:01 |
| 92 | BUFFER SORT | | 1 | 49 | 13768 (14)| 00:02:18 |
|* 93 | INDEX RANGE SCAN | I_OBJ2 | 1 | 49 | 2 (0)| 00:00:01 |
|* 94 | VIEW PUSHED PREDICATE | INDPARTV$ | 1 | 30 | 5 (0)| 00:00:01 |
| 95 | TABLE ACCESS BY INDEX ROWID | INDPART$ | 11 | 176 | 5 (0)| 00:00:01 |
|* 96 | INDEX RANGE SCAN | I_INDPART_BOPART$ | 11 | | 3 (0)| 00:00:01 |
|* 97 | INDEX RANGE SCAN | I_USER2 | 1 | 4 | 1 (0)| 00:00:01 |
| 98 | TABLE ACCESS CLUSTER | SEG$ | 1 | 14 | 2 (0)| 00:00:01 |
|* 99 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 1 (0)| 00:00:01 |
|*100 | INDEX RANGE SCAN | I_OBJ1 | 1 | 10 | 2 (0)| 00:00:01 |
|*101 | INDEX RANGE SCAN | I_USER2 | 1 | 4 | 1 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------------------

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

10 - access("IO"."NAME"="P"."TABLE_NAME")
17 - access("O"."OWNER#"=USERENV('SCHEMAID') AND "O"."NAME"=UPPER(:B1) AND "O"."NAMESPACE"=1 AND
"O"."REMOTEOWNER" IS NULL AND "O"."LINKNAME" IS NULL)
filter(("O"."REMOTEOWNER" IS NULL AND "O"."LINKNAME" IS NULL))
19 - filter(BITAND("T"."TRIGFLAG",1073741824)<>1073741824)
20 - filter("O"."OBJ#"="TP"."OBJ#")
22 - access("BO#"="T"."OBJ#")
24 - access("TS"."TS#"="TP"."TS#")
26 - access("TP"."TS#"="S"."TS#" AND "TP"."FILE#"="S"."FILE#" AND "TP"."BLOCK#"="S"."BLOCK#")
29 - access("O"."OWNER#"=USERENV('SCHEMAID') AND "O"."NAME"=UPPER(:B1) AND "O"."NAMESPACE"=1 AND
"O"."REMOTEOWNER" IS NULL AND "O"."LINKNAME" IS NULL)
filter(("O"."REMOTEOWNER" IS NULL AND "O"."LINKNAME" IS NULL))
31 - filter(BITAND("T"."TRIGFLAG",1073741824)<>1073741824)
32 - filter("O"."OBJ#"="TP"."OBJ#")
33 - filter(("BLOCK#"=0 AND "FILE#"=0))
34 - access("BO#"="T"."OBJ#")
38 - access("O"."OWNER#"=USERENV('SCHEMAID') AND "O"."NAME"=UPPER(:B1) AND "O"."NAMESPACE"=1 AND
"O"."REMOTEOWNER" IS NULL AND "O"."LINKNAME" IS NULL)
filter(("O"."REMOTEOWNER" IS NULL AND "O"."LINKNAME" IS NULL))
40 - filter(BITAND("T"."TRIGFLAG",1073741824)<>1073741824)
41 - filter("O"."OBJ#"="TCP"."OBJ#")
43 - access("BO#"="T"."OBJ#")
45 - access("TCP"."DEFTS#"="TS"."TS#")
47 - filter(((:B2=0 OR DECODE(BITAND("I"."PROPERTY",16),0,'','FUNCTION-BASED
')||DECODE("I"."TYPE#",1,'NORMAL'||DECODE(BITAND("I"."PROPERTY",4),0,'',4,'/REV'),2,'BITMAP',3,'CLUSTER',4,'
IOT - TOP',5,'IOT - NESTED',6,'SECONDARY',7,'ANSI',8,'LOB',9,'DOMAIN')<>'BITMAP') AND
BITAND("I"."FLAGS",4096)=0 AND INTERNAL_FUNCTION("I"."TYPE#")))
48 - access("I"."BO#"="IO"."OBJ#")
50 - access("I"."TS#"="TS"."TS#")
51 - filter(BITAND("O"."FLAGS",128)=0)
52 - access("O"."OBJ#"="I"."OBJ#" AND "O"."OWNER#"=USERENV('SCHEMAID'))
53 - filter(("IP"."STATUS"='UNUSABLE' OR :B3=1))
60 - access("IO"."OWNER#"=USERENV('SCHEMAID') AND "IO"."NAME"="O"."NAME" AND "IO"."NAMESPACE"=4 AND
"IO"."REMOTEOWNER" IS NULL AND "IO"."LINKNAME" IS NULL)
filter(("IO"."REMOTEOWNER" IS NULL AND "IO"."LINKNAME" IS NULL))
64 - filter(BITAND("T"."TRIGFLAG",1073741824)<>1073741824)
65 - filter("I"."BO#"="T"."OBJ#")
66 - filter(("IO"."OBJ#"="IP"."OBJ#" AND "TS"."TS#"="IP"."TS#"))
68 - access("BO#"="I"."OBJ#")
70 - access("IP"."TS#"="S"."TS#" AND "IP"."FILE#"="S"."FILE#" AND "IP"."BLOCK#"="S"."BLOCK#")
75 - access("IO"."OWNER#"=USERENV('SCHEMAID') AND "IO"."NAME"="O"."NAME" AND "IO"."NAMESPACE"=4 AND
"IO"."REMOTEOWNER" IS NULL AND "IO"."LINKNAME" IS NULL)
filter(("IO"."REMOTEOWNER" IS NULL AND "IO"."LINKNAME" IS NULL))
78 - filter("IO"."OBJ#"="ICP"."OBJ#")
80 - access("BO#"="I"."OBJ#")
81 - filter((BITAND("T"."TRIGFLAG",1073741824)<>1073741824 AND "I"."BO#"="T"."OBJ#"))
83 - access("ICP"."DEFTS#"="TS"."TS#")
91 - filter((BITAND("T"."TRIGFLAG",1073741824)<>1073741824 AND "I"."BO#"="T"."OBJ#"))
93 - access("IO"."OWNER#"=USERENV('SCHEMAID') AND "IO"."NAME"="O"."NAME" AND "IO"."NAMESPACE"=4 AND
"IO"."REMOTEOWNER" IS NULL AND "IO"."LINKNAME" IS NULL)
filter(("IO"."REMOTEOWNER" IS NULL AND "IO"."LINKNAME" IS NULL))
94 - filter(("IO"."OBJ#"="IP"."OBJ#" AND "IP"."OBJ#"="IPP"."OBJ#"))
96 - access("BO#"="I"."OBJ#")
97 - access("IO"."OWNER#"="IU"."USER#")
99 - access("I"."TS#"="S"."TS#" AND "I"."FILE#"="S"."FILE#" AND "I"."BLOCK#"="S"."BLOCK#")
100 - access("I"."INDMETHOD#"="ITO"."OBJ#")
101 - access("ITO"."OWNER#"="ITU"."USER#")

178 rows selected.

请注意观察这个SQL:

SELECT DISTINCT IP.PARTITION_NAME FROM USER_IND_PARTITIONS IP,
USER_INDEXES I, USER_TAB_PARTITIONS P WHERE (IP.STATUS = 'UNUSABLE' OR
:B3 = 1) AND (I.INDEX_TYPE <> 'BITMAP' OR :B2 = 0) AND IP.INDEX_NAME =
I.INDEX_NAME AND I.TABLE_NAME = P.TABLE_NAME AND P.TABLE_NAME =
UPPER(:B1 )

它是一个非常简单的SQL,查询数据字典，那么对于这样的SQL,我们想要从代码上面去优化，是不可能的。

那么大家也请注意观察执行计划，是不是发现这个执行计划有问题啊,查询数据字典居然这么高的cost，而且nested loops的步骤也出问题了。因此怀疑11gR1的CBO出问题了，或者是数据字典统计信息不对，不过可惜的是我没有权限收集数据字典统计信息.

好的，那么我在10g上面看看该SQL的执行计划

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - 64bi
PL/SQL Release 10.2.0.3.0 - Production
CORE 10.2.0.3.0 Production
TNS for HPUX: Version 10.2.0.3.0 - Production
NLSRTL Version 10.2.0.3.0 - Production

执行计划如下：

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------------------------------------------------------

Plan hash value: 3570566607

---------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
---------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 2726 | 511K| | 24244 (4)| 00:03:32 |
| 1 | SORT UNIQUE | | 2726 | 511K| | 24244 (4)| 00:03:32 |
|* 2 | HASH JOIN | | 2726 | 511K| | 24243 (4)| 00:03:32 |
| 3 | NESTED LOOPS OUTER | | 144 | 22752 | | 3120 (4)| 00:00:28 |
|* 4 | HASH JOIN OUTER | | 93 | 13392 | | 2978 (4)| 00:00:26 |
| 5 | NESTED LOOPS OUTER | | 93 | 13020 | | 2971 (4)| 00:00:26 |
|* 6 | HASH JOIN | | 93 | 12090 | | 2785 (4)| 00:00:25 |
|* 7 | HASH JOIN OUTER | | 93 | 11718 | | 2777 (4)| 00:00:25 |
| 8 | NESTED LOOPS | | 93 | 11346 | | 2767 (4)| 00:00:25 |
| 9 | NESTED LOOPS | | 166 | 14442 | | 2435 (5)| 00:00:22 |
|* 10 | HASH JOIN | | 17054 | 816K| | 1903 (6)| 00:00:17 |
| 11 | VIEW | USER_TAB_PARTITIONS | 9 | 153 | | 34 (0)| 00:00:01 |
| 12 | UNION-ALL | | | | | | |
| 13 | NESTED LOOPS | | 5 | 460 | | 17 (0)| 00:00:01 |
| 14 | NESTED LOOPS | | 3 | 234 | | 11 (0)| 00:00:01 |
| 15 | NESTED LOOPS | | 3 | 207 | | 8 (0)| 00:00:01 |
| 16 | NESTED LOOPS | | 3 | 195 | | 5 (0)| 00:00:01 |
| 17 | TABLE ACCESS BY INDEX ROWID| OBJ$ | 3 | 117 | | 4 (0)| 00:00:01 |
|* 18 | INDEX RANGE SCAN | I_OBJ2 | 3 | | | 3 (0)| 00:00:01 |
| 19 | TABLE ACCESS BY INDEX ROWID| TABPART$ | 1 | 26 | | 1 (0)| 00:00:01 |
|* 20 | INDEX UNIQUE SCAN | I_TABPART_OBJ$ | 1 | | | 0 (0)| 00:00:01 |
| 21 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | | 1 (0)| 00:00:01 |
|* 22 | INDEX UNIQUE SCAN | I_TS# | 1 | | | 0 (0)| 00:00:01 |
|* 23 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | | 1 (0)| 00:00:01 |
|* 24 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | | 0 (0)| 00:00:01 |
| 25 | TABLE ACCESS CLUSTER | SEG$ | 2 | 28 | | 2 (0)| 00:00:01 |
|* 26 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | | 1 (0)| 00:00:01 |
| 27 | NESTED LOOPS | | 1 | 70 | | 6 (0)| 00:00:01 |
| 28 | NESTED LOOPS | | 1 | 61 | | 5 (0)| 00:00:01 |
| 29 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 3 | 117 | | 4 (0)| 00:00:01 |
|* 30 | INDEX RANGE SCAN | I_OBJ2 | 3 | | | 3 (0)| 00:00:01 |
|* 31 | TABLE ACCESS BY INDEX ROWID | TABPART$ | 1 | 22 | | 1 (0)| 00:00:01 |
|* 32 | INDEX UNIQUE SCAN | I_TABPART_OBJ$ | 1 | | | 0 (0)| 00:00:01 |
|* 33 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | | 1 (0)| 00:00:01 |
|* 34 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | | 0 (0)| 00:00:01 |
| 35 | NESTED LOOPS | | 3 | 201 | | 11 (0)| 00:00:01 |
| 36 | NESTED LOOPS | | 3 | 174 | | 8 (0)| 00:00:01 |
| 37 | NESTED LOOPS | | 3 | 162 | | 5 (0)| 00:00:01 |
| 38 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 3 | 117 | | 4 (0)| 00:00:01 |
|* 39 | INDEX RANGE SCAN | I_OBJ2 | 3 | | | 3 (0)| 00:00:01 |
| 40 | TABLE ACCESS BY INDEX ROWID | TABCOMPART$ | 1 | 15 | | 1 (0)| 00:00:01 |
|* 41 | INDEX UNIQUE SCAN | I_TABCOMPART$ | 1 | | | 0 (0)| 00:00:01 |
| 42 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | | 1 (0)| 00:00:01 |
|* 43 | INDEX UNIQUE SCAN | I_TS# | 1 | | | 0 (0)| 00:00:01 |
|* 44 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | | 1 (0)| 00:00:01 |
|* 45 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | | 0 (0)| 00:00:01 |
| 46 | TABLE ACCESS FULL | OBJ$ | 2906K| 88M| | 1844 (4)| 00:00:17 |
|* 47 | TABLE ACCESS CLUSTER | IND$ | 1 | 38 | | 1 (0)| 00:00:01 |
|* 48 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | | 0 (0)| 00:00:01 |
|* 49 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 35 | | 2 (0)| 00:00:01 |
|* 50 | INDEX UNIQUE SCAN | I_OBJ1 | 1 | | | 1 (0)| 00:00:01 |
| 51 | TABLE ACCESS FULL | TS$ | 110 | 440 | | 9 (0)| 00:00:01 |
| 52 | TABLE ACCESS FULL | USER$ | 3354 | 13416 | | 7 (0)| 00:00:01 |
| 53 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 10 | | 2 (0)| 00:00:01 |
|* 54 | INDEX UNIQUE SCAN | I_OBJ1 | 1 | | | 1 (0)| 00:00:01 |
| 55 | TABLE ACCESS FULL | USER$ | 3354 | 13416 | | 7 (0)| 00:00:01 |
| 56 | TABLE ACCESS CLUSTER | SEG$ | 2 | 28 | | 2 (0)| 00:00:01 |
|* 57 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | | 1 (0)| 00:00:01 |
| 58 | VIEW | USER_IND_PARTITIONS | 28992 | 962K| | 21122 (4)| 00:03:04 |
| 59 | UNION-ALL | | | | | | |
|* 60 | HASH JOIN | | 17170 | 1961K| | 11898 (5)| 00:01:44 |
|* 61 | HASH JOIN | | 11043 | 1110K| | 9388 (4)| 00:01:22 |
| 62 | TABLE ACCESS FULL | TS$ | 110 | 440 | | 9 (0)| 00:00:01 |
|* 63 | HASH JOIN | | 11043 | 1067K| | 9379 (4)| 00:01:22 |
|* 64 | HASH JOIN | | 11044 | 539K| | 7427 (3)| 00:01:05 |
|* 65 | TABLE ACCESS FULL | INDPART$ | 10777 | 305K| | 561 (9)| 00:00:05 |
|* 66 | HASH JOIN | | 476K| 9762K| 3376K| 6862 (2)| 00:01:00 |
|* 67 | TABLE ACCESS FULL | TAB$ | 164K| 1445K| | 3323 (2)| 00:00:29 |
| 68 | TABLE ACCESS FULL | IND$ | 476K| 5578K| | 3316 (2)| 00:00:29 |
|* 69 | TABLE ACCESS FULL | OBJ$ | 11259 | 538K| | 1951 (10)| 00:00:17 |
| 70 | TABLE ACCESS FULL | SEG$ | 2490K| 33M| | 2489 (5)| 00:00:22 |
|* 71 | FILTER | | | | | | |
|* 72 | HASH JOIN RIGHT OUTER | | 11821 | 1027K| | 9218 (4)| 00:01:21 |
| 73 | TABLE ACCESS FULL | TS$ | 110 | 440 | | 9 (0)| 00:00:01 |
|* 74 | HASH JOIN | | 11821 | 981K| | 9208 (4)| 00:01:21 |
|* 75 | TABLE ACCESS FULL | OBJ$ | 11259 | 538K| | 1951 (10)| 00:00:17 |
|* 76 | HASH JOIN | | 154K| 5434K| 3984K| 7255 (2)| 00:01:04 |
| 77 | TABLE ACCESS FULL | INDCOMPART$ | 150K| 2209K| | 101 (11)| 00:00:01 |
|* 78 | HASH JOIN | | 476K| 9762K| 3376K| 6862 (2)| 00:01:00 |
|* 79 | TABLE ACCESS FULL | TAB$ | 164K| 1445K| | 3323 (2)| 00:00:29 |
| 80 | TABLE ACCESS FULL | IND$ | 476K| 5578K| | 3316 (2)| 00:00:29 |
| 81 | NESTED LOOPS | | 1 | 98 | | 6 (0)| 00:00:01 |
| 82 | NESTED LOOPS | | 1 | 49 | | 4 (0)| 00:00:01 |
| 83 | NESTED LOOPS | | 1 | 40 | | 3 (0)| 00:00:01 |
| 84 | NESTED LOOPS | | 1 | 28 | | 1 (0)| 00:00:01 |
| 85 | INDEX FULL SCAN | I_INDPART_PARAM | 1 | 13 | | 0 (0)| 00:00:01 |
|* 86 | TABLE ACCESS BY INDEX ROWID | INDPART$ | 1 | 15 | | 1 (0)| 00:00:01 |
|* 87 | INDEX UNIQUE SCAN | I_INDPART_OBJ$ | 1 | | | 1 (0)| 00:00:01 |
| 88 | TABLE ACCESS BY INDEX ROWID | IND$ | 1 | 12 | | 2 (0)| 00:00:01 |
|* 89 | INDEX UNIQUE SCAN | I_IND1 | 1 | | | 1 (0)| 00:00:01 |
|* 90 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | | 1 (0)| 00:00:01 |
|* 91 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 49 | | 2 (0)| 00:00:01 |
|* 92 | INDEX UNIQUE SCAN | I_OBJ1 | 1 | | | 1 (0)| 00:00:01 |
---------------------------------------------------------------------------------------------------------------------------

。。。省略。。。。

从此次可以看出，cost大大减小，那么初步判断11g CBO出现bug了，那么我在11g上面做如下设置：

SQL> alter session set OPTIMIZER_FEATURES_ENABLE='10.2.0.3';

Session altered.

执行计划如下：

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------------------------------------------

Plan hash value: 1883090593

-------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 48 | 9312 | 50778 (10)| 00:08:28 |
| 1 | HASH UNIQUE | | 48 | 9312 | 50778 (10)| 00:08:28 |
|* 2 | HASH JOIN | | 48 | 9312 | 50777 (10)| 00:08:28 |
| 3 | NESTED LOOPS OUTER | | 11 | 1760 | 9978 (16)| 00:01:40 |
|* 4 | HASH JOIN OUTER | | 10 | 1460 | 9957 (16)| 00:01:40 |
| 5 | NESTED LOOPS OUTER | | 10 | 1420 | 9951 (16)| 00:01:40 |
|* 6 | HASH JOIN | | 10 | 1320 | 9931 (16)| 00:01:40 |
| 7 | NESTED LOOPS OUTER | | 10 | 1280 | 9925 (16)| 00:01:40 |
| 8 | NESTED LOOPS | | 10 | 1240 | 9914 (16)| 00:01:40 |
| 9 | NESTED LOOPS | | 26 | 2288 | 9834 (16)| 00:01:39 |
|* 10 | HASH JOIN | | 3896 | 190K| 5628 (25)| 00:00:57 |
| 11 | VIEW | USER_TAB_PARTITIONS | 3 | 51 | 23 (5)| 00:00:01 |
| 12 | UNION-ALL | | | | | |
| 13 | NESTED LOOPS | | 1 | 93 | 9 (0)| 00:00:01 |
| 14 | NESTED LOOPS | | 1 | 84 | 7 (0)| 00:00:01 |
| 15 | NESTED LOOPS | | 1 | 70 | 5 (0)| 00:00:01 |
| 16 | NESTED LOOPS | | 1 | 66 | 4 (0)| 00:00:01 |
|* 17 | INDEX RANGE SCAN | I_OBJ2 | 1 | 40 | 3 (0)| 00:00:01 |
| 18 | TABLE ACCESS BY INDEX ROWID| TABPART$ | 1 | 26 | 1 (0)| 00:00:01 |
|* 19 | INDEX UNIQUE SCAN | I_TABPART_OBJ$ | 1 | | 0 (0)| 00:00:01 |
| 20 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 21 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| 00:00:01 |
| 22 | TABLE ACCESS CLUSTER | SEG$ | 1 | 14 | 2 (0)| 00:00:01 |
|* 23 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 1 (0)| 00:00:01 |
|* 24 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 2 (0)| 00:00:01 |
|* 25 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | 1 (0)| 00:00:01 |
| 26 | NESTED LOOPS | | 1 | 71 | 6 (0)| 00:00:01 |
| 27 | NESTED LOOPS | | 1 | 62 | 4 (0)| 00:00:01 |
|* 28 | INDEX RANGE SCAN | I_OBJ2 | 1 | 40 | 3 (0)| 00:00:01 |
|* 29 | TABLE ACCESS BY INDEX ROWID | TABPART$ | 1 | 22 | 1 (0)| 00:00:01 |
|* 30 | INDEX UNIQUE SCAN | I_TABPART_OBJ$ | 1 | | 0 (0)| 00:00:01 |
|* 31 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 2 (0)| 00:00:01 |
|* 32 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | 1 (0)| 00:00:01 |
| 33 | NESTED LOOPS | | 1 | 69 | 7 (0)| 00:00:01 |
| 34 | NESTED LOOPS | | 1 | 60 | 5 (0)| 00:00:01 |
| 35 | NESTED LOOPS | | 1 | 56 | 4 (0)| 00:00:01 |
|* 36 | INDEX RANGE SCAN | I_OBJ2 | 1 | 40 | 3 (0)| 00:00:01 |
| 37 | TABLE ACCESS BY INDEX ROWID | TABCOMPART$ | 1 | 16 | 1 (0)| 00:00:01 |
|* 38 | INDEX UNIQUE SCAN | I_TABCOMPART$ | 1 | | 0 (0)| 00:00:01 |
| 39 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 40 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| 00:00:01 |
|* 41 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 2 (0)| 00:00:01 |
|* 42 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | 1 (0)| 00:00:01 |
| 43 | INDEX FAST FULL SCAN | I_OBJ2 | 2700K| 84M| 4761 (11)| 00:00:48 |
|* 44 | TABLE ACCESS CLUSTER | IND$ | 1 | 38 | 2 (0)| 00:00:01 |
|* 45 | INDEX UNIQUE SCAN | I_OBJ# | 1 | | 1 (0)| 00:00:01 |
|* 46 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 36 | 3 (0)| 00:00:01 |
|* 47 | INDEX RANGE SCAN | I_OBJ1 | 1 | | 2 (0)| 00:00:01 |
| 48 | TABLE ACCESS CLUSTER | TS$ | 1 | 4 | 1 (0)| 00:00:01 |
|* 49 | INDEX UNIQUE SCAN | I_TS# | 1 | | 0 (0)| 00:00:01 |
| 50 | INDEX FAST FULL SCAN | I_USER2 | 3087 | 12348 | 4 (25)| 00:00:01 |
|* 51 | INDEX RANGE SCAN | I_OBJ1 | 1 | 10 | 2 (0)| 00:00:01 |
| 52 | INDEX FAST FULL SCAN | I_USER2 | 3087 | 12348 | 4 (25)| 00:00:01 |
| 53 | TABLE ACCESS CLUSTER | SEG$ | 1 | 14 | 2 (0)| 00:00:01 |
|* 54 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 1 (0)| 00:00:01 |
| 55 | VIEW | USER_IND_PARTITIONS | 9177 | 304K| 40796 (9)| 00:06:48 |
| 56 | UNION-ALL | | | | | |
| 57 | NESTED LOOPS | | 4752 | 547K| 26895 (11)| 00:04:29 |
| 58 | NESTED LOOPS | | 4424 | 449K| 17744 (15)| 00:02:58 |
| 59 | NESTED LOOPS | | 4393 | 407K| 13218 (20)| 00:02:13 |
|* 60 | HASH JOIN | | 4393 | 356K| 4136 (54)| 00:00:42 |
| 61 | TABLE ACCESS FULL | TS$ | 130 | 520 | 39 (11)| 00:00:01 |
|* 62 | HASH JOIN | | 4393 | 338K| 4095 (55)| 00:00:41 |
|* 63 | INDEX RANGE SCAN | I_OBJ2 | 4393 | 210K| 48 (7)| 00:00:01 |
|* 64 | TABLE ACCESS FULL | INDPART$ | 12994 | 380K| 4040 (55)| 00:00:41 |
| 65 | TABLE ACCESS BY INDEX ROWID | IND$ | 1 | 12 | 2 (0)| 00:00:01 |
|* 66 | INDEX UNIQUE SCAN | I_IND1 | 1 | | 1 (0)| 00:00:01 |
|* 67 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 1 (0)| 00:00:01 |
| 68 | TABLE ACCESS CLUSTER | SEG$ | 1 | 14 | 2 (0)| 00:00:01 |
|* 69 | INDEX UNIQUE SCAN | I_FILE#_BLOCK# | 1 | | 1 (0)| 00:00:01 |
|* 70 | FILTER | | | | | |
| 71 | NESTED LOOPS | | 4424 | 384K| 13894 (4)| 00:02:19 |
| 72 | NESTED LOOPS | | 4393 | 343K| 9367 (4)| 00:01:34 |
|* 73 | HASH JOIN RIGHT OUTER | | 4393 | 291K| 285 (15)| 00:00:03 |
| 74 | TABLE ACCESS FULL | TS$ | 130 | 520 | 39 (11)| 00:00:01 |
| 75 | NESTED LOOPS | | 4393 | 274K| 244 (14)| 00:00:03 |
|* 76 | INDEX RANGE SCAN | I_OBJ2 | 4393 | 210K| 48 (7)| 00:00:01 |
| 77 | TABLE ACCESS BY INDEX ROWID | INDCOMPART$ | 1 | 15 | 1 (0)| 00:00:01 |
|* 78 | INDEX UNIQUE SCAN | I_INDCOMPART$ | 1 | | 0 (0)| 00:00:01 |
| 79 | TABLE ACCESS BY INDEX ROWID | IND$ | 1 | 12 | 2 (0)| 00:00:01 |
|* 80 | INDEX UNIQUE SCAN | I_IND1 | 1 | | 1 (0)| 00:00:01 |
|* 81 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 1 (0)| 00:00:01 |
|* 82 | TABLE ACCESS BY INDEX ROWID | OBJ$ | 1 | 49 | 3 (0)| 00:00:01 |
| 83 | NESTED LOOPS | | 1 | 99 | 7 (0)| 00:00:01 |
| 84 | NESTED LOOPS | | 1 | 50 | 4 (0)| 00:00:01 |
| 85 | NESTED LOOPS | | 1 | 41 | 3 (0)| 00:00:01 |
| 86 | NESTED LOOPS | | 1 | 29 | 1 (0)| 00:00:01 |
| 87 | INDEX FULL SCAN | I_INDPART_PARAM | 1 | 13 | 0 (0)| 00:00:01 |
|* 88 | TABLE ACCESS BY INDEX ROWID | INDPART$ | 1 | 16 | 1 (0)| 00:00:01 |
|* 89 | INDEX UNIQUE SCAN | I_INDPART_OBJ$ | 1 | | 1 (0)| 00:00:01 |
| 90 | TABLE ACCESS BY INDEX ROWID | IND$ | 1 | 12 | 2 (0)| 00:00:01 |
|* 91 | INDEX UNIQUE SCAN | I_IND1 | 1 | | 1 (0)| 00:00:01 |
|* 92 | TABLE ACCESS CLUSTER | TAB$ | 1 | 9 | 1 (0)| 00:00:01 |
|* 93 | INDEX RANGE SCAN | I_OBJ1 | 1 | | 2 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------------------

让开发人员再次运行job,这次没有 latch: cache buffers chains 这个等待事件出现

create or replace trigger disable_parallel after logon on database
begin
if USER = 'ADWGQ_OPTIMA_AP11' OR USER = 'ADWGQ_OPTIMA_AP11_ETL' then
EXECUTE IMMEDIATE 'alter session set OPTIMIZER_FEATURES_ENABLE=''10.2.0.3''';
end if;
end disable_parallel;
/

在这个问题没有被fix之前，我会创建上面的触发器，临时解决该问题。希望system dba升级到11gR2能解决该问题。

总结：我们对于各种等待事件一定要有深入的认识，如果你对这里我遇到的等待事件理解不深，那么你很可能就去查热点块去了，甚至跑去查看hash bucket，更改隐含参数等等。我们不仅仅要熟悉数据库的体系结构，还要深入研究ORACLE的内部机制，那么处理这个case的时候，我们就要深入了解buffer cache 原理。这样我们处理问题就会的心应手。