博客
关于我
强烈建议你试试无所不能的chatGPT,快点击我
Oracle SQL Trace、Tkprof和10046事件
阅读量:5889 次
发布时间:2019-06-19

本文共 10680 字,大约阅读时间需要 35 分钟。

一、SQL TRACE

      当SQL语句出现性能问题时,我们可以用SQL_TRACE来跟踪SQL的执行情况,通过跟踪,我们可以了解一条SQL或者PL/SQL包的运行情况,SQL_TRACE命令会将SQL执行的整个过程输出到一个trace文件中,我们可以读这个trace文件来了解在这个SQL执行过程中Oracle都做了哪些操作。

      可以通过sql命令启动SQL_TRACE,或者在初始化参数里面。

1 SQL> alter session set sql_trace=true;2 3 Session altered.4 ----- 或者----------- 5 SQL> alter system set sql_trace =true;6 7 System altered.

      这两条命令的区别:

  在seesion级别设置,只对当前session进行跟踪,在实例级别,会对实例上所有的SQL做跟踪,这种方式跟踪的SQL太多,代价是非常大的,所以很少用。

  如果是在初始化文件里面设置,只需要在参数文件里添加一个sql_trace参数即可。

示例:

   1、确定当前的trace文件

    1.1、通过设置trace文件标识

1 SQL> alter session set tracefile_identifier='jack_trace';2 3 Session altered.

    设置标识的目的就是方便我们查找生成的trace文件。我们只需要在trace目录查找文件名里带有标识的文件即可。在Oralce 10g中,SQL_TRACE生成的trace文件默认路径是$ORACLE_BASE/admin/SID/udump;在11g中默认的路径是$ORACLE_BASE/diag/rdbms/SID/SID/trace/目录下。

    1.2、直接用如下SQL查出当前的trace文件名。

