搜索
首页数据库mysql教程使用10046查看执行计划并读懂trace文件

查看 sql 执行计划的方法有许多种, 10046 事件就是其中的一种. 与其他查看 sql 执行计划不同, 当我们遇到比较复杂的 sql 语句, 我们可以通过 10046 跟踪 sql 得到执行计划中每一个步骤的逻辑读, 物理读以及花费的时间等. 这种细粒度的跟踪对于我们分析 sql 性

查看 sql 执行计划的方法有许多种, 10046 事件就是其中的一种. 与其他查看 sql 执行计划不同, 当我们遇到比较复杂的 sql 语句, 我们可以通过 10046 跟踪 sql 得到执行计划中每一个步骤的逻辑读, 物理读以及花费的时间等. 这种细粒度的跟踪对于我们分析 sql 性能尤其有用.

一般来说, 使用 10046 事件得到 sql 执行计划的步骤如下:
1. 激活当前 session 10046 事件
2. 在当前 session 中执行 sql 语句
3. 关闭当前 session 10046 事件

执行完上述步骤后, 通常会自动生成一个 trace 文件. 在 oracle 11g 中, trace 文件一般放在$ORACLE_BASE/diag/rdbms/{database_name}/$ORACLE_SID/trace 目录下. 如果使用 oradebug 激活跟踪 10046后, 可以使用 oradebug tracefile_name 得到刚刚生成的 trace 文件的完整路径.
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
background_dump_dest                 string      g:\app\davidd\diag\rdbms\david
                                                 \david\trace

