SQL_Trace

用以描述SQL的执行过程的trace输出：

  • SQL是如何操作数据的
  • SQL执行过程中产生了哪些等待时间
  • SQL执行中消耗了多少资源
  • SQL的实际执行计划
  • SQL产生的递归语句

set auto trace（explain plan）：输出优化器产生的执行计划（估算值），此时sql语句并没有实际执行

SQL_Trace（10046）：SQL实际的执行情况（消耗的资源、产生的等待事件、数据的处理过程等）

当需要分析执行计划及CBO行为时，使用：set auto trace（explain plan）

当要看一条SQL的真实运行效果时，使用：SQL_Trace（10046）

产生一个SQL_Trace：

  1. -- 开启sql_trace
  2. alter session set sql_trace=true;
  3. select count(*) from emp;
  4. -- 关闭sql_trace
  5. alter session set sql_trace=false;

查看sql_trace的trace文件：

  1. -- 查看产生的trace文件位置
  2. select * from v$diag_info where name like 'Default%';

阅读原始的trace文件

trace文件中的一个sql执行的trace：

  1. =====================
  2. PARSING IN CURSOR #3 len=24 dep=0 uid=93 oct=3 lid=93 tim=169553505032 hv=2295140356 ad='a6f89f34' sqlid='g59vz2u4cu404'
  3. select count(*) from emp  执行的sql语句
  4. END OF STMT
  5. PARSE #3:c=15625,e=55925,p=0,cr=4,cu=0,mis=1,r=0,dep=0,og=1,plh=2083865914,tim=169553505031
  6. EXEC #3:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2083865914,tim=169553505094
  7. FETCH #3:c=0,e=32,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=2083865914,tim=169553505170
  8. STAT #3 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=3 pr=0 pw=0 time=0 us)'
  9. STAT #3 id=2 cnt=14 pid=1 pos=1 obj=94056 op='TABLE ACCESS FULL EMP (cr=3 pr=0 pw=0 time=13 us cost=3 size=0 card=14)'  这里的全表扫描等执行路径，不再是估算的执行计划，而是真正执行过程
  10. FETCH #3:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2083865914,tim=169553505470
  12. *** 2021-07-12 17:19:35.527
  13. CLOSE #3:c=0,e=21,dep=0,type=0,tim=169561324623
  14. =====================

trace中的缩写含义：

PARSING IN CURSOR部分：

  • len：被分析的SQL长度
  • dep：产生递归SQL的深度
  • uid：user id
  • otc：Oracle command type 命令的类型
  • lid：私有的用户id
  • tim：时间戳
  • hv：hash value
  • ad：SQL address

PARSE，EXEC，FETCH部分：

  • c：消耗的CPU time
  • e：elapsed time 操作的用时
  • p：physical reads 物理读的次数
  • cr：consistent reads 一致性方式读取的数据块
  • cu：current方式读取的数据块
  • mis：cursor miss in cache 硬解析次数
  • r：rows 处理的行数
  • dep：depth 递归SQL的深度
  • og：optimizer goal 优化器模式，1表示all rows，2表示 first rows，3表示rule
  • plh：plan hash，执行计划的hash
  • tim：timstamp 时间戳

STAT部分：

  • id：执行计划的行源号
  • cnt：当前行源返回的行数
  • pid：当前行源号的父号
  • pos：执行计划中的位置
  • obj：当前操作的对象id（如果当前行原始一个对象的话）
  • op：当前行源的数据访问操作

tkprof格式化trace文件工具

使用tkprof工具对trace文件进行汇总。直接使用tkprof可以查看命令帮助。

使用方式：

# tkprof trace文件 结果输出文件 
tkprof test.trc result.txt sys=no  # sys=no是为了排除系统生成的递归sql，这些sql一般是sys用户产生的

其他选项：

  • table=schema.tablename：一般配合explain=使用。trace展示的是sql的实际执行过程，有时候我们需要把执行过程和oracle推测的优化器执行计划做对比，可以使用该参数将执行计划输出到table里
  • explain=user/password：连接oracle展示执行计划
  • print=integer：只展示前n条sql
  • aggregate=yes|no：对于绑定变量等相同的sql，合并展示或是单独一条一条展示。默认yes合并展示
  • insert=filename：列出insert的数据和sql
  • record=filename：将用户的sql语句写入一个文件中，不记录sys的递归sql
  • waits=yes|no：是否记录等待事件
  • sort=option：排序方式

例如刚刚是sql进行汇总成表格后的结果：

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

SQL ID: g59vz2u4cu404
Plan Hash: 2083865914
select count(*) 
from
 emp


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.05          0          1          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          3          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.05          0          4          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 93  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SORT AGGREGATE (cr=3 pr=0 pw=0 time=0 us)
     14   TABLE ACCESS FULL EMP (cr=3 pr=0 pw=0 time=13 us cost=3 size=0 card=14)

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

跟踪其他会话的SQL

使用SQL_Trace跟踪其他会话，需要使用到dbms_system包，因此需要赋予这个包的执行权限：

conn / as sysdba
-- 赋权限
grant execute on dbms_system to test;
conn test/test;
-- 查找要跟踪的会话的SID、serial#
select sid,serial# from v$session where sid=223;  -- 要跟踪会话sid=223,serial#=1207
-- 跟踪会话
execute sys.dbms_system.set_sql_trace_in_session(223, 1207, true);
-- 关闭跟踪
execute sys.dbms_system.set_sql_trace_in_session(223, 1207, false);

其他第三方软件：

  • toad
  • pl/sql developer

10046事件

可以比sql_trace打印出更多信息。

用法：

-- 开启10046事件, level为级别
alter session set events '10046 trace name context forever,level n';
-- 关闭10046事件
alter session set events '10046 trace name context off';

级别：

  • level 1：等同于SQL_Trace功能
  • level 4：在level 1的基础上增加收集绑定变量的信息
  • level 8：在level 1的基础上增加等待事件的信息
  • level 12：等同于level 4 + level 8，即同时收集绑定变量信息和等待事件信息

10046 也可以跟踪其他会话：

-- dbms_system.set_ev(sid, serial#, 10046, level, 'username');
exec dbms_system.set_ev(135, 694, 10046, 12, ''); -- username为空表示当前用户