[oracle@node2 scripts]$ vi showtrace.sql SELECT  d.VALUE     || '/'     || LOWER (RTRIM(i.INSTANCE,CHR(0)))     || '_ora_'     || p.spid     || '.trc' as "trace_file_name"FROM (SELECT p.spid          FROM v$mystat m,v$session s,v$process p        WHERE m.statistic# = 1 AND s.SID = m.SID AND p.addr = s.paddr) p,      (SELECT t.INSTANCE          FROM v$thread t,v$parameter v        WHERE v.NAME = 'thread'          AND (v.VALUE = 0 OR t.thread# = TO_NUMBER (v.VALUE))) i,      (SELECT VALUE          FROM v$parameter        WHERE NAME = 'user_dump_dest') d;SQL> @showtracetrace_file_name--------------------------------------------------------------------------------/u01/app/oracle/diag/rdbms/yft2/YFT2/trace/yft2_ora_7328.trc

   2、启动SQL_TRACE

1 SQL> alter session set sql_trace=true;2 3 Session altered.

   3、进行相关事务操作

1 SQL> select count(*) from dba_objects;2 3   COUNT(*)4 ----------5      72450

   4、关闭SQL_TRACE

1 SQL> alter session set sql_trace=false;2 3 Session altered.

    注意:这里显示的关闭SQL_TRACE,在session级别,也可以直接退出SQLPLUS来终止SQL_TRACE。

    5、查看trace文件信息

    请看TKPROF工具介绍时显示刚才操作的trace文件信息。

二、TKPROF工具

    SQL_TRACE生产最原始的trace文件的可读性比较差,所以通常我们使用tkprof工具来处理trace文件。Tkprof工具是Oracle自带的一个工具,用于处理原始的trace文件,它的作用主要是合并汇总trace文件中的一些项,规范化文件的格式,使文件更具有可读性。

    注意:tkprof工具只能用在处理SQL_TRACE和10046事件产生的trace,其他事件如10053不能处理。

    Tkprof工具也有很多参数,可以在命令下直接敲入tkprof回车,就可以看到:

1 [oracle@node2 scripts]$ tkprof 2 Usage: tkprof tracefile outputfile [explain= ] [table= ] 3               [print= ] [insert= ] [sys= ] [sort= ] 4   table=schema.tablename   Use 'schema.tablename' with 'explain=' option. 5   explain=user/password    Connect to ORACLE and issue EXPLAIN PLAN. 6   print=integer    List only the first 'integer' SQL statements. 7   aggregate=yes|no 8   insert=filename  List SQL statements and data inside INSERT statements. 9   sys=no           TKPROF does not list SQL statements run as user SYS.10   record=filename  Record non-recursive statements found in the trace file.11   waits=yes|no     Record summary for any wait events found in the trace file.12   sort=option      Set of zero or more of the following sort options:13     prscnt  number of times parse was called14     prscpu  cpu time parsing15     prsela  elapsed time parsing16     prsdsk  number of disk reads during parse17     prsqry  number of buffers for consistent read during parse18     prscu   number of buffers for current read during parse19     prsmis  number of misses in library cache during parse20     execnt  number of execute was called21     execpu  cpu time spent executing22     exeela  elapsed time executing23     exedsk  number of disk reads during execute24     exeqry  number of buffers for consistent read during execute25     execu   number of buffers for current read during execute26     exerow  number of rows processed during execute27     exemis  number of library cache misses during execute28     fchcnt  number of times fetch was called29     fchcpu  cpu time spent fetching30     fchela  elapsed time fetching31     fchdsk  number of disk reads during fetch32     fchqry  number of buffers for consistent read during fetch33     fchcu   number of buffers for current read during fetch34     fchrow  number of rows fetched35     userid  userid of user that parsed the cursor

    2.1、explain=user/password

    在trace文件中输入SQL的执行计划,需要注意的是,如果不使用explain,在trace文件中我们看到的是SQL实际的执行路径。如果使用了explain,tkprof在trace文件中不但输入SQL的实际执行路径,还会生成该SQL的执行计划。

    2.2、 sys=no

    如果设置为yes,在trace文件中将输入所有的SYS用户操作,也包含用户SQL语句引发的递归SQL。

    如果设置为no,则不输出这些信息。

    默认情况下是yes,实际上设置为no后,trace文件具有更佳的可读性,因此一般在用tkprof工具时都手工的把该参数设置为no。

    2.3、aggregate=yes|no

    默认情况下,tkprof工具将所有相同的SQL在输入文件中做合并,如果设置为no,则分别列出每个SQL的信息。一般合并后看起来比较简洁,如果需要查看每一个SQL单独的信息,可以把aggregate设置为no。

    2.4、查看第一节中生成的trace文件

1 [oracle@node2 trace]$ tkprof YFT2_ora_7328_jack_trace.trc jack.txt sys=no 2  3 TKPROF: Release 11.2.0.1.0 - Development on Fri Dec 28 16:38:04 2012 4  5 Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved. 6  7  8 [oracle@node2 trace]$ view jack.txt  9 SQL ID: g4pkmrqrgxg3b10 Plan Hash: 294532012911 select count(*)12 from13  dba_objects14 15 16 call     count       cpu    elapsed       disk      query    current        rows17 ------- ------  -------- ---------- ---------- ---------- ----------  ----------18 Parse        1      0.02       0.02          0          0          0           019 Execute      1      0.00       0.00          0          0          0           020 Fetch        2      0.33       0.72         12       1773          0           121 ------- ------  -------- ---------- ---------- ---------- ----------  ----------22 total        4      0.35       0.74         12       1773          0           123 24 Misses in library cache during parse: 125 Optimizer mode: ALL_ROWS26 Parsing user id: 9227 28 Rows     Row Source Operation29 -------  ---------------------------------------------------30       1  SORT AGGREGATE (cr=1773 pr=12 pw=0 time=0 us)31   72450   VIEW  DBA_OBJECTS (cr=1773 pr=12 pw=0 time=637091 us cost=47 size=0 card=11457)32   72450    UNION-ALL  (cr=1773 pr=12 pw=0 time=521965 us)33   72450     FILTER  (cr=1772 pr=11 pw=0 time=377067 us)34   73356      HASH JOIN  (cr=907 pr=0 pw=0 time=480769 us cost=46 size=1294012 card=12812)35      94       INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=93 us cost=1 size=99 card=33)(object id 47)36   73356       HASH JOIN  (cr=906 pr=0 pw=0 time=295212 us cost=45 size=1255576 card=12812)37      94        INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=93 us cost=1 size=693 card=33)(object id 47)38   73356        TABLE ACCESS FULL OBJ$ (cr=905 pr=0 pw=0 time=146581 us cost=43 size=986524 card=12812)39    3889      TABLE ACCESS BY INDEX ROWID IND$ (cr=865 pr=11 pw=0 time=0 us cost=2 size=8 card=1)40    4790       INDEX UNIQUE SCAN I_IND1 (cr=122 pr=1 pw=0 time=0 us cost=1 size=0 card=1)(object id 41)41       0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=2 size=28 card=1)42       0       INDEX FULL SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=19 card=1)(object id 47)43       0       INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)44       0     NESTED LOOPS  (cr=1 pr=1 pw=0 time=0 us cost=1 size=16 card=1)45       0      INDEX FULL SCAN I_LINK1 (cr=1 pr=1 pw=0 time=0 us cost=0 size=13 card=1)(object id 137)46       0      INDEX RANGE SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=3 card=1)(object id 47)47 48 ********************************************************************************

 

三、10046事件

   10046事件并不是Oracle官方提供给用户的使用命令,在官方文档找不到这个事件的说明信息,它比SQL_TRACE能够获得更多的信息。

   10046事件按照收集的信息内容,可以分成4个级别:

   a. Level 1 等同于SQL_TRACE的功能。

   b. Level 4 在Level 1的基础上增加收集绑定变量的信息。

   c. Level 8 在Level 1的基础上增加等待事件的信息。

   d. Level 12 等同于Level 4+Level 8,即同时收集绑定变量信息和等待事件信息。

