如何使用SQL_TRACE和10046事件
如何使用SQL_TRACE和10046事件
Eygle大师的微信讲堂昨天开课，第一堂课和大家分享了一些学习Oracle的基本方法，其中提到了使用SQL_TRACE和10046事件。SQL_TRACE是Oracle提供的用于进行SQL跟踪的手段，是强有力的辅助诊断工具。在日常的数据库问题诊断和解决中，SQL_TRACE是非常常用的方法。
对于这个工具，我很早就听过，但是从来就没用过，“纸上得来终觉浅，绝知此事要躬行”，操练起来。
1.环境准备
我们在Oracle11g中进行测试。
SQL>
SQL> select * from v$version;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - Production
PL/SQL Release 11.2.0.3.0 - Production
CORE 11.2.0.3.0 Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production
SQL>
2.启用SQL_TRACE
在Oracle中初始化设置中SQL_TRACE默认是关闭的，它可以作为初始化参数在全局启用，也可以通过命令行方式在具体session启用。
1． 在全局启用
在参数文件(pfile/spfile)中指定:
SQL_TRACE =true
在全局启用SQL_TRACE会导致所有进程的活动被跟踪，包括后台进程及所有用户进程，这通常会导致比较严重的性能问题，所以在生产环境中要谨慎使用，这个参数在10g之后是动态参数，可以随时调整，在某些诊断中非常有效。
提示: 通过在全局启用SQL_TRACE，我们可以跟踪到所有后台进程的活动，很多在文档中的抽象说明，通过跟踪文件的实时变化，我们可以清晰的看到各个进程之间的紧密协调。
2． 在当前session级设置
大多数时候我们使用SQL_TRACE跟踪当前进程.通过跟踪当前进程可以发现当前操作的后台数据库递归活动(这在研究数据库新特性时尤其有效)，研究SQL执行，发现后台错误等。
我在测试中启用session级别的SQL_TRACE，如下所示。
SQL>
SQL> show parameter SQL_TRACE
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
SQL_TRACE boolean FALSE
SQL>
SQL> alter session set SQL_TRACE=true;
Session altered.
SQL>
SQL> show parameter SQL_TRACE
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
SQL_TRACE boolean TRUE
SQL>
3.连接soctt用户，执行查询语句
登陆scott用户，执行两条简单的查询语句。
[oracle@hoegh admin]$ sqlplus scott/tiger
SQL*Plus: Release 11.2.0.3.0 Production on Wed May 27 09:59:48 2015
Copyright (c) 1982, 2011, Oracle. All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> select * from cat;
TABLE_NAME TABLE_TYPE
------------------------------ -----------
BONUS TABLE
DEPT TABLE
EMP TABLE
SALGRADE TABLE
SQL> select * from dept;
DEPTNO DNAME LOC
---------- -------------- -------------
10 ACCOUNTING NEW YORK
20 RESEARCH DALLAS
30 SALES CHICAGO
40 OPERATIONS BOSTON
4.生成trace文件
plustrace角色
和Oracle10g一样，11g中plustrace角色默认也是disabled的。如果使用非授权用户打开Oracle trace功能会得到以下的错误。
SQL>
SQL> show user
USER is \"SCOTT\"
SQL>
SQL> set autotrace on
SP2-0618: Cannot find the Session Identifier. Check PLUSTRACE role is enabled
SP2-0611: Error enabling STATISTICS report
SQL>
这时需要执行$ORACLE_HOME/sqlplus/admin/plustrce.sql脚本，手工创建plustrace角色，在此不做演示。因为我们更多的时候是需要跟踪其他用户的进程，而很多这样的用户可能没有被授予或者不允许授予plustrace角色。这时可以使用DBMS_SYSTEM包来实现对进程的跟踪，这儿需要提供用户进程的sid和serial#。
10046事件
在这儿就不得不提到10046事件，10046事件是Oracle提供的内部事件，是对SQL_TRACE的增强。
10046事件可以设置以下四个级别：
1 - 启用标准的SQL_TRACE功能,等价于SQL_TRACE
4 - Level 1 加上绑定值(bind values)
8 - Level 1 + 等待事件跟踪
12 - Level 1 + Level 4 + Level 8
和SQL_TRACE类似，10046事件可以在全局设置，也可以在session级设置。
生成trace文件
首先，我们通过查询v$session视图获取scott用户进程的sid和serial#；
然后执行dbms_system.set_ev过程来实现对进程的跟踪。
SQL>
SQL> select sid,serial#,username from v$session where username=\'SCOTT\';
SID SERIAL# USERNAME
---------- ---------- ------------------------------
21 2615 SCOTT
SQL>
SQL> exec dbms_system.set_ev(21,2615,10046,12,\'SCOTT\');
PL/SQL procedure successfully completed.
SQL>
5.查看trace文件
存放目录
在11g中trace文件的存放目录有了变化，其中，11gR1 或 11gR1 以上版本可以通过查询diagnostic_dest参数获得；而11gR1以前版本则是通过user_dump_dest参数来指定。
SQL> show parameter diagnostic_dest
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
diagnostic_dest string /u01/app/oracle
SQL>
在测试数据库中，trace文件的具体路径为：/u01/app/oracle/diag/rdbms/hoegh/HOEGH/trace/。
查看trace文件
tracefile 命名规则 ：<ORACLE_SID>_ora_<pid>.trc，其中pid为相应session所对应的OS PID。根据生成时间在/u01/app/oracle/diag/rdbms/hoegh/HOEGH/trace目录下找到了trace文件HOEGH_ora_16427.trc。我们通过more命令查看文件内容，由于内容较多，只截取了开始部分内容如下。
[oracle@hoegh trace]$ more HOEGH_ora_16427.trc
Trace file /u01/app/oracle/diag/rdbms/hoegh/HOEGH/trace/HOEGH_ora_16427.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/11.2.0/dbhome_1
System name: Linux
Node name: hoegh.example.com
Release: 2.6.18-164.el5PAE
Version: #1 SMP Thu Sep 3 02:28:20 EDT 2009
Machine: i686
VM name: VMWare Version: 6
Instance name: HOEGH
Redo thread mounted by this instance: 1
Oracle process number: 23
Unix process pid: 16427, image: [email protected] (TNS V1-V3)
*** 2015-05-27 09:56:36.240
*** SESSION ID:(142.1705) 2015-05-27 09:56:36.240
*** CLIENT ID:() 2015-05-27 09:56:36.240
*** SERVICE NAME:(SYS$USERS) 2015-05-27 09:56:36.240
*** MODULE NAME:([email protected] (TNS V1-V3)) 2015-05-27 09:56:36.2
40
*** ACTION NAME:() 2015-05-27 09:56:36.240
由于trace文件的可读性差，我们使用tkprof对trace文件进行格式化，以下是格式化后的信息内容，在这儿也只截取了开始部门，完整的内容贴到文档的最后供大家参考。
格式化trace文件
[oracle@hoegh trace]$ tkprof HOEGH_ora_16427.trc 10046.txt
TKPROF: Release 11.2.0.3.0 - Development on Wed May 27 11:20:36 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@hoegh trace]$
查看格式化后的trace报告
[oracle@hoegh trace]$ more 10046.txt
TKPROF: Release 11.2.0.3.0 - Development on Wed May 27 11:20:36 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@ hoegh trace]$
TKPROF: Release 11.2.0.3.0 - Development on Wed May 27 10:06:10 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: HOEGH_ora_16427.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
********************************************************************************
SQL ID: 4tk6t8tfsfqbf Plan Hash: 0
alter session set sql_trace=true
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.00 0 0 0 0
以上内容实现了一个应用sql_trace的简单案例，trace文件的信息量较大，我将会在下一篇文章中和大家分享。
大师论点
Eygle在课堂上提到他在面试时经常问的一个问题，“在什么技术上你做过深入思考得到了自己的观点”，绝大多数人的回答都是NO。
Eygle提倡由点及面、由浅入深的学习方法，确实，不深入是不可能有收获的。
期待下一次eygle在微信讲堂的精彩分享。
hoegh
15.05.22
-- The End --
附完整trace报告
TKPROF: Release 11.2.0.3.0 - Development on Wed May 27 11:20:36 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@ hoegh trace]$
TKPROF: Release 11.2.0.3.0 - Development on Wed May 27 10:06:10 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: HOEGH_ora_16427.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
********************************************************************************
SQL ID: 4tk6t8tfsfqbf Plan Hash: 0
alter session set sql_trace=true
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
********************************************************************************
SQL ID: 7cfz5wy9caaf4 Plan Hash: 4015672053
SELECT NAME NAME_COL_PLUS_SHOW_PARAM,DECODE(TYPE,1,\'boolean\',2,\'string\',3,
\'integer\',4,\'file\',5,\'number\', 6,\'big integer\', \'unknown\') TYPE,
DISPLAY_VALUE VALUE_COL_PLUS_SHOW_PARAM
FROM
V$PARAMETER WHERE UPPER(NAME) LIKE UPPER(:NMBIND_SHOW_OBJ) ORDER BY
NAME_COL_PLUS_SHOW_PARAM,ROWNUM
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 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.01 0 0 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT ORDER BY (cr=0 pr=0 pw=0 time=9094 us cost=2 size=2128 card=1)
1 1 1 COUNT (cr=0 pr=0 pw=0 time=8984 us)
1 1 1 HASH JOIN (cr=0 pr=0 pw=0 time=8979 us cost=1 size=2128 card=1)
1 1 1 FIXED TABLE FULL X$KSPPI (cr=0 pr=0 pw=0 time=6028 us cost=0 size=94 card=1)
2752 2752 2752 FIXED TABLE FULL X$KSPPCV (cr=0 pr=0 pw=0 time=3134 us cost=0 size=203400 card=100)
********************************************************************************
SQL ID: asvzxj61dc5vs Plan Hash: 3028786551
select timestamp, flags
from
fixed_obj$ where 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 1 0.00 0.00 0 2 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 2 0 0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 TABLE ACCESS BY INDEX ROWID FIXED_OBJ$ (cr=2 pr=0 pw=0 time=15 us cost=2 size=17 card=1)
0 0 0 INDEX UNIQUE SCAN I_FIXED_OBJ$_OBJ# (cr=2 pr=0 pw=0 time=10 us cost=1 size=0 card=1)(object id 102)
********************************************************************************
SQL ID: 96g93hntrzjtr Plan Hash: 2239883476
select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#,
sample_size, minimum, maximum, distcnt, lowval, hival, density, col#,
spare1, spare2, avgcln
from
hist_head$ where obj#=:1 and intcol#=:2
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 20 0.00 0.00 0 0 0 0
Fetch 20 0.00 0.00 0 58 0 18
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 41 0.00 0.00 0 58 0 18
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: RULE
Parsing user id: SYS (recursive depth: 2)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=3 pr=0 pw=0 time=206 us)
1 1 1 INDEX RANGE SCAN I_HH_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=159 us)(object id 427)
********************************************************************************
SQL ID: db78fxqxwxt7r Plan Hash: 3312420081
select /*+ rule */ bucket, endpoint, col#, epvalue
from
histgrm$ where obj#=:1 and intcol#=:2 and row#=:3 order by bucket
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 6 0 3
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 0.00 0.00 0 6 0 3
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: RULE
Parsing user id: SYS (recursive depth: 2)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT ORDER BY (cr=3 pr=0 pw=0 time=182 us cost=0 size=0 card=0)
1 1 1 TABLE ACCESS CLUSTER HISTGRM$ (cr=3 pr=0 pw=0 time=150 us)
1 1 1 INDEX UNIQUE SCAN I_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=102 us)(object id 422)
********************************************************************************
SQL ID: gcnf7vvsyq6w3 Plan Hash: 0
select SADDR , SID , SERIAL# , AUDSID , PADDR , USER# , USERNAME , COMMAND ,
OWNERID, TADDR , LOCKWAIT , STATUS , SERVER , SCHEMA# , SCHEMANAME ,OSUSER ,
PROCESS , MACHINE , PORT , TERMINAL , PROGRAM , TYPE , SQL_ADDRESS ,
SQL_HASH_VALUE, SQL_ID, SQL_CHILD_NUMBER , SQL_EXEC_START, SQL_EXEC_ID,
PREV_SQL_ADDR , PREV_HASH_VALUE , PREV_SQL_ID, PREV_CHILD_NUMBER ,
PREV_EXEC_START , PREV_EXEC_ID , PLSQL_ENTRY_OBJECT_ID,
PLSQL_ENTRY_SUBPROGRAM_ID, PLSQL_OBJECT_ID, PLSQL_SUBPROGRAM_ID, MODULE ,
MODULE_HASH , ACTION , ACTION_HASH , CLIENT_INFO , FIXED_TABLE_SEQUENCE ,
ROW_WAIT_OBJ# , ROW_WAIT_FILE# , ROW_WAIT_BLOCK# , ROW_WAIT_ROW# ,
TOP_LEVEL_CALL#, LOGON_TIME , LAST_CALL_ET , PDML_ENABLED , FAILOVER_TYPE
, FAILOVER_METHOD , FAILED_OVER, RESOURCE_CONSUMER_GROUP, PDML_STATUS,
PDDL_STATUS, PQ_STATUS, CURRENT_QUEUE_DURATION, CLIENT_IDENTIFIER,
BLOCKING_SESSION_STATUS, BLOCKING_INSTANCE, BLOCKING_SESSION,
FINAL_BLOCKING_SESSION_STATUS, FINAL_BLOCKING_INSTANCE,
FINAL_BLOCKING_SESSION, SEQ#, EVENT#,EVENT,P1TEXT,P1,P1RAW,P2TEXT,P2,P2RAW,
P3TEXT,P3,P3RAW,WAIT_CLASS_ID, WAIT_CLASS#,WAIT_CLASS,WAIT_TIME,
SECONDS_IN_WAIT,STATE,WAIT_TIME_MICRO,TIME_REMAINING_MICRO,
TIME_SINCE_LAST_WAIT_MICRO,SERVICE_NAME, SQL_TRACE, SQL_TRACE_WAITS,
SQL_TRACE_BINDS, SQL_TRACE_PLAN_STATS, SESSION_EDITION_ID, CREATOR_ADDR,
CREATOR_SERIAL#, ECID
from
GV$SESSION where inst_id = USERENV(\'Instance\')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 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 1 0.01 0.01 0 0 0 0
Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
********************************************************************************
SQL ID: gzp9y42kcbx6m Plan Hash: 644658511
select sid,serial#,username
from
v$session where username=\'SCOTT\'
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 0 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 0 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 NESTED LOOPS (cr=0 pr=0 pw=0 time=231 us cost=0 size=121 card=1)
1 1 1 NESTED LOOPS (cr=0 pr=0 pw=0 time=2330 us cost=0 size=108 card=1)
1 1 1 FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=1981 us cost=0 size=82 card=1)
1 1 1 FIXED TABLE FIXED INDEX X$KSLWT (ind:1) (cr=0 pr=0 pw=0 time=339 us cost=0 size=26 card=1)
1 1 1 FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=2 us cost=0 size=13 card=1)
********************************************************************************
SQL ID: 3nkd3g3ju5ph1 Plan Hash: 2853959010
select obj#,type#,ctime,mtime,stime, status, dataobj#, flags, oid$, spare1,
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 4 0.00 0.00 0 0 0 0
Fetch 4 0.00 0.00 0 16 0 4
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 9 0.00 0.00 0 16 0 4
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=4 pr=0 pw=0 time=145 us cost=4 size=82 card=1)
1 1 1 INDEX RANGE SCAN I_OBJ2 (cr=3 pr=0 pw=0 time=109 us cost=3 size=0 card=1)(object id 37)
********************************************************************************
SQL ID: 7ng34ruy5awxq Plan Hash: 2542797530
select i.obj#,i.ts#,i.file#,i.block#,i.intcols,i.type#,i.flags,i.property,
i.pctfree$,i.initrans,i.maxtrans,i.blevel,i.leafcnt,i.distkey,i.lblkkey,
i.dblkkey,i.clufac,i.cols,i.analyzetime,i.samplesize,i.dataobj#,
nvl(i.degree,1),nvl(i.instances,1),i.rowcnt,mod(i.pctthres$,256),
i.indmethod#,i.trunccnt,nvl(c.unicols,0),nvl(c.deferrable#+c.valid#,0),
nvl(i.spare1,i.intcols),i.spare4,i.spare2,i.spare6,decode(i.pctthres$,null,
null,mod(trunc(i.pctthres$/256),256)),ist.cachedblk,ist.cachehit,
ist.logicalread
from
ind$ i, ind_stats$ ist, (select enabled, min(cols) unicols,
min(to_number(bitand(defer,1))) deferrable#,min(to_number(bitand(defer,4)))
valid# from cdef$ where obj#=:1 and enabled > 1 group by enabled) c where
i.obj#=c.enabled(+) and i.obj# = ist.obj#(+) and i.bo#=:1 order by i.obj#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 5 0.00 0.00 0 0 0 0
Fetch 10 0.00 0.00 0 36 0 5
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 16 0.00 0.00 0 36 0 5
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT ORDER BY (cr=8 pr=0 pw=0 time=644 us cost=7 size=372 card=2)
1 1 1 HASH JOIN OUTER (cr=8 pr=0 pw=0 time=608 us cost=6 size=372 card=2)
1 1 1 NESTED LOOPS OUTER (cr=5 pr=0 pw=0 time=177 us cost=2 size=286 card=2)
1 1 1 TABLE ACCESS CLUSTER IND$ (cr=4 pr=0 pw=0 time=100 us cost=2 size=182 card=2)
1 1 1 INDEX UNIQUE SCAN I_OBJ# (cr=2 pr=0 pw=0 time=38 us cost=1 size=0 card=1)(object id 3)
0 0 0 TABLE ACCESS BY INDEX ROWID IND_STATS$ (cr=1 pr=0 pw=0 time=71 us cost=0 size=52 card=1)
0 0 0 INDEX UNIQUE SCAN I_IND_STATS$_OBJ# (cr=1 pr=0 pw=0 time=66 us cost=0 size=0 card=1)(object id 433)
0 0 0 VIEW (cr=3 pr=0 pw=0 time=202 us cost=3 size=43 card=1)
0 0 0 SORT GROUP BY (cr=3 pr=0 pw=0 time=200 us cost=3 size=15 card=1)
0 0 0 TABLE ACCESS CLUSTER CDEF$ (cr=3 pr=0 pw=0 time=149 us cost=2 size=15 card=1)
1 1 1 INDEX UNIQUE SCAN I_COBJ# (cr=2 pr=0 pw=0 time=43 us cost=1 size=0 card=1)(object id 30)
********************************************************************************
SQL ID: 5n1fs4m2n2y0r Plan Hash: 299250003
select pos#,intcol#,col#,spare1,bo#,spare2,spare3
from
icol$ where obj#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 5 0.00 0.00 0 0 0 0
Fetch 20 0.00 0.00 0 40 0 15
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 26 0.00 0.00 0 40 0 15
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 TABLE ACCESS BY INDEX ROWID ICOL$ (cr=4 pr=0 pw=0 time=52 us cost=2 size=54 card=2)
1 1 1 INDEX RANGE SCAN I_ICOL1 (cr=3 pr=0 pw=0 time=48 us cost=1 size=0 card=2)(object id 42)
********************************************************************************
SQL ID: 83taa7kaw59c1 Plan Hash: 3765558045
select name,intcol#,segcol#,type#,length,nvl(precision#,0),decode(type#,2,
nvl(scale,-127/*MAXSB1MINAL*/),178,scale,179,scale,180,scale,181,scale,182,
scale,183,scale,231,scale,0),null$,fixedstorage,nvl(deflength,0),default$,
rowid,col#,property, nvl(charsetid,0),nvl(charsetform,0),spare1,spare2,
nvl(spare3,0)
from
col$ where obj#=:1 order by intcol#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 5 0.00 0.00 0 0 0 0
Fetch 31 0.00 0.00 0 16 0 26
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 37 0.00 0.00 0 16 0 26
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
4 4 4 SORT ORDER BY (cr=4 pr=0 pw=0 time=54 us cost=3 size=708 card=12)
4 4 4 TABLE ACCESS CLUSTER COL$ (cr=4 pr=0 pw=0 time=27 us cost=2 size=708 card=12)
1 1 1 INDEX UNIQUE SCAN I_OBJ# (cr=2 pr=0 pw=0 time=9 us cost=1 size=0 card=1)(object id 3)
********************************************************************************
SQL ID: 3ktacv9r56b51 Plan Hash: 4184428695
select owner#,name,namespace,remoteowner,linkname,p_timestamp,p_obj#,
nvl(property,0),subname,type#,d_attrs
from
dependency$ d, obj$ o where d_obj#=:1 and p_obj#=obj#(+) order by order#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 12 0.00 0.00 0 27 0 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 16 0.00 0.00 0 27 0 10
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 2
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 5 9 SORT ORDER BY (cr=14 pr=0 pw=0 time=304 us cost=11 size=330 card=3)
1 5 9 NESTED LOOPS OUTER (cr=14 pr=0 pw=0 time=297 us cost=10 size=330 card=3)
1 5 9 TABLE ACCESS BY INDEX ROWID DEPENDENCY$ (cr=4 pr=0 pw=0 time=80 us cost=4 size=84 card=3)
1 5 9 INDEX RANGE SCAN I_DEPENDENCY1 (cr=3 pr=0 pw=0 time=51 us cost=3 size=0 card=3)(object id 106)
1 3 5 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=10 pr=0 pw=0 time=157 us cost=2 size=82 card=1)
1 3 5 INDEX RANGE SCAN I_OBJ1 (cr=6 pr=0 pw=0 time=97 us cost=1 size=0 card=1)(object id 36)
********************************************************************************
SQL ID: 87gaftwrm2h68 Plan Hash: 1218588913
select o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname
from
obj$ o where o.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 1 0.00 0.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 3 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=0 pw=0 time=38 us cost=3 size=82 card=1)
1 1 1 INDEX RANGE SCAN I_OBJ1 (cr=2 pr=0 pw=0 time=31 us cost=2 size=0 card=1)(object id 36)
********************************************************************************
SQL ID: ga9j9xk5cy9s0 Plan Hash: 1697022209
select /*+ index(idl_sb4$ i_idl_sb41) +*/ piece#,length,piece
from
idl_sb4$ where obj#=:1 and part=:2 and version=:3 order by piece#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 7 0.00 0.00 1 18 0 4
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 13 0.00 0.00 1 18 0 4
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 3
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
2 1 2 TABLE ACCESS BY INDEX ROWID IDL_SB4$ (cr=5 pr=0 pw=0 time=205 us cost=3 size=19 card=1)
2 1 2 INDEX RANGE SCAN I_IDL_SB41 (cr=3 pr=0 pw=0 time=36 us cost=2 size=0 card=1)(object id 239)
********************************************************************************
SQL ID: cvn54b7yz0s8u Plan Hash: 3246118364
select /*+ index(idl_ub1$ i_idl_ub11) +*/ piece#,length,piece
from
idl_ub1$ where obj#=:1 and part=:2 and version=:3 order by piece#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 6 0.00 0.00 3 20 0 5
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 12 0.00 0.00 3 20 0 5
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 3
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 2 2 TABLE ACCESS BY INDEX ROWID IDL_UB1$ (cr=5 pr=1 pw=0 time=160 us cost=3 size=44 card=2)
1 2 2 INDEX RANGE SCAN I_IDL_UB11 (cr=3 pr=0 pw=0 time=30 us cost=2 size=0 card=2)(object id 236)
********************************************************************************
SQL ID: c6awqs517jpj0 Plan Hash: 1319326155
select /*+ index(idl_char$ i_idl_char1) +*/ piece#,length,piece
from
idl_char$ where obj#=:1 and part=:2 and version=:3 order by piece#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 4 0.00 0.01 1 9 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10 0.00 0.01 1 9 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 3
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 0 1 TABLE ACCESS BY INDEX ROWID IDL_CHAR$ (cr=3 pr=0 pw=0 time=3509 us cost=3 size=21 card=1)
1 0 1 INDEX RANGE SCAN I_IDL_CHAR1 (cr=2 pr=0 pw=0 time=30 us cost=2 size=0 card=1)(object id 237)
********************************************************************************
SQL ID: 39m4sx9k63ba2 Plan Hash: 2317816222
select /*+ index(idl_ub2$ i_idl_ub21) +*/ piece#,length,piece
from
idl_ub2$ where obj#=:1 and part=:2 and version=:3 order by piece#
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 4 0.00 0.00 1 11 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10 0.00 0.01 1 11 0 2
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 3
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
2 1 2 TABLE ACCESS BY INDEX ROWID IDL_UB2$ (cr=3 pr=0 pw=0 time=2460 us cost=3 size=40 card=2)
2 1 2 INDEX RANGE SCAN I_IDL_UB21 (cr=2 pr=0 pw=0 time=29 us cost=2 size=0 card=2)(object id 238)
********************************************************************************
SQL ID: 83sp8xb9ytgkv Plan Hash: 0
BEGIN dbms_system.set_ev(21,2615,10046,12,\'SCOTT\'); END;
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 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
********************************************************************************
SQL ID: b1wc53ddd6h3p Plan Hash: 1637390370
select audit$,options
from
procedure$ where obj#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 6 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 6 0 2
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 2
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 TABLE ACCESS BY INDEX ROWID PROCEDURE$ (cr=3 pr=0 pw=0 time=46 us cost=2 size=47 card=1)
1 1 1 INDEX UNIQUE SCAN I_PROCEDURE1 (cr=2 pr=0 pw=0 time=26 us cost=1 size=0 card=1)(object id 231)
********************************************************************************
SQL ID: 8swypbbr0m372 Plan Hash: 893970548
select order#,columns,types
from
access$ where d_obj#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 9 0.00 0.00 0 18 0 7
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 13 0.00 0.00 0 18 0 7
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Number of plan statistics captured: 2
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
7 4 7 TABLE ACCESS BY INDEX ROWID ACCESS$ (cr=9 pr=0 pw=0 time=56 us cost=3 size=161 card=7)
7 4 7 INDEX RANGE SCAN I_ACCESS1 (cr=6 pr=0 pw=0 time=48 us cost=2 size=0 card=7)(object id 108)
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.00 0.00 0 0 0 0
Execute 4 0.01 0.01 0 0 0 1
Fetch 4 0.01 0.01 0 0 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11 0.02 0.03 0 0 0 3
Misses in library cache during parse: 3
Misses in library cache during execute: 2
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 27 0.03 0.03 0 0 0 0
Execute 61 0.01 0.02 0 0 0 0
Fetch 133 0.01 0.02 6 286 0 103
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 221 0.06 0.08 6 286 0 103
Misses in library cache during parse: 16
Misses in library cache during execute: 15
4 user SQL statements in session.
27 internal SQL statements in session.
31 SQL statements in session.
********************************************************************************
Trace file: HOEGH_ora_16427.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
4 user SQL statements in trace file.
27 internal SQL statements in trace file.
31 SQL statements in trace file.
20 unique SQL statements in trace file.
534 lines in trace file.
337 elapsed seconds in trace file.
评论暂时关闭