刚刚提到的 oradebug 激活跟踪 10046 事件, 我想大部分 dba 都会使用. oradebug 是个功能强大非常好用的工具, 使用 oradebug help 将会看到它的功能很多
SQL> oradebug help
HELP           [command]                 		Describe one or all commands
SETMYPID                                 		Debug current process
SETOSPID       <ospid>                   		Set OS pid of process to debug
SETORAPID      <orapid> [&#39;force&#39;]        		Set Oracle pid of process to debug
SETORAPNAME    <orapname>                		Set Oracle process name to debug
SHORT_STACK                              		Get abridged OS stack
CURRENT_SQL                              		Get current SQL
DUMP           <dump_name> <lvl> [addr]  		Invoke named dump
DUMPSGA        [bytes]                   		Dump fixed SGA
DUMPLIST                                 		Print a list of available dumps
EVENT          <text>                    		Set trace event in process
SESSION_EVENT  <text>                    		Set trace event in session
DUMPVAR        <p|s|uga> <name> [level]  		Print/dump a fixed PGA/SGA/UGA variable
DUMPTYPE       <address> <type> <count>  		Print/dump an address with type info
SETVAR         <p|s|uga> <name> <value>  		Modify a fixed PGA/SGA/UGA variable
PEEK           <addr> <len> [level]      		Print/Dump memory
POKE           <addr> <len> <value>      		Modify memory
WAKEUP         <orapid>                  		Wake up Oracle process
SUSPEND                                  		Suspend execution
RESUME                                   		Resume execution
FLUSH                                    		Flush pending writes to trace file
CLOSE_TRACE                              		Close trace file
TRACEFILE_NAME                           		Get name of trace file
LKDEBUG                                  		Invoke global enqueue service debugger
NSDBX                                    		Invoke CGS name-service debugger
-G             <Inst-List | def | all>   		Parallel oradebug command prefix
-R             <Inst-List | def | all>   		Parallel oradebug prefix (return output
SETINST        <instance# .. | all>      		Set instance list in double quotes
SGATOFILE      <SGA dump dir>            		Dump SGA to file; dirname in double quotes
DMPCOWSGA      <SGA dump dir> 		 		Dump & map SGA as COW; dirname in double quotes
MAPCOWSGA      <SGA dump dir>            		Map SGA as COW; dirname in double quotes
HANGANALYZE    [level] [syslevel]        		Analyze system hang
FFBEGIN                                  		Flash Freeze the Instance
FFDEREGISTER                             		FF deregister instance from cluster
FFTERMINST                               		Call exit and terminate instance
FFRESUMEINST                             		Resume the flash frozen instance
FFSTATUS                                 		Flash freeze status of instance
SKDSTTPCS      <ifname>  <ofname>        		Helps translate PCs to names
WATCH          <address> <len> <self|exist|all|target>  Watch a region of memory
DELETE         <local|global|target> watchpoint <id>    Delete a watchpoint
SHOW           <local|global|target> watchpoints        Show  watchpoints
DIRECT_ACCESS  <set/enable/disable command | select query> Fixed table access
CORE                                     		Dump core without crashing process
IPC                                      		Dump ipc information
UNLIMIT                                  		Unlimit the size of the trace file
PROCSTAT                                 		Dump process statistics
CALL           <func> [arg1] ... [argn]  		Invoke function with arguments
使用 oradebug 跟踪 10046 命令如下:
SQL> oradebug setmypid
Statement processed.

// 激活 10046 事件
SQL> oradebug event 10046 trace name context forever,level 12;
Statement processed.

SQL> select /*+ leading(t3) use_merge(t4) */ *
  2  from t3, t4
  3  where t3.id = t4.t3_id and t3.n = 1100;

10 rows selected.

// 在当前 session 关闭 10046 事件
SQL> oradebug event 10046 trace name context off;
Statement processed.

// 使用 oradebug tracefile_name 可以直接看到生成的 trace 文件的位置
SQL> oradebug tracefile_name;
g:\app\davidd\diag\rdbms\david\david\trace\david_ora_2176.trc

其中, 10046 按照收集信息的内容分为以下等级:

 

Level 0 停用SQL跟踪,相当于SQL_TRACE=FALSE
Level 1 标准SQL跟踪,相当于SQL_TRACE=TRUE
Level 4 在level 1的基础上增加绑定变量的信息
Level 8 在level 1的基础上增加等待事件的信息
Level 12 在level 1的基础上增加绑定变量和等待事件的信息

 

分析读懂 trace 文件

现在我们打开 g:\app\davidd\diag\rdbms\david\david\trace\david_ora_2176.trc 看看生成的 trace 文件的内容

<pre name="code" class="sql"><pre name="code" class="sql"><pre name="code" class="sql"><pre name="code" class="sql" style="font-size:14px;">PARSING IN CURSOR #22 len=92 dep=0 uid=0 oct=3 lid=0 tim=900460923321 hv=1624778336 ad=&#39;34671d90&#39; sqlid=&#39;g0rdyg9hdh9m0&#39;
select /*+ leading(t3) use_merge(t4) */ *
from t3, t4
where t3.id = t4.t3_id and t3.n = 1100
END OF STMT
PARSE #22:c=0,e=10777,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3831111046,tim=900460923319
EXEC #22:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3831111046,tim=900460923482
WAIT #22: nam=&#39;SQL*Net message to client&#39; ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=900460923512
FETCH #22:c=15625,e=23922,p=0,cr=119,cu=0,mis=0,r=1,dep=0,og=1,plh=3831111046,tim=900460947462
WAIT #22: nam=&#39;SQL*Net message from client&#39; ela= 221 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=900460947755
WAIT #22: nam=&#39;SQL*Net message to client&#39; ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=900460947803
FETCH #22:c=0,e=71,p=0,cr=0,cu=0,mis=0,r=9,dep=0,og=1,plh=3831111046,tim=900460947864
STAT #22 id=1 cnt=10 pid=0 pos=1 obj=0 op=&#39;MERGE JOIN  (cr=119 pr=0 pw=0 time=28 us cost=193 size=1280 card=10)&#39;
STAT #22 id=2 cnt=1 pid=1 pos=1 obj=0 op=&#39;SORT JOIN (cr=15 pr=0 pw=0 time=0 us cost=6 size=63 card=1)&#39;
STAT #22 id=3 cnt=1 pid=2 pos=1 obj=83550 op=&#39;TABLE ACCESS FULL T3 (cr=15 pr=0 pw=0 time=0 us cost=5 size=63 card=1)&#39;
STAT #22 id=4 cnt=10 pid=1 pos=2 obj=0 op=&#39;SORT JOIN (cr=104 pr=0 pw=0 time=11 us cost=187 size=650000 card=10000)&#39;
STAT #22 id=5 cnt=10000 pid=4 pos=1 obj=83552 op=&#39;TABLE ACCESS FULL T4 (cr=104 pr=0 pw=0 time=8603 us cost=29 size=650000 card=10000)&#39;

从上面的 trace 文件我们可以看出 sql 语句经过了 parse(解析) -> exec(执行) -> fetch(从游标中获取数据) 几个过程, 其中第一句说明了当前跟踪执行的 sql 语句的概况,比如使用游标号, sql 语句的长度, 递归深度等等基本信息:

 

PARSING IN CURSOR #22 len=92 dep=0 uid=0 oct=3 lid=0 tim=900460923321 hv=1624778336 ad=&#39;34671d90&#39; sqlid=&#39;g0rdyg9hdh9m0&#39;

 

 

cursor cursor number
len sql 语句长度
dep sql 语句递归深度
uid user id
oct oracle command type
lid privilege user id
tim timestamp,时间戳
hv hash id
ad sql address 地址, 用在 v$sqltext
sqlid sql id

 

接着, 下面的语句说明了 sql 语句具体的执行过程以及每一个步骤消耗 CPU 的时间等性能指标

 

PARSE #22:c=0,e=10777,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3831111046,tim=900460923319
EXEC #22:c=0,e=29,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3831111046,tim=900460923482
FETCH #22:c=15625,e=23922,p=0,cr=119,cu=0,mis=0,r=1,dep=0,og=1,plh=3831111046,tim=900460947462

 

 

c CPU 消耗的时间
e Elapsed time
p number of physical reads 物理读的次数
cr number of buffers retrieved for CR reads 逻辑读的数据块
cu number of buffers retrieved in current mode (current 模式读取的数据块)
mis cursor missed in the cache 库缓存中丢失的游标, 硬解析次数
r number of rows processed 处理的行数
dep 递归深度
og optimizer mode 【1:all_rows, 2:first_rows, 3:rule, 4:choose】
plh plan hash value
tim timestamp 时间戳

 

以及执行过程中的发生的等待事件

 

WAIT #22: nam=&#39;SQL*Net message to client&#39; ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=900460923512
nam an event that we waited for 等待事件
ela 此操作消耗的时间
p3 block 块号
trm timestamp 时间戳

 

最后显示的是该游标的执行计划

 

STAT #22 id=1 cnt=10 pid=0 pos=1 obj=0 op=&#39;MERGE JOIN  (cr=119 pr=0 pw=0 time=28 us cost=193 size=1280 card=10)&#39;
STAT #22 id=2 cnt=1 pid=1 pos=1 obj=0 op=&#39;SORT JOIN (cr=15 pr=0 pw=0 time=0 us cost=6 size=63 card=1)&#39;
STAT #22 id=3 cnt=1 pid=2 pos=1 obj=83550 op=&#39;TABLE ACCESS FULL T3 (cr=15 pr=0 pw=0 time=0 us cost=5 size=63 card=1)&#39;
STAT #22 id=4 cnt=10 pid=1 pos=2 obj=0 op=&#39;SORT JOIN (cr=104 pr=0 pw=0 time=11 us cost=187 size=650000 card=10000)&#39;
STAT #22 id=5 cnt=10000 pid=4 pos=1 obj=83552 op=&#39;TABLE ACCESS FULL T4 (cr=104 pr=0 pw=0 time=8603 us cost=29 size=650000 card=10000

 

 

cnt 当前行源返回的行数
pid parent id of this row source 当前行源的父结点 id
pos position in explain plan 执行计划的位置
obj object id of row source (if this is a base object)
op the row source access operation

 

例如, 执行步骤 merge join 消耗的逻辑读为 119, 物理读为 0, 耗费的时间为 28 us, 成本 cost 193,返回 10 条记录

使用 tkprof 命令翻译 trace 文件

我们也可以使用 tkprof 命令对 trace 文件进行翻译,得到一个容易理解的 trace 汇总报表文件

C:\Documents and Settings\davidd> tkprof g:\app\davidd\diag\rdbms\david\david\trace\david_ora_2176.trc d:\trace.trc

TKPROF: Release 11.2.0.1.0 - Development on Thu Dec 18 18:51:44 2014

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

tkprof 翻译的 trace 文件的汇总报表如下:
Trace file: g:\app\davidd\diag\rdbms\david\david\trace\david_ora_2176.trc
Sort options: default


********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing 
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************


select /*+ leading(t3) use_merge(t4) */ *
from t3, t4
where t3.id = t4.t3_id and t3.n = 1100


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        2      0.00       0.00          0        119          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0        119          0          10


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


Rows     Row Source Operation
-------  ---------------------------------------------------
     10  MERGE JOIN  (cr=119 pr=0 pw=0 time=0 us cost=193 size=1280 card=10)
      1   SORT JOIN (cr=15 pr=0 pw=0 time=0 us cost=6 size=63 card=1)
      1    TABLE ACCESS FULL T3 (cr=15 pr=0 pw=0 time=0 us cost=5 size=63 card=1)
     10   SORT JOIN (cr=104 pr=0 pw=0 time=0 us cost=187 size=650000 card=10000)
  10000    TABLE ACCESS FULL T4 (cr=104 pr=0 pw=0 time=8733 us cost=29 size=650000 card=10000)




Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       2        0.00          0.00
  SQL*Net message from client                     2       20.23         20.23






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


OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS


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        2      0.00       0.00          0        119          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0        119          0          10


Misses in library cache during parse: 1


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       3        0.00          0.00
  SQL*Net message from client                     3       20.23         30.20




OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        0      0.00       0.00          0          0          0           0
Execute      0      0.00       0.00          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        0      0.00       0.00          0          0          0           0


Misses in library cache during parse: 0


    1  user  SQL statements in session.
    0  internal SQL statements in session.
    1  SQL statements in session.
********************************************************************************
Trace file: g:\app\davidd\diag\rdbms\david\david\trace\david_ora_2176.trc
Trace file compatibility: 11.1.0.7
Sort options: default


       1  session in tracefile.
       1  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       1  SQL statements in trace file.
       1  unique SQL statements in trace file.
     122  lines in trace file.
       0  elapsed seconds in trace file.

其中,Misses in library cache during parse :1 意思是解析的时候库缓存丢失游标, 也就是说发生了一次硬解析

声明
本文内容由网友自发贡献,版权归原作者所有,本站不承担相应法律责任。如您发现有涉嫌抄袭侵权的内容,请联系admin@php.cn
MySQL的位置:数据库和编程MySQL的位置:数据库和编程Apr 13, 2025 am 12:18 AM

MySQL在数据库和编程中的地位非常重要,它是一个开源的关系型数据库管理系统,广泛应用于各种应用场景。1)MySQL提供高效的数据存储、组织和检索功能,支持Web、移动和企业级系统。2)它使用客户端-服务器架构,支持多种存储引擎和索引优化。3)基本用法包括创建表和插入数据,高级用法涉及多表JOIN和复杂查询。4)常见问题如SQL语法错误和性能问题可以通过EXPLAIN命令和慢查询日志调试。5)性能优化方法包括合理使用索引、优化查询和使用缓存,最佳实践包括使用事务和PreparedStatemen

