Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Usenet -> c.d.o.server -> Re: Times do not add up in 10046 trace file

Re: Times do not add up in 10046 trace file

From: hpuxrac <johnbhurley_at_sbcglobal.net>
Date: 11 Oct 2006 05:39:24 -0700
Message-ID: <1160570364.053061.277400@b28g2000cwb.googlegroups.com>

mccmx_at_hotmail.com wrote:
> 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

First, you don't want to write off SQL net calls if they represent something important in your profile. Second, you cannot extract detail from an aggregate.

I would recommend that you look at individual SQL statements not some kind of "total" from all the non-recursive SQL. ( Besides, anything you think you are missing could come from the recursive part of the SQL ).

Put your trace file through a decent resource profiler like the hotsos one or the orarsp ( free clone ). Read Cary Millsap's book "Optimizing Oracle Performance". Received on Wed Oct 11 2006 - 07:39:24 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US