Sql_trace及10046事件

Sql_trace及10046事件

翔之天空 2016-03-07 14:16:24 499 收藏
分类专栏: Oracle 优化处理 文章标签: sql_trace 10046
版权

Oracle 优化处理
专栏收录该内容
9 篇文章0 订阅
订阅专栏

一、sql_trace
1、设置sql_trace

查看当前是否开启trace状态
SQL> show parameter sql_trace;

NAME TYPE VALUE
----------------------------------------------- ------------------------------
sql_trace boolean FALSE



设置trace文件标示(易于寻找文件)
SQL> alter session set tracefile_identifier='test_1';

Session altered.



开启trace
SQL> alter session set sql_trace=true;

Session altered.



查询数据

SQL> select count(1) from dba_users;

COUNT(1)
----------

9


查找当前trace文件名的sql
SQL> SELECT d.VALUE || '/' || LOWER(RTRIM(i.INSTANCE, CHR(0))) || '_ora_'||
2 p.spid || '.trc'AS "trace_file_name"
3 FROM (SELECTp.spid
4 FROM v$mystatm, v$session s, v$process p
5 WHEREm.statistic# = 1
6 AND s.SID =m.SID
7 AND p.addr =s.paddr) p,
8 (SELECTt.INSTANCE
9 FROM v$threadt, v$parameter v
10 WHERE v.NAME = 'thread'
11 AND (v.VALUE = 0 ORt.thread# = TO_NUMBER(v.VALUE))) i,
12 (SELECT VALUE FROM v$parameterWHERE NAME = 'user_dump_dest') d;

trace_file_name
--------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_1.trc



关闭trace
SQL> alter session set sql_trace=false;

Session altered.


2、Tkprof工具
查看tkprof帮助:

[oracle@pri ~]$ tkprof

Usage: tkprof tracefile outputfile[explain= ] [table= ]

[print= ] [insert= ] [sys= ][sort= ]

table=schema.tablename Use'schema.tablename' with 'explain=' option.

explain=user/password Connectto ORACLE and issue EXPLAIN PLAN.

print=integer List only thefirst 'integer' SQL statements.

aggregate=yes|no

insert=filename List SQLstatements and data inside INSERT statements.

sys=no TKPROF does notlist SQL statements run as user SYS.

record=filename Recordnon-recursive statements found in the trace file.

waits=yes|no Record summaryfor any wait events found in the trace file.

sort=option Set of zero ormore of the following sort options:

prscnt number of times parse wascalled

prscpu cpu time parsing

prsela elapsed time parsing

prsdsk number of disk readsduring parse

prsqry number of buffers forconsistent read during parse

prscu number of buffers forcurrent read during parse

prsmis number of misses inlibrary cache during parse

execnt number of execute wascalled

execpu cpu time spent executing

exeela elapsed time executing

exedsk number of disk readsduring execute

exeqry number of buffers forconsistent read during execute

execu number of buffers forcurrent read during execute

exerow number of rows processedduring execute

exemis number of library cachemisses during execute

fchcnt number of times fetch wascalled

fchcpu cpu time spent fetching

fchela elapsed time fetching

fchdsk number of disk readsduring fetch

fchqry number of buffers forconsistent read during fetch

fchcu number of buffers forcurrent read during fetch

fchrow number of rows fetched

userid userid of user that parsed the cursor

 


3、查看tkprof格式化的trace文件
[oracle@pri ~]$ tkprof /u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_1.trc sys=no
output = test_1


TKPROF: Release 11.2.0.4.0 - Development onMon Mar 7 10:09:14 2016

Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.

 


[oracle@pri~]$ cat test_1.prf


TKPROF: Release 11.2.0.4.0 - Development onMon Mar 7 10:09:14 2016


Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.


Trace file:/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_1.trc
Sort options: default

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

count = number of times OCI procedurewas 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

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

OVERALL TOTALS FOR ALL NON-RECURSIVESTATEMENTS


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- -------------------- ----------
Parse 2 0.03 0.03 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 25 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 7 0.03 0.03 0 25 0 1


Misses in library cache during parse: 2
Misses in library cache during execute: 1

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- -------------------- ----------
Parse 14 0.02 0.02 0 0 0 0
Execute 91 0.03 0.04 0 0 0 0
Fetch 183 0.00 0.01 1 336 0 136
------- ------ -------- ---------- ---------- -------------------- ----------
total 288 0.06 0.08 1 336 0 136


Misses in library cache during parse: 14
Misses in library cache during execute: 14

 

3 user SQL statements in session.
15 internal SQL statements insession.
18 SQL statements in session.

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

Trace file:/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_1.trc
Trace file compatibility: 11.1.0.7
Sort options: default


1 session in tracefile.
3 user SQL statements in trace file.
15 internal SQL statements intrace file.
18 SQL statements in trace file.
18 unique SQL statements in tracefile.
553 lines in trace file.
30 elapsed seconds in trace file.

 

4、跟踪其他用户的trace
(这里测试TRACE_USER用户)


</pre><pre name="code" class="sql">创建测试用户及测试表
SQL> create user trace_user identified by 1;
User created.

SQL> grant connect,resource to trace_user;
Grant succeeded.

SQL> conn trace_user/1;
Connected.

SQL> create table t1(a int);
Table created.



查看TRACE_USER用户的SID, SERIAL#
SQL> select sid,serial#,username from v$session where username is not null;

SID SERIAL# USERNAME
---------- ----------------------------------------
41 41 TRACE_USER
45 83 SYS
50 15 SYS


开启trace
SQL> exec dbms_system.set_sql_trace_in_session(41,41,true);

PL/SQL procedure successfully completed.


查看tkprof格式化的trace文件
[oracle@pri ~]$ tkprof /u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826.trc sys=no

output = trace_user

TKPROF: Release 11.2.0.4.0 - Development onMon Mar 7 10:29:11 2016

Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.


[oracle@pri~]$ cat trace_user.prf


TKPROF: Release 11.2.0.4.0 - Development onMon Mar 7 10:29:11 2016

Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.

Trace file:/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826.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 forconsistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call

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

OVERALL TOTALS FOR ALL NON-RECURSIVESTATEMENTS


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

Misses in library cache during parse: 1
Misses in library cache during execute: 1

Elapsed times include waiting on followingevents:
Event waited on Times Max. Wait Total Waited

---------------------------------------- Waited ---------- ------------

SQL*Net message to client 5 0.00 0.00
SQL*Net message from client 5 24.77 48.19


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

4 user SQL statements in session.
0 internal SQL statements insession.
4 SQL statements in session.
********************************************************************************

Trace file: /u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826.trc
Trace file compatibility: 11.1.0.7
Sort options: default

1 session in tracefile.
4 user SQL statements in trace file.
0 internal SQL statements intrace file.
4 SQL statements in trace file.
4 unique SQL statements in tracefile.
93 lines in trace file.
36 elapsed seconds in trace file.

 

二、10046事件
1、设置10046事件
SQL> create table test_trace_10046 as select * from dba_objects;

Table created.



SQL> alter session set tracefile_identifier='test_trace_10046';

Session altered.



SQL> alter session set events '10046 trace name context forever,level 12';

Session altered.



SQL> select count(1) from test_trace_10046;

COUNT(1)
----------
13982


SQL> alter session set events '10046 trace name context off';

Session altered.

 

2、查看Trace文件
[oracle@pri trace]$ cat /u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_trace_10046.trc

 

Trace file/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_trace_10046.trc

Oracle Database 11g Enterprise Edition Release11.2.0.4.0 - 64bit Production

With the Partitioning, OLAP, Data Miningand Real Application Testing options

ORACLE_HOME =/u01/app/oracle/product/11.2.0/dbhome_1

System name: Linux

Node name: pri

Release: 2.6.32-279.el6.x86_64

Version: #1 SMP Wed Jun 13 18:24:36 EDT 2012

Machine: x86_64

VM name: VMWare Version: 6

Instance name: orclpri

Redo thread mounted by this instance: 1

Oracle process number: 27

Unix process pid: 19826, image: oracle@pri(TNS V1-V3)

 

 

*** 2016-03-07 11:03:30.149

*** SESSION ID:(50.15) 2016-03-0711:03:30.149

*** CLIENT ID:() 2016-03-07 11:03:30.149

*** SERVICE NAME:(SYS$USERS) 2016-03-0711:03:30.149

*** MODULE NAME:(sqlplus@pri (TNS V1-V3))2016-03-07 11:03:30.149

*** ACTION NAME:() 2016-03-07 11:03:30.149

 

 

*** TRACE CONTINUED FROM FILE/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_10046.trc***

 

WAIT #140501453045952: nam='SQL*Net messageto client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1457319810148493

 

*** 2016-03-07 11:03:41.479

WAIT #140501453045952: nam='SQL*Net messagefrom client' ela= 11329805 driver id=1650815232 #bytes=1 p3=0 obj#=-1tim=1457319821478968

CLOSE#140501453045952:c=0,e=15,dep=0,type=1,tim=1457319821479163

=====================

PARSING IN CURSOR #140501455982944 len=210dep=2 uid=0 oct=3 lid=0 tim=1457319821482493 hv=864012087 ad='8b72b708'sqlid='96g93hntrzjtr'

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$ whereobj#=:1 and intcol#=:2

END OF STMT

BINDS #140501455982944:

Bind#0

oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

oacflg=00 fl2=0001 frm=00 csi=00 siz=48 off=0

kxsbbbfp=7fc90b5fb678 bln=22 avl=04 flg=05

value=14268

Bind#1

oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

oacflg=00 fl2=0001 frm=00 csi=00 siz=0 off=24

kxsbbbfp=7fc90b5fb690 bln=22 avl=03 flg=01

value=1001

EXEC#140501455982944:c=1000,e=343,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1457319821482792

FETCH#140501455982944:c=0,e=32,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1457319821482856

CLOSE#140501455982944:c=0,e=3,dep=2,type=3,tim=1457319821482912

=====================

PARSING IN CURSOR #140501454100952 len=435dep=1 uid=0 oct=3 lid=0 tim=1457319821483569 hv=3793683776 ad='91455b28'sqlid='a465k4rj1y1a0'

SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWSIGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB)opt_param('parallel_execution_enabled', 'false') NO_PARALLEL_INDEX(SAMPLESUB)NO_SQL_TUNE */ NVL(SUM(C1),0), NVL(SUM(C2),0) FROM (SELECT /*+NO_PARALLEL("TEST_TRACE_10046") FULL("TEST_TRACE_10046")NO_PARALLEL_INDEX("TEST_TRACE_10046") */ 1 AS C1, 1 AS C2 FROM"SYS"."TEST_TRACE_10046" SAMPLE BLOCK (34.426230 , 1) SEED(1) "TEST_TRACE_10046") SAMPLESUB

END OF STMT

PARSE#140501454100952:c=1999,e=2612,p=0,cr=2,cu=0,mis=1,r=0,dep=1,og=1,plh=2235872047,tim=1457319821483567

EXEC #140501454100952:c=0,e=40,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=2235872047,tim=1457319821483809

WAIT #140501454100952: nam='db filescattered read' ela= 63 file#=1 block#=35140 blocks=4 obj#=14268tim=1457319821484193

WAIT #140501454100952: nam='db filescattered read' ela= 72 file#=1 block#=35145 blocks=7 obj#=14268tim=1457319821487994

WAIT #140501454100952: nam='db filesequential read' ela= 30 file#=1 block#=35156 blocks=1 obj#=14268tim=1457319821488364

WAIT #140501454100952: nam='db filescattered read' ela= 22 file#=1 block#=35163 blocks=5 obj#=14268tim=1457319821488500

WAIT #140501454100952: nam='db filescattered read' ela= 27 file#=1 block#=35170 blocks=6 obj#=14268tim=1457319821488957

WAIT #140501454100952: nam='db filescattered read' ela= 27 file#=1 block#=35177 blocks=7 obj#=14268tim=1457319821489318

WAIT #140501454100952: nam='db filescattered read' ela= 34 file#=1 block#=35186 blocks=6 obj#=14268tim=1457319821489683

WAIT #140501454100952: nam='db filescattered read' ela= 20 file#=1 block#=35195 blocks=5 obj#=14268 tim=1457319821489920

WAIT #140501454100952: nam='db filesequential read' ela= 24 file#=1 block#=35333 blocks=1 obj#=14268tim=1457319821490113

WAIT #140501454100952: nam='db filescattered read' ela= 37 file#=1 block#=35344 blocks=8 obj#=14268 tim=1457319821490375

WAIT #140501454100952: nam='db filesequential read' ela= 94 file#=1 block#=35358 blocks=1 obj#=14268tim=1457319821490666

WAIT #140501454100952: nam='db filescattered read' ela= 29 file#=1 block#=35360 blocks=8 obj#=14268tim=1457319821490866

WAIT #140501454100952: nam='db filescattered read' ela= 28 file#=1 block#=35368 blocks=8 obj#=14268tim=1457319821491119

WAIT #140501454100952: nam='db filescattered read' ela= 21 file#=1 block#=35379 blocks=5 obj#=14268tim=1457319821491465

WAIT #140501454100952: nam='db filescattered read' ela= 30 file#=1 block#=35384 blocks=8 obj#=14268tim=1457319821491893

WAIT #140501454100952: nam='db filescattered read' ela= 399 file#=1 block#=35461 blocks=51 obj#=14268tim=1457319821492941

FETCH#140501454100952:c=6999,e=10101,p=131,cr=56,cu=0,mis=0,r=1,dep=1,og=1,plh=2235872047,tim=1457319821493938

STAT #140501454100952 id=1 cnt=1 pid=0pos=1 obj=0 op='SORT AGGREGATE (cr=56 pr=131 pw=0 time=10087 us)'

STAT #140501454100952 id=2 cnt=3938 pid=1pos=1 obj=14268 op='TABLE ACCESS SAMPLE TEST_TRACE_10046 (cr=56 pr=131 pw=0time=931 us cost=19 size=61752 card=5146)'

CLOSE#140501454100952:c=0,e=12,dep=1,type=0,tim=1457319821494179

=====================

PARSING IN CURSOR #140501453052968 len=37dep=0 uid=0 oct=3 lid=0 tim=1457319821494916 hv=1992023742 ad='8b7a2190'sqlid='d3w3u31vbrrpy'

select count(1) from test_trace_10046

END OF STMT

PARSE#140501453052968:c=12998,e=15676,p=131,cr=59,cu=0,mis=1,r=0,dep=0,og=1,plh=1377150037,tim=1457319821494914

EXEC#140501453052968:c=0,e=48,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1377150037,tim=1457319821495061

WAIT #140501453052968: nam='SQL*Net messageto client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1tim=1457319821495128

WAIT #140501453052968: nam='db filescattered read' ela= 18 file#=1 block#=35137 blocks=3 obj#=14268tim=1457319821495296

WAIT #140501453052968: nam='db filesequential read' ela= 29 file#=1 block#=35144 blocks=1 obj#=14268tim=1457319821495704

WAIT #140501453052968: nam='db file scatteredread' ela= 17 file#=1 block#=35152 blocks=4 obj#=14268 tim=1457319821495950

WAIT #140501453052968: nam='db filescattered read' ela= 16 file#=1 block#=35157 blocks=3 obj#=14268tim=1457319821496189

WAIT #140501453052968: nam='db filescattered read' ela= 14 file#=1 block#=35160 blocks=3 obj#=14268tim=1457319821496369

WAIT #140501453052968: nam='db filescattered read' ela= 67 file#=1 block#=35168 blocks=2 obj#=14268tim=1457319821496642

WAIT #140501453052968: nam='db filesequential read' ela= 26 file#=1 block#=35176 blocks=1 obj#=14268tim=1457319821496887

WAIT #140501453052968: nam='db filescattered read' ela= 13 file#=1 block#=35184 blocks=2 obj#=14268tim=1457319821497084

WAIT #140501453052968: nam='db filescattered read' ela= 16 file#=1 block#=35192 blocks=3 obj#=14268tim=1457319821497405

WAIT #140501453052968: nam='db filescattered read' ela= 21 file#=1 block#=35328 blocks=5 obj#=14268tim=1457319821497696

WAIT #140501453052968: nam='db filescattered read' ela= 12 file#=1 block#=35334 blocks=2 obj#=14268tim=1457319821497874

WAIT #140501453052968: nam='db filescattered read' ela= 30 file#=1 block#=35336 blocks=8 obj#=14268tim=1457319821498071

WAIT #140501453052968: nam='db filescattered read' ela= 23 file#=1 block#=35352 blocks=6 obj#=14268tim=1457319821498467

WAIT #140501453052968: nam='db filesequential read' ela= 26 file#=1 block#=35359 blocks=1 obj#=14268tim=1457319821498782

WAIT #140501453052968: nam='db filescattered read' ela= 16 file#=1 block#=35376 blocks=3 obj#=14268 tim=1457319821499082

WAIT #140501453052968: nam='db filescattered read' ela= 30 file#=1 block#=35456 blocks=5 obj#=14268tim=1457319821499520

FETCH#140501453052968:c=4000,e=5181,p=52,cr=187,cu=0,mis=0,r=1,dep=0,og=1,plh=1377150037,tim=1457319821500352

STAT #140501453052968 id=1 cnt=1 pid=0pos=1 obj=0 op='SORT AGGREGATE (cr=187 pr=52 pw=0 time=5173 us)'

STAT #140501453052968 id=2 cnt=13983 pid=1pos=1 obj=14268 op='TABLE ACCESS FULL TEST_TRACE_10046 (cr=187 pr=52 pw=0time=3915 us cost=51 size=0 card=11439)'

WAIT #140501453052968: nam='SQL*Net messagefrom client' ela= 281 driver id=1650815232 #bytes=1 p3=0 obj#=14268tim=1457319821501039

FETCH#140501453052968:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1377150037,tim=1457319821501116

WAIT #140501453052968: nam='SQL*Net messageto client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=14268tim=1457319821501157

 

*** 2016-03-07 11:03:47.104

WAIT #140501453052968: nam='SQL*Net messagefrom client' ela= 5603509 driver id=1650815232 #bytes=1 p3=0 obj#=14268 tim=1457319827104693

CLOSE#140501453052968:c=0,e=20,dep=0,type=0,tim=1457319827104875

PARSE#140501456027464:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1457319827104989

EXEC#140501456027464:c=1000,e=859,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1457319827105885

 

 

3、查看Tkprof格式化的trace文件
[oracle@pri ~]$ tkprof/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_trace_10046.trc

output = test

 

TKPROF: Release 11.2.0.4.0 - Development onMon Mar 7 12:07:31 2016

 

Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.

 

 

[oracle@pri~]$ cat test.prf

 

TKPROF: Release 11.2.0.4.0 - Development onMon Mar 7 12:07:31 2016

 

Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.

 

Trace file:/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_trace_10046.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: 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 0 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 2 0.00 0.00 0 2 0 0

 

Misses in library cache during parse: 0

Optimizer mode: RULE

Parsing user id: SYS (recursive depth: 2)

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

 

SQL ID: a465k4rj1y1a0 Plan Hash: 2235872047

 

SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWSIGNORE_WHERE_CLAUSE

NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')

NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),0),NVL(SUM(C2),0)

