引言

在Oracle数据库性能调优工作中，当我们通过AWR报告或实时监控定位到高消耗SQL之后，下一步就需要对SQL进行微观层面的深度剖析。SQL Trace（10046事件）配合TKPROF工具，是Oracle提供的最经典、最强大的SQL级性能分析手段。它能精确记录SQL执行过程中的每一步等待事件、CPU消耗、逻辑读和物理读，是SQL调优的“显微镜”。

本文将系统讲解SQL Trace的原理、启用方法、Trace文件的管理，以及如何用TKPROF将原始Trace文件转换为可读性强的分析报告，帮助你从Trace文件中提取关键性能信息。

一、SQL Trace的核心原理

1.1 什么是SQL Trace？

SQL Trace是Oracle数据库提供的一种内核级诊断工具。当对某个会话或整个实例启用SQL Trace后，Oracle会将SQL执行过程中的所有细节信息写入一个Trace文件中，包括：

• 每条SQL的解析（Parse）、执行（Execute）、获取（Fetch）各阶段的耗时
• CPU时间、等待事件及耗时
• 逻辑读（consistent gets + db block gets）和物理读（disk reads）
• 执行计划及行源操作统计信息
• 绑定变量的值

1.2 10046事件的级别

SQL Trace通过10046事件来控制跟踪深度，共分为四个级别：

| 级别 | 说明 | 用途 |

|------|------|------|

| Level 1 | 标准SQL Trace | 记录SQL执行的基本统计信息 |

| Level 4 | Level 1 + 绑定变量值 | 可以看到SQL实际使用的绑定变量值 |

| Level 8 | Level 1 + 等待事件 | 记录SQL执行过程中的所有等待事件及耗时 |

| Level 12 | Level 1 + 绑定变量 + 等待事件 | 最全面的Trace级别，推荐用于深入分析 |

二、启用SQL Trace的六种方法

2.1 方法一：对当前会话启用（最常用）

-- 开启Level 12的Trace ALTER SESSION SET events '10046 trace name context forever, level 12'; -- 执行需要分析的SQL SELECT * FROM employees WHERE department_id = 10; -- 关闭Trace ALTER SESSION SET events '10046 trace name context off';

2.2 方法二：使用DBMS_SESSION包

-- 对当前会话开启 EXEC DBMS_SESSION.SESSION_TRACE_ENABLE(waits => TRUE, binds => TRUE); -- 执行SQL... -- 关闭 EXEC DBMS_SESSION.SESSION_TRACE_DISABLE();

2.3 方法三：对其他会话启用

-- 查询目标会话的SID和SERIAL# SELECT sid, serial#, username, status FROM v$session WHERE username = 'HR'; -- 对指定会话开启Trace EXEC DBMS_MONITOR.SESSION_TRACE_ENABLE( session_id => 123, serial_num => 456, waits => TRUE, binds => TRUE ); -- 关闭指定会话的Trace EXEC DBMS_MONITOR.SESSION_TRACE_DISABLE( session_id => 123, serial_num => 456 );

2.4 方法四：使用DBMS_MONITOR对特定服务/模块启用

-- 对特定服务和模块组合开启Trace EXEC DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE( service_name => 'SALES_SVC', module_name => 'ORDER_ENTRY', waits => TRUE, binds => TRUE ); -- 关闭 EXEC DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE( service_name => 'SALES_SVC', module_name => 'ORDER_ENTRY' );

2.5 方法五：设置SQL_ID级别Trace（12c及以上）

-- 对特定SQL_ID开启Trace ALTER SYSTEM SET EVENTS 'sql_trace [sql: 5tjqf7sxdz5g2] level=12'; -- 关闭 ALTER SYSTEM SET EVENTS 'sql_trace [sql: 5tjqf7sxdz5g2] off';

2.6 方法六：通过登录触发器

-- 创建登录触发器，对特定用户的会话自动开启Trace CREATE OR REPLACE TRIGGER trace_hr_session AFTER LOGON ON DATABASE BEGIN IF USER = 'HR' THEN EXECUTE IMMEDIATE 'ALTER SESSION SET events ''10046 trace name context forever, level 12'''; END IF; END; /

三、定位和读取Trace文件

3.1 查找Trace文件路径

-- 查看Trace文件目录 SHOW PARAMETER user_dump_dest; -- 或者通过以下查询获取完整路径 SELECT value FROM v$parameter WHERE name = 'user_dump_dest'; -- 查看当前会话的Trace文件名（Oracle 11g及以上） SELECT value FROM v$diag_info WHERE name = 'Default Trace File';

3.2 标识自己的Trace文件

-- 在Trace文件中加入标记，便于后续识别 ALTER SESSION SET tracefile_identifier = 'my_sql_test'; -- Trace文件名将包含此标识：<SID>_ora_<PID>_my_sql_test.trc

3.3 查看Trace文件名的方法

