집 >데이터 베이스 >MySQL 튜토리얼 >10046事件与tkprof命令
在ORACLE数据库里,我们通常可以使用如下这些方法(包括但不限于)得到目标SQL的执行计划: 1,explain plan 2,DBMS_XPLAN包 3,SQLPLUS中的AUTOTRACE开关 4,10046事件 5,10053事件 6,AWR报告或者STATSPACK报告 前面的四种方法比较普遍。 下面我来介绍下第
在ORACLE数据库里,我们通常可以使用如下这些方法(包括但不限于)得到目标SQL的执行计划:
1,explain plan
2,DBMS_XPLAN包
3,SQLPLUS中的AUTOTRACE开关
4,10046事件
5,10053事件
6,AWR报告或者STATSPACK报告
前面的四种方法比较普遍。
下面我来介绍下第四种即10046事件如何得到目标SQL的执行计划
10046与使用explain plan命令,DBMS_XPLAN包和AUTOTRACE开关的不同之处在于,所得到的执行计划中明确显示了目标SQL的实际执行计划中每一个步骤所消耗的逻辑度(cr:consistent read),物理读(pr:physical read)和花费的时间(time)。
用10046事件得到的目标SQL的执行计划只需要依次执行下面三步:
在当前SESSION中激活10046事件在此SESSION中执行目标SQL在此SESSION中关闭10046事件执行完上面的步骤后,ORACLE会将目标SQL的执行计划和明细资源消耗写入此SESSION对应的TRACE文件中,此文件一把会在USER_DUMP_DEST目录下,其命名格式是: 实例名_ora_当前SESSION的SPID.trc.
通常可以用下面两种方法激活10046事件:
在当前SESSION中执行alter session set events '10046 trace name context forever,level 12'在当前SESSION中执行oradebug event 10046 trace name context forever,level 12本人偏向喜欢用第二中,因为可以在激活10046事件后,执行命令oradebug tracefile_name来得到当前SESSION所对应的trace文件的具体路径和名称
对应的在当前SESSION中关闭10046事件的方法为:
alter session set events '10046 trace name context off'oradebug event 10046 trace name context off10046生成的TRACE文件,我们称之为裸文件(raw trace),ORACCLE 提供了工具TKPROF来查看他。下面我们来做一个实验来演示如何通过10046事件来获取和查看目标SQL的实际执行计划
下面我以目标SQL: "select empno,ename,dname from scott.emp,scott.dept where emp.deptno=dept.deptno" 为例子来说明10046事件和TKPROF的用法
SQL> oradebug help SQL> select empno,ename,dname from scott.emp,scott.dept where emp.deptno=dept.deptno; EMPNO ENAME DNAME EMPNO ENAME DNAME 14 rows selected. 用oradebug tracefile_name命令就可以一目了然的看到当前session激活10046事件后所对应的trace文件的路径和名称: SQL> oradebug tracefile_name 关掉10046事件: SQL> oradebug event 10046 trace name context off 查看/u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc文件 [oracle@even ~]$ vi /u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc *** 2013-12-06 12:46:25.079 。。。。。。 。。。。。。 这样直接查看此文件,太难看了,格式很乱,不方便读。这个时候我们可以用ORACLE的TKPROF来格式化此文件,操作如下: [oracle@even ~]$ tkprof /u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc /u01/app/oracle/admin/OMR/udump/watson_omr_ora_16192_tkprof.trc TKPROF: Release 10.2.0.1.0 - Production on Fri Dec 6 12:57:28 2013 Copyright (c) 1982, 2005, Oracle. All rights reserved. 这个时候下面的格式就是格式化过的,方便读的 [oracle@even ~]$ vi /u01/app/oracle/admin/OMR/udump/watson_omr_ora_16192_tkprof.trc TKPROF: Release 10.2.0.1.0 - Production on Fri Dec 6 12:57:28 2013 Copyright (c) 1982, 2005, Oracle. All rights reserved. Trace file: /u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc ******************************************************************************** The following statement encountered a error during parse: select empno,ename,dname,from scott.emp,scott.dept where emp.deptno=dept.deptno Error encountered: ORA-00936 select obj#,type#,ctime,mtime,stime,status,dataobj#,flags,oid$, spare1, Misses in library cache during parse: 1 Rows Row Source Operation select t.ts#,t.file#,t.block#,nvl(t.bobj#,0),nvl(t.tab#,0),t.intcols, 69,0-1 7% 。。。。。。 。。。。。。 我们可以看到,用tkprof命令翻译后的内容更加直观,容易懂,而且内容显示的执行计划是我们熟悉的形式。
HELP [command] Describe one or all commands
SETMYPID Debug current process
SETOSPID
SETORAPID
SHORT_STACK Dump abridged OS stack
DUMP
DUMPSGA [bytes] Dump fixed SGA
DUMPLIST Print a list of available dumps
EVENT
SESSION_EVENT
DUMPVAR
DUMPTYPE
SETVAR
PEEK
POKE
WAKEUP
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
-R
SETINST
SGATOFILE
DMPCOWSGA
MAPCOWSGA
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
WATCH
DELETE
SHOW
CORE Dump core without crashing process
IPC Dump ipc information
UNLIMIT Unlimit the size of the trace file
PROCSTAT Dump process statistics
CALL
SQL> oradebug setmypid
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12
Statement processed.
---------- ---------- --------------
7369 SMITH RESEARCH
7499 ALLEN SALES
7521 WARD SALES
7566 JONES RESEARCH
7654 MARTIN SALES
7698 BLAKE SALES
7782 CLARK ACCOUNTING
7788 SCOTT RESEARCH
7839 KING ACCOUNTING
7844 TURNER SALES
7876 ADAMS RESEARCH
---------- ---------- --------------
7900 JAMES SALES
7902 FORD RESEARCH
7934 MILLER ACCOUNTING
/u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc
Statement processed.
/u01/app/oracle/admin/OMR/udump/omr_ora_16192.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production
With the Partitioning, Oracle Label Security, OLAP and Data Mining options
ORACLE_HOME = /u01/app/oracle/product/10.2.0/db_1
System name: Linux
Node name: even.oracle.com
Release: 2.6.18-164.el5
Version: #1 SMP Thu Sep 3 02:16:47 EDT 2009
Machine: i686
Instance name: OMR
Redo thread mounted by this instance: 1
Oracle process number: 15
Unix process pid: 16192, image: oracle@even.oracle.com (TNS V1-V3)
*** SERVICE NAME:(SYS$USERS) 2013-12-06 12:46:25.079
*** SESSION ID:(158.19) 2013-12-06 12:46:25.079
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
********************************************************************************
********************************************************************************
spare2
from
obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null
and linkname is null and subname is null
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.03 0 0 0 0
Fetch 1 0.00 0.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.03 0 3 0 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
------- ---------------------------------------------------
1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=0 pw=0 time=157 us)
1 INDEX RANGE SCAN I_OBJ2 (cr=2 pr=0 pw=0 time=84 us)(object id 37)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net break/reset to client 2 0.00 0.00
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************
nvl(t.clucols,0),t.audit$,t.flags,t.pctfree$,t.pctused$,t.initrans,
t.maxtrans,t.rowcnt,t.blkcnt,t.empcnt,t.avgspc,t.chncnt,t.avgrln,
t.analyzetime,t.samplesize,t.cols,t.property,nvl(t.degree,1),
nvl(t.instances,1),t.avgspc_flb,t.flbcnt,t.kernelcols,nvl(t.trigflag, 0),
nvl(t.spare1,0),nvl(t.spare2,0),t.spare4,t.spare6,ts.cachedblk,ts.cachehit,
ts.logicalread
from
tab$ t, tab_stats$ ts where t.obj#= :1 and t.obj# = ts.obj# (+)