Unaccounted for time in 10046 trace file

From: Hameed, Amir <Amir.Hameed_at_xerox.com>
Date: Fri, 13 Sep 2013 19:48:06 +0000
Message-ID: <AF02C941134B1A4AB5F61A726D08DCED0DE1770C_at_USA7109MB012.na.xerox.net>

Hi,
I ran a simple SELECT statement where I drove a FTS on a large table and then trace it at level 8. Below is the SQL statement: select /*+ full(MMT) */ count(*) from apps.mtl_material_transactions MMT ; Here is the output from TKPROF:

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2    174.21     841.44    7852466    7853454          0           1


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

total        4    174.22     841.44    7852466    7853454          0           1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  library cache lock                              1        0.00          0.00
  library cache pin                               1        0.00          0.00
  SQL*Net message to client                       2        0.00          0.00
  Disk file operations I/O                      123        0.00          0.00
  gc current block 3-way                          1        0.00          0.00
  enq: KO - fast object checkpoint                3        0.01          0.01
  reliable message                                1        0.00          0.00
  direct path read                             1919        4.48        356.76
  gc cr block 2-way                              31        0.00          0.01
  db file sequential read                       201        0.03          0.63
  gc cr disk read                                 1        0.00          0.00
  SQL*Net message from client                     2        0.00          0.00
********************************************************************************

I am not able to reconcile the elapsed time and the discrepancy is just too much: elapsed - cpu = 667.22
Total Waited = 357.4
Unaccounted for time = 667.22 - 357.4 = 309.82

I know that Cary Milsap has talked about unaccounted for time in TKPROF output but this gap is just too much. Any idea where to look for the missing time?

Thanks,
Amir

--
http://www.freelists.org/webpage/oracle-l

Received on Fri Sep 13 2013 - 21:48:06 CEST