DBA手记:DBA诊断利器 - Event 10046和10053

一次某优化工具厂商的朋友，发来一个案例请求协助诊断，朋友的优化工具在客户的环境中执行某个SQL查询时，需要10分钟时间才能出结果，这是无法接受的，而同样的查询在其他环境上都可以快速的获得输出结果， 数据库环境是9.2.0.8。

首先我获得了一个10046跟踪文件，通过tkprof格式化之后，这个SQL的输出结果展现出来。

首先该SQL代码如下：

该段SQL的Elapsed时间超过了600秒，Query模式逻辑读也非常高，对于一个优化工具来说显然是不可接受的。

接下来的跟踪文件中显示了SQL的执行计划：

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  NESTED LOOPS OUTER
      0   NESTED LOOPS OUTER
      0    NESTED LOOPS OUTER
      0     NESTED LOOPS OUTER
      0      NESTED LOOPS OUTER
      0       NESTED LOOPS 
      0        NESTED LOOPS OUTER
      0         NESTED LOOPS 
      0          NESTED LOOPS OUTER
      0           NESTED LOOPS OUTER
      0            NESTED LOOPS 
      0             NESTED LOOPS 
      0              NESTED LOOPS 
1935557               NESTED LOOPS 
   2863                NESTED LOOPS 
   2863                 NESTED LOOPS 
   2863                  NESTED LOOPS 
      1                   NESTED LOOPS 
      1                    TABLE ACCESS BY INDEX ROWID USER$
      1                     INDEX UNIQUE SCAN I_USER1 (object id 44)
      1                    TABLE ACCESS BY INDEX ROWID USER$
      1                     INDEX UNIQUE SCAN I_USER1 (object id 44)
   2863                   TABLE ACCESS FULL CDEF$
   2863                  TABLE ACCESS BY INDEX ROWID CON$
   2863                   INDEX UNIQUE SCAN I_CON2 (object id 49)
   2863                 TABLE ACCESS CLUSTER USER$
   2863                  INDEX UNIQUE SCAN I_USER# (object id 11)
1935557                VIEW 
1935557                 UNION-ALL PARTITION
1935557                  FILTER 
1935557                   NESTED LOOPS 
   2863                    TABLE ACCESS BY INDEX ROWID USER$
   2863                     INDEX UNIQUE SCAN I_USER1 (object id 44)
1935557                    TABLE ACCESS FULL OBJ$
      0                   TABLE ACCESS BY INDEX ROWID IND$
      0                    INDEX UNIQUE SCAN I_IND1 (object id 39)
      0                  FILTER 
      0                   NESTED LOOPS 
      0                    TABLE ACCESS BY INDEX ROWID USER$
      0                     INDEX UNIQUE SCAN I_USER1 (object id 44)
      0                    INDEX RANGE SCAN I_LINK1 (object id 113)
      0               TABLE ACCESS BY INDEX ROWID CON$
1935557                INDEX UNIQUE SCAN I_CON2 (object id 49)
      0              TABLE ACCESS BY INDEX ROWID CON$
      0               INDEX UNIQUE SCAN I_CON1 (object id 48)
      0             TABLE ACCESS BY INDEX ROWID CDEF$
      0              INDEX UNIQUE SCAN I_CDEF1 (object id 50)
      0            TABLE ACCESS BY INDEX ROWID CON$
      0             INDEX UNIQUE SCAN I_CON2 (object id 49)
      0           TABLE ACCESS CLUSTER USER$
      0            INDEX UNIQUE SCAN I_USER# (object id 11)
      0          TABLE ACCESS BY INDEX ROWID OBJ$
      0           INDEX UNIQUE SCAN I_OBJ1 (object id 36)
      0         INDEX UNIQUE SCAN I_OBJ1 (object id 36)
      0        TABLE ACCESS BY INDEX ROWID OBJ$
      0         INDEX UNIQUE SCAN I_OBJ1 (object id 36)
      0       TABLE ACCESS BY INDEX ROWID OBJ$
      0        INDEX UNIQUE SCAN I_OBJ1 (object id 36)
      0      TABLE ACCESS CLUSTER USER$
      0       INDEX UNIQUE SCAN I_USER# (object id 11)
      0     INDEX UNIQUE SCAN I_OBJ1 (object id 36)
      0    TABLE ACCESS BY INDEX ROWID OBJ$
      0     INDEX UNIQUE SCAN I_OBJ1 (object id 36)
      0   TABLE ACCESS CLUSTER USER$
      0    INDEX UNIQUE SCAN I_USER# (object id 11)

以上执行计划中，最可疑的部分是对于OBJ$的全表扫描，这个环节的行数返回有1，935，557行，这个量级一直向上传递，所以我们首先怀疑这里的执行计划选择错误，如果选择索引，执行性能肯定会有极大的不同。

可是10046的跟踪事件显示的信息比较有限不能够准确定位错误的原因，我请朋友通过10053事件来生成一个执行计划的跟踪，10053使用极为简便，通过如下方式就可以捕获SQL的解析过程：

alter session set events '10053 trace name context forever,level 1';
explain plan for you_select_query;
例如：
SQL> alter session set events '10053 trace name context forever,level 1';
Session altered.

SQL> explain plan for select count(*) from obj$;
Explained.

然后在udump目录下就可以找到10053生成的跟踪文件，在该文件中，找到了查询相关表的统计信息，其中OBJ$的信息如下所示，其中CDN（CarDiNality）指表中包含的记录数量，此处显示OBJ$表中有24万左右的记录，使用了2941个数据块：