MySQL:从小型企业到大型企业MySQL:从小型企业到大型企业Apr 13, 2025 am 12:17 AM

MySQL适合小型和大型企业。1)小型企业可使用MySQL进行基本数据管理,如存储客户信息。2)大型企业可利用MySQL处理海量数据和复杂业务逻辑,优化查询性能和事务处理。

幻影是什么读取的,InnoDB如何阻止它们(下一个键锁定)?幻影是什么读取的,InnoDB如何阻止它们(下一个键锁定)?Apr 13, 2025 am 12:16 AM

InnoDB通过Next-KeyLocking机制有效防止幻读。1)Next-KeyLocking结合行锁和间隙锁,锁定记录及其间隙,防止新记录插入。2)在实际应用中,通过优化查询和调整隔离级别,可以减少锁竞争,提高并发性能。

mysql:不是编程语言,而是...mysql:不是编程语言,而是...Apr 13, 2025 am 12:03 AM

MySQL不是一门编程语言,但其查询语言SQL具备编程语言的特性:1.SQL支持条件判断、循环和变量操作;2.通过存储过程、触发器和函数,用户可以在数据库中执行复杂逻辑操作。

MySQL:世界上最受欢迎的数据库的简介MySQL:世界上最受欢迎的数据库的简介Apr 12, 2025 am 12:18 AM

