一.Consistentgets 说明

我们使用autotrace 查看执行计划和统计信息时,会显示类似如下信息:

 

0  recursive calls   :递归调用。一般原因:dictionary cache未命中;动态存储扩展;PL/SQL语句

         0  db block gets    :bufer中读取的block数量,用于insert,update,delete,selectfor update

    174530  consistent gets   :这里是一致读次数(一个block可能会被读多次),bufer中读取的用于查询(除掉select forupdate)的block数量。

                  --db blocksgets+consistent gets= logical read

          0 physical reads    :从磁盘上读取的block数量

          0 redo size      :bytes,写到redo logs的数据量

    3546854 bytes sent via SQL*Net to client

      60244 bytes received via SQL*Net from client

       5433 SQL*Net roundtrips to/from client

          0 sorts (memory)    :内存排序次数

          0 sorts (disk)     :磁盘排序次数;与sort_area_size有关

      81467 rows processed

 

 

官网对consistent gets 的解释:

consistent gets:Number of times a consistent read wasrequested for a block.

 

    通常我们执行SQL查询时涉及的每一block都是Consistent Read, 只是有些CR(Consistent Read)需要使用undo 来进行构造, 大部分CR(Consistent Read)并不涉及到undo block的读.

      还有就是每次读这个block都是一次CR(可能每个block上有多个数据row), 也就是如果某个block被读了10次, 系统会记录10个Consistent Read.

 

简单的说:

       consistentgets : 通过不带for update的select 读的blocks.

       dbblock gets : 通过update/delete/selectfor update读的blocks.

 

db block gets + consistent gets = 整个逻辑读。

 

二.测试

2.1 测试环境

OS: Oracle linux 6.1

DB: Oracle 11.2.0.3

2.2 对比Consistent gets

SQL> select count(1) from dave;

 

 COUNT(1)

----------

  1164176

 

SQL> create index idx_dave_objid ondave(object_id);

 

Index created.

 

SQL> execdbms_stats.gather_table_stats('sys','dave',cascade=>true);

 

PL/SQL procedure successfully completed.

 

SQL> set tim on timing on

08:20:01 SQL> set autot trace exp stat;

08:20:16 SQL> select * from dave whereobject_id=10;

 

16 rows selected.

 

Elapsed: 00:00:00.13

 

Execution Plan

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

Plan hash value: 3358514785

 

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

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

 

| Id | Operation                   | Name           | Rows  | Bytes | Cost (%CP

U)| Time    |

 

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

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

 

|   0| SELECT STATEMENT            |                |    16 | 1552 |    19   (

0)| 00:00:01 |

 

|   1|  TABLE ACCESS BY INDEX ROWID| DAVE           |   16 |  1552 |    19  (

0)| 00:00:01 |

 

|*  2|   INDEX RANGE SCAN          | IDX_DAVE_OBJID |    16 |      |     3   (

0)| 00:00:01 |

 

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

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

 

 

Predicate Information (identified byoperation id):

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

 

   2- access("OBJECT_ID"=10)

 

 

Statistics

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

         15 recursive calls

         0  db block gets

         63 consistent gets

         0  physical reads

         0  redo size

      3043  bytes sent via SQL*Net toclient

       534  bytes received via SQL*Netfrom client

         3  SQL*Net roundtrips to/fromclient

         0  sorts (memory)

         0  sorts (disk)

        16  rows processed

 

08:20:23 SQL> set lin 120

08:20:43 SQL> /

 

16 rows selected.

 

Elapsed: 00:00:00.02

 

Execution Plan

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

Plan hash value: 3358514785

 

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

| Id | Operation                   |Name           | Rows  | Bytes | Cost (%CPU)| Time     |

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

|   0| SELECT STATEMENT            |                |    16 | 1552 |    19   (0)| 00:00:01 |

|   1|  TABLE ACCESS BY INDEX ROWID| DAVE           |   16 |  1552 |    19  (0)| 00:00:01 |

|*  2|   INDEX RANGE SCAN          | IDX_DAVE_OBJID |    16 |      |     3   (0)| 00:00:01 |

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

 

Predicate Information (identified by operationid):

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

 

   2- access("OBJECT_ID"=10)

 

 

Statistics

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

         0  recursive calls

         0  db block gets

         21 consistent gets

         0  physical reads

         0  redo size

      3043  bytes sent via SQL*Net toclient

       534  bytes received via SQL*Netfrom client

         3  SQL*Net roundtrips to/fromclient

         0  sorts (memory)

         0  sorts (disk)

        16  rows processed

 

 

