使用10046 trace跟踪SQL

环境准备

drop table t purge;create table t ( x int );alter system flush shared_pool;alter system flush buffer_cache;

开始跟踪

SQL> alter session set events '10046 trace name context  forever,level 12';Session altered.SQL> begin  2      for i in 1 .. 100000  3      loop  4          execute immediate  5          'insert into t values ( '||i||')';  6      end loop;  7      commit;    8  end;  9  /PL/SQL procedure successfully completed.SQL> alter session set events '10046 trace name context off';Session altered.

查找生成的跟踪文件

SQL> select d.value  2  || '/'  3  || LOWER (RTRIM(i.INSTANCE, CHR(0)))  4  || '_ora_'  5  || p.spid  6  || '.trc' trace_file_name  7  from (select p.spid  8        from v$mystat m,v$session s, v$process p  9        where  m.statistic#=1 and s.sid=m.sid and p.addr=s.paddr) p, 10        (select t.INSTANCE 11         FROM v$thread t,v$parameter v 12         WHERE v.name='thread' 13         AND(v.VALUE=0 OR t.thread#=to_number(v.value))) i, 14         (select value 15         from v$parameter 16         where name='user_dump_dest') d;TRACE_FILE_NAME----------------------------------------------------------------------/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_2199.trc

对trace文件进行格式化

[oracle@orasql ~]$ tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_2199.trc /home/oracle/10046.log sys=no sort=prsela,exeela,fchelaTKPROF: Release 11.2.0.4.0 - Development on Sat Jul 22 16:46:35 2017Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.[oracle@orasql ~]$

查看格式化后的跟踪文件

[oracle@orasql ~]$ vi /home/oracle/10046.logTKPROF: Release 11.2.0.4.0 - Development on Sat Jul 22 16:46:35 2017Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.Trace file: /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_2199.trcSort options: prsela  exeela  fchela********************************************************************************count    = number of times OCI procedure was executedcpu      = cpu time in seconds executingelapsed  = elapsed time in seconds executingdisk     = number of physical reads of buffers from diskquery    = number of buffers gotten for consistent readcurrent  = number of buffers gotten in current mode (usually for update)rows     = number of rows processed by the fetch or execute call********************************************************************************begin    for i in 1 .. 100000    loop        execute immediate        'insert into t values ( '||i||')';    end loop;    commit;end;call     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        1      0.00       0.00          0          0          0           0Execute      1      4.98       5.07          0          0          0           1Fetch        0      0.00       0.00          0          0          0           0------- ------  -------- ---------- ---------- ---------- ----------  ----------total        2      4.99       5.07          0          0          0           1Misses in library cache during parse: 1Optimizer mode: ALL_ROWSParsing user id: 84Elapsed times include waiting on following events:  Event waited on                             Times   Max. Wait  Total Waited  ----------------------------------------   Waited  ----------  ------------  log file sync                                   1        0.01          0.01  SQL*Net message to client                       1        0.00          0.00  SQL*Net message from client                     1       26.55         26.55********************************************************************************