MySQL是一种开源的关系型数据库管理系统,主要用于快速、可靠地存储和检索数据。其工作原理包括客户端请求、查询解析、执行查询和返回结果。使用示例包括创建表、插入和查询数据,以及高级功能如JOIN操作。常见错误涉及SQL语法、数据类型和权限问题,优化建议包括使用索引、优化查询和分表分区。

MySQL的重要性:数据存储和管理MySQL的重要性:数据存储和管理Apr 12, 2025 am 12:18 AM

MySQL是一个开源的关系型数据库管理系统,适用于数据存储、管理、查询和安全。1.它支持多种操作系统,广泛应用于Web应用等领域。2.通过客户端-服务器架构和不同存储引擎,MySQL高效处理数据。3.基本用法包括创建数据库和表,插入、查询和更新数据。4.高级用法涉及复杂查询和存储过程。5.常见错误可通过EXPLAIN语句调试。6.性能优化包括合理使用索引和优化查询语句。

为什么要使用mysql?利益和优势为什么要使用mysql?利益和优势Apr 12, 2025 am 12:17 AM

选择MySQL的原因是其性能、可靠性、易用性和社区支持。1.MySQL提供高效的数据存储和检索功能,支持多种数据类型和高级查询操作。2.采用客户端-服务器架构和多种存储引擎,支持事务和查询优化。3.易于使用,支持多种操作系统和编程语言。4.拥有强大的社区支持,提供丰富的资源和解决方案。