相同的SQL,第一次执行产生了63次consistent gets,第二次执行产生了21次consistent gets,减少2/3.

 

2.3 使用10046 跟踪SQL

 

--在跟踪之前,为避免缓存带来的影响,我们先刷新shared pool 和 db buffer。

 

08:27:31 SQL> alter system flushshared_pool;

 

System altered.

 

Elapsed: 00:00:00.21

08:28:47 SQL> alter system flushbuffer_cache;

 

System altered.

 

Elapsed: 00:00:00.30

 

 

--使用10046 跟踪:

 

--第一次:

SQL> set tim on timing on

08:50:08 SQL> set autot trace stat

08:50:16 SQL> oradebug setmypid

Statement processed.

08:50:20 SQL> alter session set tracefile_identifier='dave1';

 

Session altered.

 

Elapsed: 00:00:00.01

08:50:26 SQL> oradebug event 10046 tracename context forever,level 12;

Statement processed.

08:50:31 SQL> select * from dave whereobject_id=10;

 

16 rows selected.

 

Elapsed: 00:00:00.07

 

Statistics

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

        40  recursive calls

         0  db block gets

         94 consistent gets

        26  physical reads

         0  redo size

      1959  bytes sent via SQL*Net toclient

       534  bytes received via SQL*Netfrom client

         3  SQL*Net roundtrips to/fromclient

         4  sorts (memory)

         0  sorts (disk)

        16  rows processed

 

08:50:36 SQL> oradebug event 10046 tracename context off;

Statement processed.

08:50:42 SQL> oradebug tracefile_name

/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave1.trc

08:50:45 SQL>

 

--第二次:

 

08:50:45 SQL> alter session settracefile_identifier='dave2';       

 

Session altered.

 

Elapsed: 00:00:00.01

08:51:34 SQL> oradebug event 10046 tracename context forever,level 12;

Statement processed.

08:51:40 SQL> select * from dave whereobject_id=10;

 

16 rows selected.

 

Elapsed: 00:00:00.01

 

Statistics

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

         0  recursive calls

         0  db block gets

         21 consistent gets

         0  physical reads

         0  redo size

      1959  bytes sent via SQL*Net toclient

       534  bytes received via SQL*Netfrom client

         3  SQL*Net roundtrips to/fromclient

         0  sorts (memory)

         0  sorts (disk)

        16  rows processed

 

08:51:45 SQL> oradebug event 10046 tracename context off;

Statement processed.

08:51:52 SQL> oradebug tracefile_name

/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave2.trc

 

第一次执行: 产生94个consistent gets,trace file:dave_ora_9774_dave1.trc

第二次执行: 产生21个consistentgets,trace file:dave_ora_9774_dave2.trc

 

2.4 使用tkprof 格式化trace file

1. 第一次的trace file:

[oracle@dave ~]$ tkprof /u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave1.trc/u01/dave1.trc

 

TKPROF: Release 11.2.0.3.0 - Development onWed Sep 12 08:56:59 2012

 

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

 

 

2. 第二次的trace file:

[oracle@dave ~]$ tkprof/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave2.trc/u01/dave2.trc

 

TKPROF: Release 11.2.0.3.0 - Development onWed Sep 12 08:57:29 2012

 

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

 

2.5 对比tracefile

 

1.   trace 1

 

OVERALLTOTALS FOR ALL NON-RECURSIVE STATEMENTS

 

call    count       cpu    elapsed       disk     query    current        rows

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

Parse       1      0.01       0.02          7         73          0           0

Execute     1      0.00       0.00          0          0          0           0

Fetch       3      0.00       0.00         19         21          0          16

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

total       5      0.02       0.02         26         94          0          16

 

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                       5        0.00          0.00

 SQL*Net message from client                     5        4.55          4.55

  dbfile sequential read                        5        0.00          0.00

  dbfile parallel read                          1        0.00          0.00

 

 

OVERALLTOTALS FOR ALL RECURSIVE STATEMENTS

 

call    count       cpu    elapsed       disk     query    current        rows

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

Parse       0      0.00       0.00          0          0          0           0

Execute    22      0.00      0.00          0          0          0           0

Fetch      39      0.00       0.00          7         73          0          36

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

total      61      0.00       0.01          7         73          0          36

 

Misses in library cache during parse: 0

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        7        0.00          0.00

 

   1  user  SQL statements in session.

   7  internal SQL statements insession.

   8  SQL statements in session.

 

 

2. trace 2

 

