10046事件使用

对数据库进行性能诊断可以使用SQL跟踪的方法，把信息dump记录到trace 文件，再用tkprof 格式化显示输出分析sql的性能问题

设置不同的跟踪级别，得到不同的信息
Level 0 停用SQL跟踪，相当于SQL_TRACE=FALSE
Level 1 标准SQL跟踪，相当于SQL_TRACE=TRUE
Level 4 在level 1的基础上增加绑定变量的信息
Level 8 在level 1的基础上增加等待事件的信息
Level 12 在level 1的基础上增加绑定变量和等待事件的信息

下面记录对session级单个sql的跟踪

开始因权限问题，往往真正的应用用户可能没有event的权限，在dba设置跟踪，应用程序用户执行sql

app session:

select * from v$mystat where rownum=1;
查出当前sid;

开个dba session:
SQL> select sid,serial#,paddr,USERNAME,MACHINE from v$session WHERE SID=1705;

SID SERIAL# PADDR USERNAME MACHINE
---------- ---------- ---------------- ------------------------------ ----------------------------------------------------------------
1705 7648 000000025E7A5768 ICME WORKGROUP\CHINA-AE1142D00

SQL> select spid from v$process where addr='000000025E7A5768';

SPID
------------
27065


SQL> oradebug setospid 27065
Oracle pid: 400, Unix process pid: 27065, image: oracle@icme-db
SQL> oradebug unlimit;
Statement processed.
SQL> oradebug event 10046 trace name context forever, level 8;
Statement processed.

app session:
执行要跟踪的sql

回到dba session:
SQL> oradebug event 10046 trace name context off; -- 关闭跟踪
Statement processed.
SQL> oradebug tracefile_name
/oracle/admin/icme/udump/icme_ora_27065.trc
SQL> exit

格式化显示
$>tkprof /oracle/admin/icme/udump/icme_ora_27065.trc xxx.out

vi xxx.out

贴一段信息
sql省略

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.10 0 0 1 0
Execute 1 0.56 0.76 35 11465 7 0
Fetch 4 0.40 0.87 708 36735 1 36
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 1.00 1.74 743 48200 9 36

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 57