-- 方法一：通过v$process和v$session关联 SELECT p.tracefile FROM v$session s, v$process p WHERE s.paddr = p.addr AND s.sid = (SELECT SYS_CONTEXT('USERENV', 'SID') FROM DUAL); -- 方法二：使用oradebug（需SYSDBA权限） ORADEBUG SETMYPID ORADEBUG TRACEFILE_NAME

四、TKPROF工具详解

4.1 什么是TKPROF？

TKPROF（Transient Kernel Profiler）是Oracle自带的命令行工具，用于将原始Trace文件（二进制的、难以阅读的格式）转换为格式化的、易读的分析报告。它能：

• 汇总每条SQL的执行统计
• 计算每条SQL的资源消耗
• 按多种维度排序（CPU时间、物理读、逻辑读、执行次数等）
• 生成包含执行计划的报告

4.2 TKPROF的基本语法

tkprof <trace_file> <output_file> [options]

常用选项：

| 选项 | 说明 |

|------|------|

|sys=no| 排除SYS用户递归执行的SQL（强烈推荐） |

|sort=<option>| 按指定维度排序输出 |

|print=<n>| 只输出前n条SQL |

|aggregate=yes/no| 是否合并相同SQL的统计信息 |

|explain=<user/pass>| 为每条SQL生成执行计划 |

|record=<file>| 将Trace中的SQL提取到文件中 |

|waits=yes/no| 是否输出等待事件摘要 |

|insert=<file>| 生成可将统计信息存入数据库的INSERT脚本 |

4.3 排序选项详解

sort参数是TKPROF最重要的选项，决定报告中SQL的排列顺序：

| 排序键 | 含义 |

|--------|------|

|prsela| 按解析阶段总耗时（Parse Elapsed） |

|exeela| 按执行阶段总耗时（Execute Elapsed） |

|fchela| 按获取阶段总耗时（Fetch Elapsed） |

|prscpu| 按解析阶段CPU时间 |

|execpu| 按执行阶段CPU时间 |

|fchcpu| 按获取阶段CPU时间 |

|prscnt| 按解析次数 |

|execnt| 按执行次数 |

|fchcnt| 按获取次数 |

|disk| 按物理读数量 |

|query| 按逻辑读数量（Consistent Gets + DB Block Gets） |

|rows| 按处理行数 |

常用排序组合：

# 按物理读降序排列（分析I/O瓶颈） tkprof ora_12345.trc output_io.txt sys=no sort=disk # 按获取阶段耗时降序排列（分析查询响应时间） tkprof ora_12345.trc output_time.txt sys=no sort=fchela # 按逻辑读降序排列（分析SQL效率） tkprof ora_12345.trc output_gets.txt sys=no sort=query

五、TKPROF报告解读指南

5.1 报告整体结构

一份典型的TKPROF报告包含以下部分：

1. 头信息：Trace文件名称、版本、排序选项 2. SQL语句摘要：每条SQL的统计信息 3. 执行计划：SQL的执行路径 4. 等待事件摘要：等待类型及次数统计 5. 总体摘要：所有SQL的汇总统计

5.2 SQL语句摘要部分解读

SQL ID: 5tjqf7sxdz5g2 Plan Hash: 3896541234 SELECT employee_id, first_name, last_name FROM employees WHERE department_id = :dept_id call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.01 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 2 0.15 0.18 45 3200 0 43 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.15 0.20 45 3200 0 43 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 84 (HR) Rows Row Source Operation ------- --------------------------------------------------- 43 TABLE ACCESS BY INDEX ROWID EMPLOYEES (cr=3200 pr=45 pw=0 time=186543 us) 43 INDEX RANGE SCAN EMP_DEPT_IDX (cr=150 pr=10 pw=0 time=45123 us)(object id 74821)

关键指标解读：

| 列名 | 含义 | 分析要点 |

|------|------|----------|

|call| SQL处理阶段：Parse/Execute/Fetch | 三个阶段各自消耗多少资源 |

|cpu| CPU时间（秒） | 与elapsed对比，差距大说明有等待 |

|elapsed| 总耗时（秒） | 包含CPU时间和等待时间 |

|disk| 物理读（数据块） | 值越高I/O开销越大 |

|query| 一致性逻辑读（CR Gets） | 反映SQL访问的数据块数量，是SQL效率的核心指标 |

|current| 当前模式逻辑读（DB Block Gets） | 通常来自DML操作 |

|rows| 处理的行数 | 与实际返回的行数对比 |

5.3 行源操作信息解读

在Row Source Operation部分：

• cr：一致性逻辑读数量
• pr：物理读数量
• pw：物理写数量
• time：本步骤消耗时间（微秒）

通过对比每一步的cr和pr，可以精确定位SQL执行过程中最耗资源的步骤。

5.4 执行计划与统计信息

如果在TKPROF中使用了explain参数，报告还会包含优化器估算的执行计划。将估算的计划与实际的行源操作统计进行对比，可以发现统计信息不准确或优化器选择偏差的问题。

