跟踪会话使用event10046和tkprof

一、使用跟踪事件10046

很多时候，对数据库进行性能诊断可以使用SQL跟踪的方法，把一些信息记录在trace文件里以后分析。一般情况下我们可以通过初始化参数SQL_TRACE=TRUE来设置SQL跟踪。我们也可以通过设置10046事件来进行SQL跟踪，并且可以设置不同的跟踪级别，比使用SQL_TRACE获得更多的信息。
Level 0     停用SQL跟踪，相当于SQL_TRACE=FALSE
Level 1     标准SQL跟踪，相当于SQL_TRACE=TRUE
Level 4     在level 1的基础上增加绑定变量的信息
level 8     在level 1的基础上增加等待事件的信息
Level 12    在level 1的基础上增加绑定变量和等待事件的信息
10046事件不但可以跟踪用户会话(trace文件位于USER_DUMP_DEST)，也可以跟踪background进程(trace文件位于BACKGROUND_DUMP_DEST)。

trace文件的大小决定于4个因素：
跟踪级别，跟踪时长，会话的活动级别和MAX_DUMP_FILE_SIZE参数。

二、启用跟踪事件10046

0.准备工作

1)Init.ORA参数
timed_statistics 设置为true(也可以在session上设置),否则不会有CPU时间信息　　
user_dump_dest 指定trace文件生成的目录　　
max_dump_file_size trace文件的最大尺寸(单位为操作系统块),UMLIMITED表示没有限制，Oracle8以后可以在后面加上K或M来表示文件大小　
optimizer_mode 定义缺省的查询优化器。虽然可以用alter session来设置，但在格式化trace文件里optimizer_mode会回复到原来的设置(一个新的session来分析SQL的执行计划)，这样会产生不准确的执行计划，所以建议不要通过session来修改这个参数。
注：在运行tkprof时不要加explain参数，就不存在这个问题，执行计划是Oracle在运行时所用的计划

2) 确定是以"dedicated"方式连接到数据库
通过tnsping service_name查看

1.在全局设置

修改初始化参数：
EVENT = "10046 trace name context forever, level 1"
或在Init.ORA中加入SQL_TRACE = TRUE，这样会对系统性能造成明显的影响，建议不要使用。

2.在当前session设置
SQL> alter session set sql_trace=true;
或
SQL> alter session set events '10046 trace name context forever, level 1';
SQL> alter session set events '10046 trace name context off';
在PL/SQL中,由于不能执行alter session,可以使用：　　
dbms_session.set_sql_trace(TRUE);　　
--必须安装DBMS_SESSION包，并"直接"赋给用户alter session的权限。

