你有没有遇到过这种崩溃场景?

1、SQL明明走了索引,却慢得像蜗牛;

2、生产环境CPU/IO爆表,TOP SQL看不出问题;

3、开发说“代码没改”,DBA却背锅……

别慌!Oracle经典诊断利器——SQL_TRACE能把SQL执行的每一毫秒、每一次IO、每一次等待事件全部“扒光”,再搭配 **TKPROF** 一键生成美观报告,问题SQL瞬间现形。

今天这篇干货,从零到实战,手把手教你玩转SQL_TRACE。读完你就能独立诊断生产慢SQL,涨知识、涨技能、涨粉丝~

一、SQL_TRACE到底是什么?为什么这么强?

SQL_TRACE 是“会话级SQL跟踪”工具。它会把当前会话(或指定会话)执行的所有SQL语句“完整记录”下来,包括:

1、真实的执行计划

2、CPU时间、Elapsed总耗时

3、逻辑读、物理读、Fetch次数、Parse次数

4、等待事件(可选)

比 AUTOTRACE 更详细,比 AWR 更精准,尤其适合“实时诊断正在跑的SQL或存储过程”。

注意:12c 以后官方已不推荐直接用 `SQL_TRACE` 参数,建议用 `DBMS_MONITOR` 或 `DBMS_SESSION` 代替,功能更强大,还能顺便抓 binds 和 waits。

二、快速上手:跟踪当前会话

方法1:最简单 alter session(兼容老版本)

SQL> ALTER SESSION SET SQL_TRACE = TRUE;   -- 开启

-- 执行业务SQL...

SQL> ALTER SESSION SET SQL_TRACE = FALSE;  -- 关闭

默认情况下sql_trace的跟踪文件中,是不包含等待事件的,如果需要跟踪等待事件,需要单独加上跟踪等地事件的参数。

SQL> alter session set events 'sql_trace wait=true';    -- 开启

-- 执行业务SQL...

SQL> alter session set events 'sql_trace wait=false';  -- 关闭

方法2:推荐!DBMS_SESSION(12c+官方推荐)

SQL> exec dbms_session.set_sql_trace(true);     -- 开启

-- 执行业务SQL...

SQL> exec dbms_session.set_sql_trace(false);     -- 关闭

查看当前会话Trace文件位置:

SQL> select value from v$diag_info where name='Default Trace File';  -- 查看当前会话的Trace文件

格式化Trace文件:

$ tkprof /u01/app/diag/rdbms/orcl/orcl1/trace/orcl1_ora_6210.trc /home/oracle/mary.txt

三、进阶:跟踪指定会话(生产环境必备)

方法1:使用dbms_system.set_sql_trace_in_session跟踪:

1. 确定目标会话(SID + SERIAL#):

可通过主机名、用户名、program等信息确定会话信息

SELECT SID, SERIAL#, USERNAME, MACHINE 

FROM V$SESSION 

WHERE USERNAME = 'MARY' 

  AND MACHINE LIKE '%rac%';

开启跟踪:

SQL> exec dbms_system.set_sql_trace_in_session(1,67,true); 

PL/SQL procedure successfully completed. 

3. **业务执行完后关闭**:

SQL> exec dbms_system.set_sql_trace_in_session(1,67,false);

**小技巧**:有时候我们不确定是哪个会话在捣乱?一次开多个跟踪,完事逐个关就行!

SQL> exec dbms_system.set_sql_trace_in_session(1,627,true); 

SQL> exec dbms_system.set_sql_trace_in_session(2,673,true); 

SQL> exec dbms_system.set_sql_trace_in_session(13,675,true); 

SQL> exec dbms_system.set_sql_trace_in_session(16,676,true); 

跟踪完成后,逐一关闭即可。

SQL> exec dbms_system.set_sql_trace_in_session(1,627,false); 

SQL> exec dbms_system.set_sql_trace_in_session(2,673,false); 

SQL> exec dbms_system.set_sql_trace_in_session(13,675,false); 

SQL> exec dbms_system.set_sql_trace_in_session(16,676,false); 

方法2:使用DBMS_MONITOR开启跟踪:

开启跟踪:(通过这种开启sql_trace的方式所捕获的结果,已经很接近于10046了)

BEGIN 

    DBMS_MONITOR.SESSION_TRACE_ENABLE( 

        session_id   => 35, 

        serial_num   => 121, 

        waits        => TRUE, 

        binds        => TRUE 

    ); 

END; 

关闭跟踪:

BEGIN 

    DBMS_MONITOR.SESSION_TRACE_DISABLE( 

        session_id   => 35,     

        serial_num   => 121 

    ); 

END; 

Trace文件位置确认:

SELECT s.sid, s.serial#, p.tracefile FROM v$session s JOIN v$process p ON s.paddr = p.addr WHERE s.sid = 1 AND s.serial# = 67;

$ tkprof /u01/app/diag/rdbms/orcl/orcl1/trace/orcl1_ora_6210.trc /home/oracle/mary.txt

四、TKPROF:把“天书”变成“报告”

转换输出文件中的示例

Trace文件是纯文本,直接看头疼。**TKPROF** 一键格式化,瞬间变清晰报告。

常用命令:

tkprof /path/to/tracefile.trc /home/oracle/report.txt sys=no

[oracle@orcl11204 trace]$ 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 

这里有两个参数比较实用,一个是排序参数,可根据各种SQL的时间因素进行排序,如选项fchela,即按照elapsed time fetching来对分析的结果排序(需要设置初始化参数time_statistics=true),转换输出的文件将把最消耗时间的SQL放在最前面显示。另外一个有用的参数就是sys,这个参数设置为no,可以阻止所有以sys用户执行的递归SQL被显示出来,这样可以减少转换输出文件的内容,便于进一步分析。 

五、TKPROF报告核心解读

转换输出文件中的示例:

select order#,columns,types from access$ where d_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        3      0.00       0.00          0          6          0           2 

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

total        5      0.00       0.00          0          6          0           2 

Misses in library cache during parse: 0 

Optimizer mode: CHOOSE 

Parsing user id: SYS   (recursive depth: 1) 

Number of plan statistics captured: 1 

rclhis_ora_15245.trc 

输出文件中各数据项的含义:

call:被跟踪的SQL语句的处理过程分为三个阶段,即解析、执行和提取数据。 

parse:将SQL语句转换成执行计划,包括语法检查及语义分析。 

execute:真正地由ORACLE来执行语句。对于insert、update、delete操作,该语句会修改数据;对于select操作,该语句就只是确定选择的记录。 

fetch:返回查询语句中所获得的记录,只有select语句会被执行。 

count    = number of times OCI procedure was executed  

记录被parse、execute、fetch的次数。

cpu      = cpu time in seconds executing  

所有的parse、execute、fetch所消耗的CPU时间,以秒为单位

elapsed  = elapsed time in seconds executing  

所以消耗在parse、execute、fetch的总时间

disk     = number of physical reads of buffers from disk  

从磁盘上的数据文件中物理读取的数据块的数量

query    = number of buffers gotten for consistent read  

在一致读模式下,所有parse、execute、fetch所获取的buffer的数量。一致读模式的buffer是并发事务环境下为用户提供一个一致读的快照。

current  = number of buffers gotten in current mode (usually for update)  

在current模式下所获得的buffer的数量。执行insert、update、delete操作涉及在current模式下获取的buffer数据。

rows     = number of rows processed by the fetch or execute call 

所有SQL语句返回的记录数目,但是不包含子查询中返回的记录数目。对于select语句,返回记录是在fetch这步;对于insert、update、delete操作,返回记录则是在execute这步。

六、只跟踪特定SQL_ID(慎用!!!)

说明:以下方法是设置全局跟踪,影响面自行评估,慎用!!!

-- 开启

ALTER SYSTEM SET EVENTS 'sql_trace [SQL: <sql_id>] level 12';

-- 关闭

ALTER SYSTEM SET EVENTS 'sql_trace [SQL: <sql_id>] off';

示例:

ALTER SYSTEM SET EVENTS 'sql_trace [SQL: b5adfzn3knh8n] level 12';

ALTER SYSTEM SET EVENTS 'sql_trace [SQL: b5adfzn3knh8n] off';

由于用了 EVENTS 或会话跟踪,trace 文件可能分散在多个进程中。

使用下面SQL快速找到所有最新 trace 文件:

SELECT p.spid, p.tracefile, s.sid, s.serial#, s.program

FROM v$process p JOIN v$session s ON p.addr = s.paddr

WHERE p.tracefile LIKE '%_ora_%'

ORDER BY p.tracefile DESC;

掌握 SQL_TRACE + TKPROF,你就拥有了 Oracle 性能诊断的“X光机”。

下次再遇到慢SQL,别再猜了,直接 Trace 起来,5分钟出报告,领导同事直呼“专业”!

点赞 + 转发 + 关注,下期我们有更多干货内容继续分享

**评论区告诉我**:你目前最头疼的SQL性能问题是什么?我在后台一一解答,共同进步!

(文末彩蛋:把这篇文章发给你的DBA小伙伴,他一定会说“卧槽,这也太实用了”)

—— 睿 | Oracle性能优化老司机  

持续输出硬核干货,欢迎一起卷技术~

Logo

北京人形旗下天工造物具身智能开源社区,聚焦具身天工与慧思开物两大平台

更多推荐