描述InnoDB锁定机制(共享锁,独家锁,意向锁,记录锁,间隙锁,下一键锁)。描述InnoDB锁定机制(共享锁,独家锁,意向锁,记录锁,间隙锁,下一键锁)。Apr 12, 2025 am 12:16 AM

InnoDB的锁机制包括共享锁、排他锁、意向锁、记录锁、间隙锁和下一个键锁。1.共享锁允许事务读取数据而不阻止其他事务读取。2.排他锁阻止其他事务读取和修改数据。3.意向锁优化锁效率。4.记录锁锁定索引记录。5.间隙锁锁定索引记录间隙。6.下一个键锁是记录锁和间隙锁的组合,确保数据一致性。

See all articles

热AI工具

Undresser.AI Undress

Undresser.AI Undress

人工智能驱动的应用程序,用于创建逼真的裸体照片

AI Clothes Remover

AI Clothes Remover

用于从照片中去除衣服的在线人工智能工具。

Undress AI Tool

Undress AI Tool

免费脱衣服图片

Clothoff.io

Clothoff.io

AI脱衣机

AI Hentai Generator

AI Hentai Generator

免费生成ai无尽的。

热门文章

R.E.P.O.能量晶体解释及其做什么(黄色晶体)
3 周前By尊渡假赌尊渡假赌尊渡假赌
R.E.P.O.最佳图形设置
3 周前By尊渡假赌尊渡假赌尊渡假赌
R.E.P.O.如果您听不到任何人,如何修复音频
3 周前By尊渡假赌尊渡假赌尊渡假赌
WWE 2K25:如何解锁Myrise中的所有内容
4 周前By尊渡假赌尊渡假赌尊渡假赌

热工具

mPDF

mPDF

mPDF是一个PHP库,可以从UTF-8编码的HTML生成PDF文件。原作者Ian Back编写mPDF以从他的网站上“即时”输出PDF文件,并处理不同的语言。与原始脚本如HTML2FPDF相比,它的速度较慢,并且在使用Unicode字体时生成的文件较大,但支持CSS样式等,并进行了大量增强。支持几乎所有语言,包括RTL(阿拉伯语和希伯来语)和CJK(中日韩)。支持嵌套的块级元素(如P、DIV),

WebStorm Mac版

WebStorm Mac版

好用的JavaScript开发工具

VSCode Windows 64位 下载

VSCode Windows 64位 下载

微软推出的免费、功能强大的一款IDE编辑器

EditPlus 中文破解版

EditPlus 中文破解版

体积小,语法高亮,不支持代码提示功能

螳螂BT

螳螂BT

Mantis是一个易于部署的基于Web的缺陷跟踪工具,用于帮助产品缺陷跟踪。它需要PHP、MySQL和一个Web服务器。请查看我们的演示和托管服务。