OVERALLTOTALS 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       3      0.00       0.00          0         21          0          16

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

total       5      0.00       0.00          0         21          0          16

 

Misses in library cache during parse: 0

 

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        5.15          5.16

 

 

OVERALLTOTALS 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 insession.

   1  SQL statements in session.

 

以上关键部分已经黑体加粗。

 

3. 小结

NON-RECURSIVESTATEMENTS:

       指非递归的SQL,就是用户本身SQL消耗的实际资源情况。

 

RECURSIVESTATEMENTS

       指递归SQL,就是由用户SQL衍生出来的其他的SQL,这里通常指为了执行这条SQL语句,而对其进行语义分析,动态采样等操作。所以这部分的消耗是这些衍生SQL的消耗。

 

通过2个trace 对比,我们可以看出trace 1 比trace 2多出来的consistent gets就是用来parse的部分,其实际执行的消耗都是一样的。都是21.

 

在trace 1中,我们看到的解析产生的consistent get 是73. 其也是由很多部分组成,在开始的那部分信息,都是与解析相关。关于在解析的步骤和消耗,可以查看附录4.1 中完整的trace 。这里列一个计算结果:

       8+4+7+3+3+3+45= 73.

 

 

三.总结

       当我们第一次执行一条SQL语句时,Oracle 会其进行一个硬解析的操作,这个操作会额外的消耗一些资源,比如语法分析,语义分析,制定执行计划等操作。所以我们看到的consistent gets会比较大,第二次执行相同的SQL时,没有进行硬解析,所以产生的consistent gets就是我们SQL 实际的一个资源消耗。

 

 

四.附录:完整的TraceFile

4.1 dave1.trc

[oracle@dave u01]$ cat dave1.trc

 

TKPROF: Release 11.2.0.3.0 - Development onWed Sep 12 08:56:59 2012

 

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

 

Trace file:/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave1.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: 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

  andlinkname is null and subname is null

 

 

call    count       cpu    elapsed       disk     query    current        rows

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

Parse       0      0.00       0.00          0          0          0           0

Execute     2      0.00      0.00          0          0          0           0

Fetch       2      0.00       0.00          1          8          0           2

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

total       4      0.00       0.00          1          8          0           2

 

Misses in library cache during parse: 0

Optimizer mode: CHOOSE

Parsing user id: SYS   (recursive depth: 1)

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        1        0.00          0.00

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

 

SQL ID: 1gu8t96d0bdmu Plan Hash: 2035254952

 

selectt.ts#,t.file#,t.block#,nvl(t.bobj#,0),nvl(t.tab#,0),t.intcols,

 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# (+)

 

 

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          2          4          0           1

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

total       2      0.00       0.00          2          4          0           1

 

Misses in library cache during parse: 0

Optimizer mode: CHOOSE

Parsing user id: SYS   (recursive depth: 1)

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        2        0.00          0.00

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

 

SQL ID: 7ng34ruy5awxq Plan Hash: 3992920156

 

selecti.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) cwhere

 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       0      0.00       0.00          0          0          0           0

Execute      1     0.00       0.00          0          0          0           0

Fetch       2      0.00       0.00          2          7          0           1

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

total       3      0.00       0.00          2          7          0           1

 

Misses in library cache during parse: 0

Optimizer mode: CHOOSE

Parsing user id: SYS   (recursive depth: 1)

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        2        0.00          0.00

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

 

SQL ID: 5n1fs4m2n2y0r Plan Hash: 299250003

 

selectpos#,intcol#,col#,spare1,bo#,spare2,spare3

from

 icol$ where obj#=:1

 

 

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       2      0.00       0.00         1          3          0           1

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

total       3      0.00       0.00          1          3          0           1

 

Misses in library cache during parse: 0

Optimizer mode: CHOOSE

Parsing user id: SYS   (recursive depth: 1)

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        1        0.00          0.00

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

 

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       0      0.00       0.00          0          0          0           0

Execute     1      0.00       0.00          0          0          0           0

Fetch      16      0.00       0.00          0          3          0          15

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

total      17      0.00       0.00          0          3          0          15

 

Misses in library cache during parse: 0

Optimizer mode: CHOOSE

Parsing user id: SYS   (recursive depth: 1)

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

 

SQL ID: 87gaftwrm2h68 Plan Hash: 1218588913

 

selecto.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       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          3          0           1

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

total       2      0.00       0.00          0          3         0           1

 

Misses in library cache during parse: 0

Optimizer mode: CHOOSE

