oracle sql_trace跟踪与使用tkprof工具分析

当执行某条sql语句，或者执行某个过程/包的时候性能出现问题，我们可以通过sql_trace来跟踪它们的执行情况，在跟踪文件中输出了，整个会话，或者整个数据库的执行情况。

首先，我们需要开启sql_trace（有session级，也有database级别的，数据库级别的显然会非常耗费资源，一般情况也没有必要开启）：

--设置当前会话，开启sql_trace
alter session set sql_trace=TRUE;
--设置trace文件标识，方便查找
ALTER SESSION SET tracefile_identifier='lubinsu';
--通过下面的语句来查询当前sql_trace文件的路径
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;

到指定目录下可以很方便地找到我们设置了标识的trace文件：

现在我随意执行一条语句试试：

--执行一条语句：

SELECT * FROM scott.emp a WHERE a.empno = 7900;

--关闭sql_trace

ALTER SESSION SET SQL_TRACE = FALSE;

--到oracle目录下查看下生成的文件里到底有哪些东西：

显然这文件的可读性是很差的，现在我们用tkprof来分析跟踪文件：

tkprof orclsid_ora_31518_lubinsu.trc

传到windows下查看：

ftp> get orclsid_ora_31518_lubinsu.out E:\oracle\trace\orclsid_ora_31518_lubinsu

.out

200 PORT command successful. Consider using PASV.

150 Opening BINARY mode data connection for orclsid_ora_31518_lubinsu.out (13956

bytes).

226 File send OK.

ftp: 13956 bytes received in 0.00Seconds 13956.00Kbytes/sec.

经过tkprof的分析，是不是感觉可读性好了很多，在文本开头对每个字段的含义进行了说明，并且描述了tkprof的版本信息：

往下查找，可以找到我们之前执行的这条sql：

********************************************************************************

--执行一条语句：

SELECT * FROM scott.emp a WHERE a.empno = 7900

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 2 0 1

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 3 0.00 0.00 0 2 0 1

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 5

Rows Row Source Operation

------- ---------------------------------------------------

1 TABLE ACCESS BY INDEX ROWID EMP (cr=2 pr=0 pw=0 time=426 us)

1 INDEX UNIQUE SCAN PK_EMP (cr=1 pr=0 pw=0 time=235 us)(object id 51149)

********************************************************************************

可见这条sql一致性方式读取的数据块为2，处理的行数为1

当然，跟踪文件里还有很多信息：

Trace file: /home/oracle/oracle/product/10.2.0/db_1/admin/orcl/udump/orclsid_ora_31518_lubinsu.trc

Trace file compatibility: 10.01.00

Sort options: default

0 session in tracefile.

21 user SQL statements in trace file.

10 internal SQL statements in trace file.

31 SQL statements in trace file.

10 unique SQL statements in trace file.

281 lines in trace file.

686 elapsed seconds in trace file.

..............