六、完整操作流程示例

实战命令序列：

-- 步骤1-5：在SQL*Plus中操作 ALTER SESSION SET tracefile_identifier = 'perf_test'; ALTER SESSION SET events '10046 trace name context forever, level 12'; -- 执行目标SQL SELECT /* my_test */ e.employee_id, e.last_name, d.department_name FROM employees e, departments d WHERE e.department_id = d.department_id AND e.salary > 5000; ALTER SESSION SET events '10046 trace name context off'; -- 步骤6：找到Trace文件 SELECT value FROM v$diag_info WHERE name = 'Default Trace File';

# 步骤7：在操作系统命令行执行TKPROF cd /u01/app/oracle/diag/rdbms/orcl/orcl/trace/ # 按物理读排序输出 tkprof orcl_ora_12345_perf_test.trc report_disk.txt sys=no sort=disk # 按获取阶段耗时排序，并生成执行计划 tkprof orcl_ora_12345_perf_test.trc report_time.txt \ sys=no sort=fchela explain=hr/hr waits=yes # 提取SQL语句到文件 tkprof orcl_ora_12345_perf_test.trc report_sql.txt \ sys=no record=extracted_sql.sql

七、Trace分析的高级技巧

7.1 使用trcsess合并多个Trace文件

当应用通过连接池访问数据库时，一个业务操作可能涉及多个会话的Trace，可以使用trcsess工具合并：

# 按Session ID合并 trcsess output=merged.trc session=123.456 *.trc # 按客户端ID合并（需要在应用端设置DBMS_SESSION.SET_IDENTIFIER） trcsess output=merged.trc clientid=myapp *.trc # 对合并后的文件运行TKPROF tkprof merged.trc merged_report.txt sys=no sort=fchela

7.2 分析绑定变量值

当Trace级别包含Level 4或Level 12时，可以在Trace文件中直接看到绑定变量值：

BINDS #18446744071539018256: Bind#0 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7f8b3c0a5d00 bln=22 avl=02 flg=05 value=10

或在TKPROF报告中使用binds=yes参数查看。

7.3 与AWR数据关联验证

将TKPROF报告中SQL的SQL_ID与AWR中的记录关联：

-- 从AWR中查询同一SQL_ID的历史执行统计 SELECT snap_id, executions_delta, elapsed_time_delta / 1000000 AS elapsed_sec, disk_reads_delta, buffer_gets_delta, rows_processed_delta FROM dba_hist_sqlstat WHERE sql_id = '5tjqf7sxdz5g2' ORDER BY snap_id;

八、使用场景与最佳实践

8.1 典型使用场景

| 场景 | Trace方案 | 分析重点 |

|------|-----------|----------|

| 单条SQL响应慢 | 当前会话Level 12 | 等待事件分布，物理读比例 |

| 批量作业性能差 | 对其他会话启用Level 8 | Execute阶段耗时，逻辑读总量 |

| 绑定变量窥探问题 | Level 12 | 查看绑定变量实际值，对比不同值的计划 |

| 间歇性性能抖动 | DBMS_MONITOR长期监控 | 结合ASH数据对比异常时段 |

| 连接池环境 | trcsess合并多个Trace | 端到端的完整调用链路 |

8.2 注意事项与风险

1. 性能影响：Level 12的Trace会产生大量写入I/O，对生产系统有不可忽视的性能影响。建议在业务低峰期使用，或对单个会话短期开启。

1. 磁盘空间：Trace文件增长极快，需要确保Trace目录有足够空间，并在分析完成后及时清理。

1. 优先使用DBMS_MONITOR：在生产环境中，推荐使用DBMS_MONITOR系列包，其功能更丰富且易于管理。

1. 敏感信息：Trace文件中可能包含业务数据（绑定变量值），需要注意安全保管。

1. 不要只依赖TKPROF估算计划：explain参数生成的是估算计划，与实际情况可能存在差异。务必结合Trace中实际的行源操作统计进行分析。

九、总结与建议

1. SQL Trace是Oracle最底层的SQL性能分析工具，通过10046事件的四个级别控制跟踪粒度，Level 12（绑定变量+等待事件）是进行深度分析的最佳选择。

1. TKPROF将原始Trace文件转化为结构化报告，核心排序键包括fchela（查询耗时）、disk（物理读）、query（逻辑读），根据不同的分析目标选择合适的排序方式。

1. 报告解读的核心是对比CPU时间与Elapsed时间（识别等待）、关注物理读与逻辑读的比例（评估缓存效率）、分析行源操作每一步的资源消耗（定位执行计划瓶颈）。

1. 最佳实践：先通过AWR定位高消耗SQL，再用SQL Trace对该SQL进行微观剖析，最后结合执行计划和统计信息制定优化方案。

调优箴言：TKPROF报告中的每个数字都有其物理含义，不要满足于“看到了什么”，而要追问“为什么是这个数字”。