FROM

(SELECT /*+NO_PARALLEL("TEST_TRACE_10046") FULL("TEST_TRACE_10046")

NO_PARALLEL_INDEX("TEST_TRACE_10046") */ 1 AS C1, 1 AS C2 FROM

"SYS"."TEST_TRACE_10046" SAMPLE BLOCK (34.426230 ,1) SEED (1)

"TEST_TRACE_10046") SAMPLESUB

 

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- -------------------- ----------

Parse 1 0.00 0.00 0 2 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 1 0.00 0.01 131 56 0 1

------- ------ -------- ---------- ---------- -------------------- ----------

total 3 0.00 0.01 131 58 0 1

 

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

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 SORT AGGREGATE (cr=56 pr=131 pw=0 time=10087 us)

3938 3938 3938 TABLE ACCESS SAMPLE TEST_TRACE_10046 (cr=56 pr=131 pw=0 time=931 uscost=19 size=61752 card=5146)

 

 

Elapsed times include waiting on followingevents:

Event waited on Times Max. Wait Total Waited

---------------------------------------- Waited ---------- ------------

dbfile scattered read 13 0.00 0.00

dbfile sequential read 3 0.00 0.00

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

 

SQL ID: d3w3u31vbrrpy Plan Hash: 1377150037

 

select count(1)