以level=4作为10046事件的一个例子:

-----首先获得sid-------------------------  1 SQL> select distinct sid from v$mystat; 2  3     SID 4 ---------- 5      1 6 SQL> col machine for a15;  -----获得sid以后,查找SPID号--------------- 7 SQL> select b.spid,a.sid,a.serial#,a.machine from v$session a,v$process b where a.paddr=b.addr and a.sid='1'; 8  9 SPID                SID    SERIAL# MACHINE10 ------------------------ ---------- ---------- ---------------11 25533                  1        17 node212 SQL> create table t as select * from dba_objects;13 14 Table created.15 16 SQL> exec dbms_stats.gather_table_stats(user,'t');17 18 PL/SQL procedure successfully completed.19 -----设定10046的事件级别为4---------------- 20 SQL> alter session set events '10046 trace name context forever,level 4';21 22 Session altered.23 -----定义2个变量x,y,然后让查询绑定这两个变量-------------24 SQL> variable x number;25 SQL> variable y varchar2;26 SQL> exec :x:=20;27 28 PL/SQL procedure successfully completed.29 30 SQL> exec :y:='T';31 32 PL/SQL procedure successfully completed.33 34 SQL> col object_name for a10;35 SQL> select object_id,object_name from t where object_id=:x or object_Name=:y;36  OBJECT_ID OBJECT_NAM37 ---------- ----------38     20     ICOL$39    74873   T ------10046事件的关闭------------ 40 SQL> alter session set events '10046 trace name context off';41  -------获得产生的跟踪文件所在的目录------------- 42 SQL> select value from v$parameter where name='user_dump_dest';43 44 VALUE45 --------------------------------------------------------------------------------46 /u01/app/oracle/diag/rdbms/yft2/YFT2/trace47 [oracle@node2 ~]$ cd /u01/app/oracle/diag/rdbms/yft2/YFT2/trace/ --------找到SPID是25533的trace文件--------------------- 48 [oracle@node2 trace]$ ll49 total 13250 -rw-r----- 1 oracle oinstall 120459 Dec 27 13:57 alert_YFT2.log51 -rw-r----- 1 oracle oinstall   3541 Dec 27 14:37 YFT2_ora_25533.trc52 -rw-r----- 1 oracle oinstall    106 Dec 27 14:37 YFT2_ora_25533.trm -------通过tkprof工具转换一下trace文件-------------------- 53 [oracle@node2 trace]$ tkprof YFT2_ora_25533.trc out.txt sys=no aggregate=no54 55 TKPROF: Release 11.2.0.1.0 - Development on Thu Dec 27 14:43:21 201256 57 Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.58 59 60 [oracle@node2 trace]$ ls61 alert_YFT2.log  out.txt  YFT2_ora_25533.trc  YFT2_ora_25533.trm62 [oracle@node2 trace]$ view out.txt 63 SQL ID: fb2s5q68vjc7264 Plan Hash: 160119687365 select object_id,object_name66 from67  t where object_id=:x or object_Name=:y68 69 70 call     count       cpu    elapsed       disk      query    current        rows71 ------- ------  -------- ---------- ---------- ---------- ----------  ----------72 Parse        1      0.00       0.00          0          0          0           073 Execute      1      0.00       0.00          0          0          0           074 Fetch        2      0.01       0.01          0       1038          0           275 ------- ------  -------- ---------- ---------- ---------- ----------  ----------76 total        4      0.01       0.01          0       1038          0           277 78 Misses in library cache during parse: 179 Misses in library cache during execute: 180 Optimizer mode: ALL_ROWS81 82 Session altered.

转载地址:http://xkfsx.baihongyu.com/

你可能感兴趣的文章
laravel 验证码使用示例
查看>>
IE开发人员工具无法使用
查看>>
分页器(自定制)
查看>>
HDU1877 又一版 A+B
查看>>
往sde中导入要素类报错000732
查看>>
springboot之启动方式
查看>>
初次安装git配置用户名和邮箱及密钥
查看>>
6.1(续)索引、索引组织表--Oracle模式对象
查看>>
动画 球
查看>>
C++中的堆,栈,静态内存区,常量区
查看>>
动态SQL实现与注意事项(有返回值与无返回值动态SQL 实现)
查看>>
java struts2 debug
查看>>
简单够用的设计
查看>>
Android图片圆角效果
查看>>
WeChat Official Account Admin Platform API Introduction
查看>>
C语言写单链表的创建、释放、追加(即总是在最后的位置增加节点)
查看>>
poj1635
查看>>
C# LINQ详解(一)
查看>>
视频直播点播nginx-rtmp开发手册中文版
查看>>
ruby学习总结04
查看>>