使用10046追踪执行计划demo
（一）开启10046追踪
SQL> alter session set events '10046 trace name context forever,level 12';
（二）执行sql语句
SELECT J.JOB_ID, J.JOB_TITLE, J.MIN_SALARY, J.MAX_SALARY, E.EMPLOYEE_ID, E.FIRST_NAME || E.LAST_NAME AS NAME, E.EMAIL, E.PHONE_NUMBER FROM JOBS J, EMPLOYEES E WHERE J.JOB_ID = E.JOB_ID;
（三）关闭追踪
SQL> alter session set events '10046 trace name context off';
（四）在查看alert目录里面找到新生成的文件，执行分析
(4.1)找到文件
[oracle@rac1 trace]$ pwd /u01/app/oracle/diag/rdbms/rac/rac1/trace [oracle@rac1 trace]$ ls -lrt ... ... -rw-r----- 1 oracle asmadmin 196 Jan 14 15:41 rac1_ora_27998.trm -rw-r----- 1 oracle asmadmin 9530 Jan 14 15:41 rac1_ora_27998.trc
[oracle@rac1 trace]$ tkprof rac1_ora_27998.trc lijiaman_10046.txt sys=no sort=prsela,exeela,fchela（4.3）查看解析后的文件
[oracle@rac1 trace]$ ls -lrt ... -rw-r----- 1 oracle asmadmin 112680 Jan 14 15:39 rac1_ora_12468.trc -rw-r----- 1 oracle asmadmin 196 Jan 14 15:41 rac1_ora_27998.trm -rw-r----- 1 oracle asmadmin 9530 Jan 14 15:41 rac1_ora_27998.trc -rw-r--r-- 1 oracle oinstall 8587 Jan 14 15:43 lijiaman_10046.txt
附录：解析后文件信息
TKPROF: Release 11.2.0.1.0 - Development on Sun Jan 14 15:43:44 2018
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
Trace file: rac1_ora_27998.trc
Sort options: prsela exeela fchela
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
select j.job_id,
j.job_title,
j.min_salary,
j.max_salary,
e.employee_id,
e.first_name||e.last_name as name,
e.email,
e.phone_number
from jobs j,employees e
where j.job_id = e.job_id
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 11 0 107
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 11 0 107
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 85
Rows Row Source Operation
------- ---------------------------------------------------
107 MERGE JOIN (cr=11 pr=0 pw=0 time=2014 us cost=6 size=8988 card=107)
19 TABLE ACCESS BY INDEX ROWID JOBS (cr=4 pr=0 pw=0 time=90 us cost=2 size=627 card=19)
19 INDEX FULL SCAN JOB_ID_PK (cr=2 pr=0 pw=0 time=18 us cost=1 size=0 card=19)(object id 73932)
107 SORT JOIN (cr=7 pr=0 pw=0 time=78 us cost=4 size=5457 card=107)
107 TABLE ACCESS FULL EMPLOYEES (cr=7 pr=0 pw=0 time=106 us cost=3 size=5457 card=107)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 0.86 0.93
Disk file operations I/O 1 0.00 0.00
********************************************************************************
SQL ID: 9m7787camwh4m
Plan Hash: 0
begin :id := sys.dbms_transaction.local_transaction_id; end;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 4
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 8 0.00 0.00 0 0 0 4
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 85
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 4 0.00 0.00
SQL*Net message from client 4 60.12 72.13
********************************************************************************
SQL ID: 5x323vaz5nuu4
Plan Hash: 0
alter session set events '10046 trace name context off'
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Parsing user id: 85
********************************************************************************
SQL ID: cf06fwacdmgfk
Plan Hash: 1388734953
select 'x'
from
dual
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 0 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 0 0 2
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 85
Rows Row Source Operation
------- ---------------------------------------------------
1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 5 0.00 0.00
SQL*Net message from client 5 0.01 0.02
rdbms ipc reply 3 0.00 0.00
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 8 0.00 0.00 0 0 0 0
Execute 8 0.00 0.00 0 0 0 4
Fetch 4 0.00 0.00 0 11 0 109
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 20 0.00 0.00 0 11 0 113
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 12 0.00 0.00
SQL*Net message from client 12 60.12 73.09
rdbms ipc reply 3 0.00 0.00
Disk file operations I/O 1 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
8 user SQL statements in session.
0 internal SQL statements in session.
8 SQL statements in session.
********************************************************************************
Trace file: rac1_ora_27998.trc
Trace file compatibility: 11.1.0.7
Sort options: prsela exeela fchela
1 session in tracefile.
8 user SQL statements in trace file.
0 internal SQL statements in trace file.
8 SQL statements in trace file.
4 unique SQL statements in trace file.
152 lines in trace file.
73 elapsed seconds in trace file.
【完】