from

test_trace_10046

 

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- -------------------- ----------

Parse 1 0.00 0.00 0 1 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 2 0.00 0.00 52 187 0 1

------- ------ -------- ---------- ---------- -------------------- ----------

total 4 0.00 0.00 52 188 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 SORT AGGREGATE (cr=187 pr=52 pw=0 time=5173 us)

13983 13983 13983 TABLE ACCESS FULL TEST_TRACE_10046 (cr=187 pr=52 pw=0 time=3915 us cost=51size=0 card=11439)

 

 

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

dbfile scattered read 13 0.00 0.00

dbfile sequential read 3 0.00 0.00

SQL*Net message from client 2 5.60 5.60

 

 

 

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

 

OVERALL TOTALS FOR ALL NON-RECURSIVESTATEMENTS

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- -------------------- ----------

Parse 1 0.00 0.00 0 1 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 2 0.00 0.00 52 187 0 1

------- ------ -------- ---------- ---------- -------------------- ----------

total 4 0.00 0.00 52 188 0 1

 

Misses in library cache during parse: 1

 

Elapsed times include waiting on followingevents:

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 11.32 16.93

dbfile scattered read 13 0.00 0.00

dbfile sequential read 3 0.00 0.00

 

 

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- -------------------- ----------

Parse 1 0.00 0.00 0 2 0 0