3.对其他用户session设置
首先获得要跟踪的session的session id和serial number
SQL> select sid,serial# from v$session where username='WACOS';
然后：
SQL> exec dbms_system.set_sql_trace_in_session( 1234, 56789, true);
或者
SQL> exec dbms_support.start_trace_in_session(sid => 1234,serial# => 56789,waits => true,binds => true);
SQL> exec dbms_support.stop_trace_in_session(sid => 1234,serial# => 56789);
或者
SQL> exec dbms_system.set_ev( 1234, 56789, 10046, 8, '');
SQL> exec dbms_system.set_ev( 1234, 56789, 10046, 0, '');
或者
SQL> exec dbms_monitor.session_trace_enable(session_id => 1234,serial_num => 56789,waits => true,binds => true);
SQL> exec dbms_monitor.session_trace_disable(session_id => 1234,serial_num => 56789);

也可以通过使用oradebug工具来设置10046事件
首先通过V$PROCESS获得该session的os process id。
SQL> select p.spid os_process_id, p.pid oracle_process_id
from v$session s, v$process p
where s.paddr = p.addr and s.username = upper('WACOS');
SQL> oradebug setospid 12345;
SQL> oradebug unlimit;
SQL> oradebug event 10046 trace name context forever, level 1;
SQL> oradebug event 10046 trace name context off;

三、获取跟踪文件

trace文件名是SID_ora_xxxx.trc，其中xxxx是与Oracle连接的shadow进程的PID，SID是Oracle实例的SID。
文件生成在Init.ORA参数user_dump_dest指定的目录下。
--select spid from v$process where addr = (select paddr from v$session where sid = (select distinct sid from v$mystat));
--若是其它session：select spid from v$process where addr = (select paddr from v$session where sid = &sid);

1.使用oradebug
SQL> oradebug setmypid
SQL> oradebug tracefile_name
/opt/oracle/product/9.2.0/rdbms/log/uxdb_ora_9183.trc

2.设置初始参数TRACEFILE_IDENTIFIER
SQL> alter session set tracefile_identifier = 'MyTrace';
这样在生成的trace文件名中会包含有MyTrace字样
/opt/oracle/product/9.2.0/rdbms/log/uxdb_ora_9183_MyTrace.trc

3.通过SQL查询
SQL> select d.value||'/'||lower(rtrim(i.instance, chr(0)))||'_ora_'||p.spid||'.trc' trace_file_name
from  
( select p.spid  
    from sys.v$mystat m,sys.v$session s,sys.v$process p  
    where m.statistic# = 1 and s.sid = m.sid and p.addr = s.paddr) p,
( select t.instance from sys.v$thread    t,sys.v$parameter    v
    where v.name = 'thread' and (v.value = 0 or t.thread# = to_number(v.value))) i,  
( select value from sys.v$parameter where name = 'user_dump_dest') d;
/opt/oracle/db01/app/oracle/admin/ORCL/udump/orcl_ora_8066.trc

四、用tkprof格式化trace文件:

常用：tkprof ORCL_ora_xxxx.trc ORCL_ora_yyyy.trc report.txt sys=no sort=fchela
tkprof是用来解释trace文件内容，把原始的trace文件转化为容易理解的文件。使用方法为:　　
tkprof trace文件名 报告文件名 [sort=option]
首先解释输出文件中列的含义：
? CALL：每次SQL语句的处理都分成三个部分
    Parse：这步将SQL语句转换成执行计划，包括检查是否有正确的授权和所需要用到的表、列以及其他引用到的对象是否存在。
    Execute：这步是真正的由Oracle来执行语句。对于insert、update、delete操作，这步会修改数据，对于select操作，这步就只是确定选择的记录。
    Fetch：返回查询语句中所获得的记录，这步只有select语句会被执行。
? COUNT:这个语句被parse、execute、fetch的次数。
? CPU：这个语句对于所有的parse、execute、fetch所消耗的cpu的时间，以秒为单位。
? ELAPSED：这个语句所有消耗在parse、execute、fetch的总的时间。
? DISK：从磁盘上的数据文件中物理读取的块的数量。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据。
? QUERY：在一致性读模式下，所有parse、execute、fetch所获得的buffer的数量。一致性模式的buffer是用于给一个长时间运行的事务提供一个一致性读的快照，缓存实际上在头部存储了状态。
? CURRENT：在current模式下所获得的buffer的数量。一般在current模式下执行insert、update、delete操作都会获取buffer。在current模式下如果在高速缓存区发现有新的缓存足够给当前的事务使用，则这些buffer都会被读入了缓存区中。
? ROWS: 所有SQL语句返回的记录数目，但是不包括子查询中返回的记录数目。对于select语句，返回记录是在fetch这步，对于insert、update、delete操作，返回记录则是在execute这步。
sort参数是用来指定输出的SQL是按什么数据来排序(如cpu时间或elapsed时间,详见tkprof的使用参数说明)　　
在report.txt中有关于每个SQL的parse/execute/fetch/disk read/buffer get/cpu time/执行计划(包括每一步运行时的行数),样例如下：　　
********************************************************************************
select owner#
from
obj$ o where obj# = :1
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          1        0.00         0.00            0            3            0             1
------- ------    -------- ---------- ---------- ---------- ----------    ----------
total          3        0.00         0.00            0            3            0             1
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS     (recursive depth: 1)
Rows       Row Source Operation
-------    ---------------------------------------------------
        1    TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 r=0 w=0 time=24 us)
        1     INDEX UNIQUE SCAN I_OBJ1 (cr=2 r=0 w=0 time=12 us)(object id 33)
********************************************************************************

在report.txt文件头有各个数据的解释，根据以下一些指标可以分析一下SQL的执行性能:　　
(query+current)/rows 平均每行所需的block数，太大的话（超过20）SQL语句效率太低
Parse count/Execute count parse count应尽量接近1，如果太高的话，SQL会进行不必要的reparse。要检查Pro*C程序的MAXOPENCURSORS是不是太低了，或不适当的使用的RELEASE_CURSOR选项　　
rows Fetch/Fetch Fetch Array的大小，太小的话就没有充分利用批量Fetch的功能，增加了数据在客户端和服务器之间的往返次数。在Pro*C中可以用prefetch=NN,Java/JDBC中可调用SETROWPREFETCH,在PL/SQL中可以用BULK COLLECT,SQLPLUS中的arraysize(缺省是15)
disk/query+current 磁盘IO所占逻辑IO的比例，太大的话有可能是db_buffer_size过小(也跟SQL的具体特性有关)
elapsed/cpu 太大表示执行过程中花费了大量的时间等待某种资源
cpu　OR　elapsed 太大表示执行时间过长，或消耗了大量的CPU时间，应该考虑优化
执行计划中的Rows 表示在该处理阶段所访问的行数，要尽量减少
整合.trc文件:
tkprof *.trc /file/ora_trc/ora_trc.txt explain=username/pwd sys=no insert=/file/ora_trc/insert.sql    record=/file/ora_trc/record.txt aggregate=no waits=yes

tkprof的参数有下面几个:　　
explain=username/password -> connect to oracle and issue explain plain
talbe=schema.tablename -> use'schema.table' with explain option
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
print=integer -> list only the first 'integer' sql statements
sort=option -> set zero or more of the following sort options
详细参数：
sort=userid -> userid of user that parsed the cursor
sort=fchrow -> number of rows fetched
sort=fchcu -> number of buffers for current read during fetch
sort=fchela -> elapsed time fetching
sort=fchcnt -> number of times fetch was called

查看当前session的跟踪级别:
SQL> Set serveroutput on
SQL> declare
event_level number;
begin
dbms_system.read_ev(10046,event_level);
dbms_output.put_line(to_char(event_level));
end;
/