sql_trace and 10046事件

sql_trace and 10046事件[@more@]

1).trace_file

alter session set tracefile_identifier='mytest' 可以设置目前session的trace file的名字。

alter session set sql_trace=true

2)

[oracle@oracle10g ~]$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
[print= ] [insert= ] [sys= ] [sort= ]
table=schema.tablename Use 'schema.tablename' with 'explain=' option.
explain=user/password Connect to ORACLE and issue EXPLAIN PLAN.
print=integer List only the first 'integer' SQL statements.
aggregate=yes|no
insert=filename List SQL statements and data inside INSERT statements.
sys=no TKPROF does not list SQL statements run as user SYS.
record=filename Record non-recursive statements found in the trace file.
waits=yes|no Record summary for any wait events found in the trace file.
sort=option Set of zero or more of the following sort options:
prscnt number of times parse was called
prscpu cpu time parsing
prsela elapsed time parsing
prsdsk number of disk reads during parse
prsqry number of buffers for consistent read during parse
prscu number of buffers for current read during parse
prsmis number of misses in library cache during parse
execnt number of execute was called
execpu cpu time spent executing
exeela elapsed time executing
exedsk number of disk reads during execute
exeqry number of buffers for consistent read during execute
execu number of buffers for current read during execute
exerow number of rows processed during execute
exemis number of library cache misses during execute
fchcnt number of times fetch was called
fchcpu cpu time spent fetching
fchela elapsed time fetching
fchdsk number of disk reads during fetch
fchqry number of buffers for consistent read during fetch
fchcu number of buffers for current read during fetch
fchrow number of rows fetched
userid userid of user that parsed the cursor

• explain=user/password 不但会生成sql的实际执行路径，还会生成sql的执行计划
• sys=yes/no yes(默认情况下)表示在trace文件输出所有sys操作，
• aggregate=yes|no tkprof工具将所有相同的sql在输入文件中做合并

select object_type,count(*)
from
tt group by object_type

---==================================================
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 4 0.02 0.04 0 686 0 39
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.03 0.04 0 686 0 39

Misses in library cache during parse: 0 shared pool命中，表示在软解析
Optimizer mode: ALL_ROWS 优化器模式
Parsing user id: SYS 当前用户

Rows Row Source Operation
------- ---------------------------------------------------
39 HASH GROUP BY (cr=686 pr=0 pw=0 time=40976 us)
49586 TABLE ACCESS FULL TT (cr=686 pr=0 pw=0 time=132 us)

---==============================================================

parse：sql的分析阶段

execute：sql的执行阶段

fetch：数据的提取阶段

count：表示当前的操作执行了多少次

cpu：当前的操作消耗多少cpu(单位秒)

elapsed：当前的操作一共用时多少(包括cpu时间和等待时间)

disk：当前的物理读

query：当前操作的一致性读方式读取的数据块数(通常是查询使用的方式)

current：当前操作的current方式读取的数据块数(通常是修改数据使用的方式)

rows：当前操作处理的数据记录数

rows source operation ：行源操作，表示当前操作的数据访问方式

cr---consistent read:一致性读取的方式，相当于query中fetch的数值

pr---physical read:物理读取的数据块，相当于disk上fetch的数值

pw---physical write:物理写

time：当前操作执行的时间

3）直接分析产生的trace文件

[oracle@oracle10g udump]$ ll
total 12
-rw-r--r-- 1 oracle oinstall 5186 Nov 14 08:18 a1.txt
-rw-r----- 1 oracle oinstall 2048 Nov 14 08:16 oracle10g_ora_3174.trc
[oracle@oracle10g udump]$ more oracle10g_ora_3174.trc
/u01/oracle/admin/oracle10g/udump/oracle10g_ora_3174.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - 64bit Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /u01/oracle/product/10.2.0/db_1
System name: Linux
Node name: oracle10g
Release: 2.6.18-164.el5
Version: #1 SMP Tue Aug 18 15:51:48 EDT 2009
Machine: x86_64
Instance name: oracle10g
Redo thread mounted by this instance: 1
Oracle process number: 18
Unix process pid: 3174, image: oracle@oracle10g (TNS V1-V3)

*** SERVICE NAME:(SYS$USERS) 2012-11-14 08:15:46.432
*** SESSION ID:(1080.9) 2012-11-14 08:15:46.432

上面是操作系统，数据库的信息。
=====================
.........................................
=====================
PARSING IN CURSOR #2 len=56 dep=0 uid=0 oct=3 lid=0 tim=1321144680316280 hv=831628736 ad='71ab1080'
select object_type,count(*) from tt group by object_type
END OF STMT
PARSE #2:c=1000,e=255,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1321144680316271
EXEC #2:c=0,e=305,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1321144680316725
FETCH #2:c=29995,e=40757,p=0,cr=686,cu=0,mis=0,r=1,dep=0,og=1,tim=1321144680357571
FETCH #2:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,tim=1321144680358246
FETCH #2:c=0,e=21,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,tim=1321144680358708
FETCH #2:c=0,e=117,p=0,cr=0,cu=0,mis=0,r=8,dep=0,og=1,tim=1321144680359035
STAT #2 id=1 cnt=39 pid=0 pos=1 obj=0 op='HASH GROUP BY (cr=686 pr=0 pw=0 time=40976 us)'
STAT #2 id=2 cnt=49586 pid=1 pos=1 obj=52376 op='TABLE ACCESS FULL TT (cr=686 pr=0 pw=0 time=132 us)'
=====================
parsing in cursor部分：

len：被分析sql的长度

dep：产生递归sql的深度

uid：user id

otc：oracle command type命令的类型

lid：私有用户的id

tim：时间戳

hv：hash value

ad：sql address

parse，exec，fetch部分

c：消耗的cpu time

e：elapsed time 操作的用时

p：physical read 物理读的次数

cr：consistent read 一次性方式读取的数据块

cu：current 方式读取的数据块

mis：cursor miss in cache硬分析次数

r：row处理的行数

dep：depth递归sql的深度

og：optimizer goal优化器模式

tim：timestamp时间戳

stat部分

id：执行计划的行原号

cnt：当前行源返回的行数

pid：当前行源号的父号

pos：执行计划中的位置

obj：当前操作对象的id

op：当前行源的数据访问操作

4）10046事件

• level 1 = sql_trace
• level 4 = level 1 + 绑定变量的信息
• level 8 = level 1 + 等待时间信息
• level 12 =level 4 + level 8

SQL> alter session set events '10046 trace name context forever,level 12';

Session altered.

SQL> alter session set events '10046 trace name context off';

Session altered.

5)对其他会话进行sql_trace

SQL> exec dbms_system.set_sql_trace_in_session(1083,248,true);

PL/SQL procedure successfully completed.

SQL> exec dbms_system.set_sql_trace_in_session(1083,248,false);

PL/SQL procedure successfully completed.

6)对其他会话进行10046

SQL> exec dbms_monitor.session_trace_enable(1083,248,waits=>true,binds=>true);

PL/SQL procedure successfully completed.

SQL> exec dbms_monitor.session_trace_disable(1083,248);

PL/SQL procedure successfully completed.

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/24237320/viewspace-1059763/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/24237320/viewspace-1059763/