浅谈Oracle SQL trace-ylw6006
$ cat /home/oracle/trace02.log （tkprof处理后将看不到绑定变量信息）TKPROF:> Copyright (c) 1982, 2005, Oracle.All rights reserved.
Trace file: dg53_ora_18857_hr_trace02.trc
Sort options: default
********************************************************************************
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
********************************************************************************
alter session set events '10046 trace name context forever,level 12'
call count cpu elapsed disk query current rows
------- -------------- ---------- ---------- ---------- --------------------
Parse 0 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 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user> Elapsed times include waiting on following events:
Event waited on Times Max. WaitTotal Waited
---------------------------------------- Waited----------------------
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************
select salary
from
employees where employee_id=: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.01 1 2 0 1
------- -------------- ---------- ---------- ---------- --------------------
total 4 0.00 0.01 1 2 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user> Rows Row Source Operation
----------------------------------------------------------
1TABLE ACCESS BY INDEX ROWID EMPLOYEES (cr=2 pr=1 pw=0 time=16216 us)
1 INDEX UNIQUE SCAN EMP_EMP_ID_PK (cr=1 pr=0 pw=0 time=128 us)(object> Rows Execution Plan
----------------------------------------------------------
0SELECT STATEMENT MODE: ALL_ROWS
1 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF 'EMPLOYEES'
(TABLE)
1 INDEX MODE: ANALYZED (UNIQUE SCAN) OF 'EMP_EMP_ID_PK' (INDEX
(UNIQUE))
Elapsed times include waiting on following events:
Event waited on Times Max. WaitTotal Waited
---------------------------------------- Waited----------------------
SQL*Net message to client 2 0.00 0.00
db file sequential read 1 0.01 0.01
SQL*Net message from client 2 0.00 0.00
********************************************************************************
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
Optimizer mode: ALL_ROWS
Parsing user> ********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- -------------- ---------- ---------- ---------- --------------------
Parse 2 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.01 1 2 0 1
------- -------------- ---------- ---------- ---------- --------------------
total 7 0.00 0.01 1 2 0 1
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. WaitTotal Waited
---------------------------------------- Waited----------------------
SQL*Net message to client 5 0.00 0.00
SQL*Net message from client 5 10.32 15.71
db file sequential read 1 0.01 0.01
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
3userSQL statements in session.
0internal SQL statements in session.
3SQL statements in session.
1statement EXPLAINed in this session.
********************************************************************************
Trace file: dg53_ora_18857_hr_trace02.trc
Trace file compatibility: 10.01.00
Sort options: default
0session in tracefile.
3userSQL statements in trace file.
0internal SQL statements in trace file.
3SQL statements in trace file.
3unique SQL statements in trace file.
1SQL statements EXPLAINed using schema:
HR.prof$plan_table
Default table was used.
Table was created.
Table was dropped.
46lines in trace file.
15elapsed seconds in trace file.
$ head -30 dg53_ora_18857_hr_trace02.trc
/u01/app/oracle/admin/orcl10g/udump/dg53_ora_18857_hr_trace02.trc
*** TRACE DUMP CONTINUED FROM FILE
/u01/app/oracle/admin/orcl10g/udump/dg53_ora_18857_hr_trace02.trc ***
*** 2012-06-08 14:28:26.627
=====================
PARSING IN CURSOR #2 len=68 dep=0 uid=55 oct=42 lid=55 tim=1307750885378875
hv=2804619552 ad='2349fc80'
alter session set events '10046 trace name context forever,level 12'
END OF STMT
EXEC #2:c=0,e=107,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1307750885378870
WAIT #2: nam='SQL*Net message to client' ela= 2 driver> obj#=-1 tim=1307750885378967
WAIT #2: nam='SQL*Net message from client' ela= 126 driver> obj#=-1 tim=1307750885379118
WAIT #0: nam='SQL*Net message to client' ela= 1 driver> obj#=-1 tim=1307750885379173
WAIT #0: nam='SQL*Net message from client' ela= 5384831 driver> p3=0 obj#=-1 tim=1307750890764022
=====================
PARSING IN CURSOR #3 len=50 dep=0 uid=55 oct=3 lid=55 tim=1307750890764197hv=2273608758 ad='2349fa44'
select salary from employees where employee_id=:id
END OF STMT
PARSE #3:c=0,e=96,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1307750890764193
BINDS #3:
kkscoacd
Bind#0
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0
kxsbbbfp=b7fb9ad0bln=22avl=02flg=05
value=200
EXEC #3:c=0,e=334,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1307750890764600
WAIT #3: nam='SQL*Net message to client' ela= 2 driver> WAIT #3: nam='db file sequential read' ela= 13073 file#=5 block#=84 blocks=1 obj#=51857 tim=1307750890780678
FETCH #3:c=5999,e=16119,p=1,cr=2,cu=0,mis=0,r=1,dep=0,og=1,tim=1307750890780769
页:
[1]