Times do not add up in 10046 trace file

From: <mccmx_at_hotmail.com>
Date: 11 Oct 2006 03:13:17 -0700
Message-ID: <1160561597.549302.12330@h48g2000cwc.googlegroups.com>

Oracle 10.2.0.2 W2K3

In the summary section of the trace file below, the total elapsed time is 113.84s of which 72.12s seconds was CPU time. This leaves 41s of wait time. However the wait breakdown adds up to much more than this. Ignoring SQL*Net wait times because they are 'between call' waits, we have at least, 63.15 + 33.10 + 3.91 = 100.16.

Can anyone explain why the total wait time is so much higher than the difference between CPU and elapsed times....?

---

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current

    rows
------- ------ -------- ---------- ---------- ---------- ----------

---

Parse    10675      8.39      12.22          0          3          0
       0
Execute  57732     36.50      57.10     100129     101923     165840
   27507
Fetch    53336     27.23      44.51     101400    1213121          0

   53250
------- ------ -------- ---------- ---------- ---------- ----------

---

total 121743 72.12 113.84 201529 1315047 165840

   80757

Misses in library cache during parse: 8083 Misses in library cache during execute: 8269

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

• Waited ----------

  ---

  SQL*Net message to client 105456 0.00 1.14 SQL*Net message from client 105456 0.02 239.01 db file sequential read 888 0.10 3.91 db file scattered read 12701 0.15 33.10 log file sync 13940 0.03 63.15 undo segment extension 11 0.00 0.00 latch: library cache 3 0.00 0.00 latch: shared pool 14 0.00 0.00 latch free 8 0.00 0.01 latch: redo allocation 2 0.00 0.00 latch: cache buffers chains 1 0.00 0.00 latch: row cache objects 1 0.00 0.00

Received on Wed Oct 11 2006 - 05:13:17 CDT