Execute 2 0.00 0.00 0 0 0 0

Fetch 2 0.00 0.01 131 58 0 1

------- ------ -------- ---------- ---------- -------------------- ----------

total 5 0.00 0.01 131 60 0 1

 

Misses in library cache during parse: 1

 

Elapsed times include waiting on followingevents:

Event waited on Times Max. Wait Total Waited

---------------------------------------- Waited ---------- ------------

dbfile scattered read 13 0.00 0.00

dbfile sequential read 3 0.00 0.00

 

1 user SQL statements in session.

2 internal SQL statements insession.

3 SQL statements in session.

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

Trace file:/u01/app/oracle/diag/rdbms/orclpri/orclpri/trace/orclpri_ora_19826_test_trace_10046.trc

Trace file compatibility: 11.1.0.7

Sort options: default

 

1 session in tracefile.

1 user SQL statements in trace file.

2 internal SQL statements intrace file.

3 SQL statements in trace file.

3 unique SQL statements in tracefile.

110 lines in trace file.

5 elapsed seconds in trace file.

 


————————————————
版权声明:本文为CSDN博主「翔之天空」的原创文章,遵循CC 4.0 BY-SA版权协议,转载请附上原文出处链接及本声明。
原文链接:https://blog.csdn.net/fly43108622/article/details/50818867

posted @ 2021-11-23 00:23  耀阳居士  阅读(128)  评论(0编辑  收藏  举报