快速 入门 使用 10046 事件
How to use 10046 event trace quickly?<br>--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:dataOracleSID_HOMEADMINDDUMPdiag
dbmsSIDSID
race
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:dataOraclesid_HOMEADMINDDUMPdiag
dbmssidsid
racesid_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