Rows Row Source Operation
------- ---------------------------------------------------
36 TEMP TABLE TRANSFORMATION (cr=48200 pr=743 pw=1 time=1637744 us)
1 LOAD AS SELECT (cr=11465 pr=35 pw=1 time=759963 us)
11 VIEW (cr=11465 pr=35 pw=0 time=158968 us)
112 COUNT (cr=11094 pr=35 pw=0 time=162965 us)
112 VIEW (cr=11094 pr=35 pw=0 time=162740 us)
112 NESTED LOOPS OUTER (cr=11094 pr=35 pw=0 time=162738 us)
112 VIEW (cr=10739 pr=0 pw=0 time=136397 us)
112 NESTED LOOPS (cr=10739 pr=0 pw=0 time=136173 us)
1 TABLE ACCESS BY INDEX ROWID ICME_ORG (cr=3 pr=0 pw=0 time=59 us)
1 INDEX UNIQUE SCAN PK_ICME_ORG (cr=2 pr=0 pw=0 time=37 us)(object id 51402)
112 VIEW (cr=10736 pr=0 pw=0 time=135984 us)
171999 HASH JOIN (cr=10736 pr=0 pw=0 time=610466 us)
147813 TABLE ACCESS FULL ICME_ORG (cr=1761 pr=0 pw=0 time=85 us)
171999 TABLE ACCESS BY INDEX ROWID ICME_STUDENT_RANK_TRAN_LOG (cr=8975 pr=0 pw=0 time=172091 us)
219758 INDEX RANGE SCAN IDX_STU_RANK_TRAN_LOG_YEARID (cr=567 pr=0 pw=0 time=822 us)(object id 68986)
112 TABLE ACCESS BY INDEX ROWID ICME_SIMULATE_QA_STATUS (cr=355 pr=35 pw=0 time=213733 us)
112 INDEX UNIQUE SCAN UK_SIMULATE_QA_STATUS (cr=226 pr=35 pw=0 time=212869 us)(object id 60888)
36 HASH JOIN (cr=36735 pr=708 pw=0 time=877507 us)
524 TABLE ACCESS BY INDEX ROWID ICME_SCORE_TYPE (cr=16 pr=1 pw=0 time=5949 us)
524 INDEX FULL SCAN IDX_SCORE_TYPE_PROJTYPE (cr=1 pr=1 pw=0 time=4884 us)(object id 59479)
36 HASH JOIN (cr=36719 pr=707 pw=0 time=871551 us)
524 TABLE ACCESS BY INDEX ROWID ICME_SCORE_TYPE (cr=16 pr=0 pw=0 time=1062 us)
524 INDEX FULL SCAN IDX_SCORE_TYPE_PROJTYPE (cr=1 pr=0 pw=0 time=10 us)(object id 59479)
36 HASH JOIN (cr=36703 pr=707 pw=0 time=870360 us)
11 VIEW (cr=5 pr=1 pw=0 time=128 us)
11 TABLE ACCESS FULL SYS_TEMP_0FD9D665D_9C4F24A6 (cr=5 pr=1 pw=0 time=117 us)
36 VIEW (cr=36698 pr=706 pw=0 time=869768 us)
36 HASH GROUP BY (cr=36698 pr=706 pw=0 time=869766 us)
287 VIEW (cr=36698 pr=706 pw=0 time=655485 us)
287 UNION-ALL (cr=36698 pr=706 pw=0 time=655483 us)
282 FILTER (cr=36654 pr=702 pw=0 time=652996 us)
282 HASH JOIN (cr=36654 pr=702 pw=0 time=652707 us)
282 NESTED LOOPS (cr=846 pr=6 pw=0 time=14581 us)
282 NESTED LOOPS (cr=280 pr=6 pw=0 time=11169 us)
11 VIEW (cr=3 pr=0 pw=0 time=43 us)
11 TABLE ACCESS FULL SYS_TEMP_0FD9D665D_9C4F24A6 (cr=3 pr=0 pw=0 time=41 us)
282 TABLE ACCESS BY INDEX ROWID ICME_PROJECT_SCORE (cr=277 pr=6 pw=0 time=25721 us)
283 INDEX RANGE SCAN UK_PROJECT_SCORE (cr=35 pr=6 pw=0 time=24523 us)(object id 51421)
282 TABLE ACCESS BY INDEX ROWID ICME_SUBJECT (cr=566 pr=0 pw=0 time=3194 us)
282 INDEX UNIQUE SCAN PK_ICME_SUBJECT (cr=284 pr=0 pw=0 time=1488 us)(object id 51469)
244495 TABLE ACCESS BY INDEX ROWID ICME_PROJECT (cr=35808 pr=696 pw=0 time=742090 us)
244495 INDEX FULL SCAN IDX_PROJECT_CHECKID (cr=698 pr=696 pw=0 time=253955 us)(object id 68995)
5 FILTER (cr=44 pr=4 pw=0 time=9661 us)
5 TABLE ACCESS BY INDEX ROWID ICME_NOPROJECT_SCORE (cr=44 pr=4 pw=0 time=9647 us)
17 NESTED LOOPS (cr=39 pr=2 pw=0 time=80506 us)
11 VIEW (cr=3 pr=0 pw=0 time=117 us)
11 TABLE ACCESS FULL SYS_TEMP_0FD9D665D_9C4F24A6 (cr=3 pr=0 pw=0 time=106 us)
5 INDEX RANGE SCAN UK_NOPROJECT_SCORE (cr=36 pr=2 pw=0 time=10843 us)(object id 106044)

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
36 HASH JOIN (cr=36719 pr=707 pw=0 time=871551 us)
524 TABLE ACCESS BY INDEX ROWID ICME_SCORE_TYPE (cr=16 pr=0 pw=0 time=1062 us)
524 INDEX FULL SCAN IDX_SCORE_TYPE_PROJTYPE (cr=1 pr=0 pw=0 time=10 us)(object id 59479)
36 HASH JOIN (cr=36703 pr=707 pw=0 time=870360 us)
11 VIEW (cr=5 pr=1 pw=0 time=128 us)
11 TABLE ACCESS FULL SYS_TEMP_0FD9D665D_9C4F24A6 (cr=5 pr=1 pw=0 time=117 us)
36 VIEW (cr=36698 pr=706 pw=0 time=869768 us)
36 HASH GROUP BY (cr=36698 pr=706 pw=0 time=869766 us)
287 VIEW (cr=36698 pr=706 pw=0 time=655485 us)
287 UNION-ALL (cr=36698 pr=706 pw=0 time=655483 us)
282 FILTER (cr=36654 pr=702 pw=0 time=652996 us)
282 HASH JOIN (cr=36654 pr=702 pw=0 time=652707 us)
282 NESTED LOOPS (cr=846 pr=6 pw=0 time=14581 us)
282 NESTED LOOPS (cr=280 pr=6 pw=0 time=11169 us)
11 VIEW (cr=3 pr=0 pw=0 time=43 us)
11 TABLE ACCESS FULL SYS_TEMP_0FD9D665D_9C4F24A6 (cr=3 pr=0 pw=0 time=41 us)
282 TABLE ACCESS BY INDEX ROWID ICME_PROJECT_SCORE (cr=277 pr=6 pw=0 time=25721 us)
283 INDEX RANGE SCAN UK_PROJECT_SCORE (cr=35 pr=6 pw=0 time=24523 us)(object id 51421)
282 TABLE ACCESS BY INDEX ROWID ICME_SUBJECT (cr=566 pr=0 pw=0 time=3194 us)
282 INDEX UNIQUE SCAN PK_ICME_SUBJECT (cr=284 pr=0 pw=0 time=1488 us)(object id 51469)
244495 TABLE ACCESS BY INDEX ROWID ICME_PROJECT (cr=35808 pr=696 pw=0 time=742090 us)
244495 INDEX FULL SCAN IDX_PROJECT_CHECKID (cr=698 pr=696 pw=0 time=253955 us)(object id 68995)
5 FILTER (cr=44 pr=4 pw=0 time=9661 us)
5 TABLE ACCESS BY INDEX ROWID ICME_NOPROJECT_SCORE (cr=44 pr=4 pw=0 time=9647 us)
17 NESTED LOOPS (cr=39 pr=2 pw=0 time=80506 us)
11 VIEW (cr=3 pr=0 pw=0 time=117 us)
11 TABLE ACCESS FULL SYS_TEMP_0FD9D665D_9C4F24A6 (cr=3 pr=0 pw=0 time=106 us)
5 INDEX RANGE SCAN UK_NOPROJECT_SCORE (cr=36 pr=2 pw=0 time=10843 us)(object id 106044)

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
control file sequential read 5 0.00 0.00
db file sequential read 743 0.01 0.68
direct path write temp 1 0.00 0.00
SQL*Net message to client 4 0.00 0.00
SQL*Net message from client 4 2.15 5.05