Parsing user id: SYS   (recursive depth: 1)

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

 

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    15      0.00       0.00         0          0          0           0

Fetch      15      0.00       0.00          1         45          0          15

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

total      30      0.00       0.00          1         45         0          15

 

Misses in library cache during parse: 0

Optimizer mode: RULE

Parsing user id: SYS   (recursive depth: 1)

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        1        0.00          0.00

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

 

SQL ID: 6rsg9q38ak6ys Plan Hash: 3358514785

 

select *

from

 davewhere object_id=10

 

 

call    count       cpu    elapsed       disk     query    current        rows

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

Parse       1      0.01      0.02          7         73          0           0

Execute     1      0.00       0.00          0          0          0           0

Fetch       3      0.00       0.00         19         21          0          16

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

total       5      0.02       0.02         26         94          0          16

 

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

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

       16         16         16 TABLE ACCESS BY INDEX ROWID DAVE (cr=21 pr=19 pw=0 time=2502 us cost=19size=1552 card=16)

       16         16         16  INDEX RANGE SCAN IDX_DAVE_OBJID (cr=5 pr=3 pw=0 time=1644 us cost=3size=0 card=16)(object id 76858)

 

 

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

  dbfile sequential read                        5        0.00          0.00

 SQL*Net message from client                     3        0.00          0.00

  dbfile parallel read                          1        0.00          0.00

 

 

 

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

 

OVERALL TOTALS FOR ALL NON-RECURSIVESTATEMENTS

 

call    count       cpu    elapsed       disk     query    current        rows

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

Parse       1      0.01       0.02          7         73         0           0

Execute     1      0.00       0.00          0          0          0           0

Fetch       3      0.00       0.00         19         21          0          16

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

total       5      0.02       0.02         26         94          0          16

 

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                       5        0.00          0.00

 SQL*Net message from client                     5        4.55          4.55

  dbfile sequential read                        5        0.00          0.00

  dbfile parallel read                          1        0.00          0.00

 

 

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    22      0.00       0.00          0          0          0           0

Fetch      39      0.00       0.00          7         73          0          36

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

total      61      0.00       0.01          7         73          0          36

 

Misses in library cache during parse: 0

 

Elapsed times include waiting on followingevents:

 Event waited on                             Times   Max. Wait Total Waited

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

  dbfile sequential read                        7        0.00          0.00

 

   1  user  SQL statements in session.

   7  internal SQL statements insession.

   8  SQL statements in session.

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

Trace file:/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave1.trc

Trace file compatibility: 11.1.0.7

Sort options: default

 

      4  sessions in tracefile.

      2  user  SQL statements in trace file.

     14  internal SQL statements in tracefile.

      8  SQL statements in trace file.

      8  unique SQL statements in tracefile.

    465  lines in trace file.

      0  elapsed seconds in trace file.

 

 

4.2 dave2.trc

[oracle@dave u01]$ cat dave2.trc

 

TKPROF: Release 11.2.0.3.0 - Development onWed Sep 12 08:57:29 2012

 

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

 

Trace file:/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave2.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: 6rsg9q38ak6ys Plan Hash: 3358514785

 

select *

from

 davewhere object_id=10

 

 

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       3      0.00       0.00          0         21          0          16

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

total       5      0.00       0.00          0         21          0          16

 

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: SYS

Number of plan statistics captured: 1

 

Rows (1st) Rows (avg) Rows (max)  Row Source Operation

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

       16         16         16 TABLE ACCESS BY INDEX ROWID DAVE (cr=21 pr=0 pw=0 time=963 us cost=19size=1552 card=16)

       16         16         16  INDEX RANGE SCAN IDX_DAVE_OBJID (cr=5 pr=0 pw=0 time=671 us cost=3 size=0card=16)(object id 76858)

 

 

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        0.00          0.00

 

 

 

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

 

OVERALL TOTALS FOR ALL NON-RECURSIVESTATEMENTS

 

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       3      0.00       0.00         0         21          0          16

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

total       5      0.00       0.00          0         21          0          16

 

Misses in library cache during parse: 0

 

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        5.15          5.16

 

 

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 insession.

   1  SQL statements in session.

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

Trace file:/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_9774_dave2.trc

Trace file compatibility: 11.1.0.7

Sort options: default

 

      5  sessions in tracefile.

      2  user  SQL statements in trace file.

      0  internal SQL statements intrace file.

      1  SQL statements in trace file.

      1  unique SQL statements in tracefile.

    120  lines in trace file.

      0  elapsed seconds in trace file.