How to use 10046 event trace quickly?

快速 入门 使用 10046  事件
How to use 10046 event trace quickly?
--author Eureka at 2013.06.06

第一步 使用sqlplus 连接Oracle服务器
1 Use tool Sqlplus connect to  Oracle server.
Such as
Sqlplus  username/password@db

第二步， 设置trace log 的表示符，为了更好的找到这个文件
2 Set  tracefile_identifier for session
Such as
alter session set  tracefile_identifier = '10046trace';

第三步，设置10046事件
3 Set  10046 event trace
Such as
alter session set events '10046 trace name context forever, level 12';

第四步，执行要分析的SQL语句
4 Execute the SQL
Such as:
Select count(1) from dba_objects;

第五步，关闭10046 事件，得到跟踪日志
5 Close  10046 event trace, generate 10046 trace log.
alter session set events '10046 trace name context off';

(Note: you can also exit the connection, close the session get the 10046 trace log)

第六步，在产生跟踪日志的文件夹中找到我们这次产生的日志
7. Use tracefile_identifier Find the trace log in the trace log folder.
Such as :
Folder is :  D:\data\Oracle\SID_HOME\ADMIN\DDUMP\diag\rdbms\SID\SID
\trace\
You can sort the files by generate time, then  use tracefile_identifier.
Here we get  file “SID_ora_9112_10046trace.trc ”.

第七步，使用工具tkprof 整理原始的日志，得到清晰的执行计划
8 use  tool tkprof get explain 
Such as 
C:\>tkprof D:\data\Oracle\sid_HOME\ADMIN\DDUMP\diag\rdbms\sid\sid
\trace\sid_ora_9112_10046trace.trc  c:\9112.txt sys=no
TKPROF: Release 11.2.0.2.0 - Development on Thu Jun 6 01:12:57 2013
Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

Check the file 9112.txt, The detail explain  as follow

************************************************************************

SQL ID: 9a8v45jk7xhvx Plan Hash: 1524891911

select count(1) 
from
 dba_objects


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.03       0.03          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.17       0.28         11       2698          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.20       0.31         11       2698          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 37  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=2698 pr=11 pw=0 time=284342 us)
     27050      27050      27050   VIEW  DBA_OBJECTS (cr=2698 pr=11 pw=0 time=363169 us cost=112 size=0 card=21349)
     27050      27050      27050    UNION-ALL  (cr=2698 pr=11 pw=0 time=309706 us)
     27034      27034      27034     FILTER  (cr=2696 pr=11 pw=0 time=206225 us)
     28107      28107      28107      HASH JOIN  (cr=473 pr=0 pw=0 time=302292 us cost=109 size=1794455 card=27607)
        71         71         71       INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=94 us cost=1 size=276 card=69)(object id 47)
     28107      28107      28107       HASH JOIN  (cr=472 pr=0 pw=0 time=180862 us cost=108 size=1683966 card=27606)
        71         71         71        INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=155 us cost=1 size=1518 card=69)(object id 47)
     28107      28107      28107        TABLE ACCESS FULL OBJ$ (cr=471 pr=0 pw=0 time=48629 us cost=106 size=1076595 card=27605)
      5419       5419       5419      TABLE ACCESS BY INDEX ROWID IND$ (cr=2223 pr=11 pw=0 time=188651 us cost=2 size=8 card=1)
      6492       6492       6492       INDEX UNIQUE SCAN I_IND1 (cr=978 pr=11 pw=0 time=138106 us cost=1 size=0 card=1)(object id 41)
         0          0          0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=2 size=30 card=1)
         0          0          0       INDEX SKIP SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)
         0          0          0       INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=10 card=1)(object id 39)
        16         16         16     HASH JOIN  (cr=2 pr=0 pw=0 time=356 us cost=3 size=112 card=16)
        16         16         16      INDEX FULL SCAN I_LINK1 (cr=1 pr=0 pw=0 time=61 us cost=1 size=45 card=15)(object id 138)
        71         71         71      INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=83 us cost=1 size=276 card=69)(object id 47)


Elapsed times include waiting on following events:
  Event waited on                           Times    Max. Wait   Total Waited
  --------------------------------------   Waited  ------------  ---------------
  SQL*Net message to client                  2        0.00          0.00
  Disk file operations I/O                        1        0.05          0.05
  db file sequential read                        11        0.01          0.05
  SQL*Net message from client             2        8.21          8.21