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

Home -> Community -> Mailing Lists -> Oracle-L -> Re: tkprof elapsed time

Re: tkprof elapsed time

From: amonte <ax.mount_at_gmail.com>
Date: Wed, 21 Nov 2007 19:44:55 +0100
Message-ID: <85c1fb130711211044n613cbfffg18b0a77d1456af9c@mail.gmail.com>


Hi Vlad

I dint have the trace file handy but it is very easy to reproduce.

Generate 10000 insert statement to EMP Tabe and set autocommit on in sqlplus

Thanks

alex

On Nov 21, 2007 5:02 PM, Vlad Sadilovskiy <vlovsky_at_gmail.com> wrote:

> Amonte, it supposed to be calculated as you suggested with few exceptions.
> Do you have cursors in the trace that end up at level higher than zero
> followed by SQL*Net... waits? There could be some other problem with it.
>
> Do you mind sending out the trace I'll "dig" into it :)
>
> Checkout this two articles that have example of strange behavior.
>
> BLOB write size and CPU<http://vsadilovskiy.wordpress.com/2007/11/19/blob-write-size-and-cpu/>
> <http://vsadilovskiy.wordpress.com/2007/11/19/blob-write-size-and-cpu/>
> Call-Less Cursor<http://vsadilovskiy.wordpress.com/2007/10/29/trace-and-statspack-lob-1/>
>
> Vlad Sadilovskiy
> Oracle Database Tools
> Web site: http://www.fourthelephant.com
> Blog: http://vsadilovskiy.wordpress.com
>
> On 11/21/07, amonte <ax.mount_at_gmail.com> wrote:
> >
> > Hi
> >
> > In a TKPROF output such as follows:
> >
> > call count cpu elapsed disk query
> > current rows
> > ------- ------ -------- ---------- ---------- ---------- ----------
> > ----------
> > Parse 1 0.00 0.00 0 0
> > 0 0
> > Execute 7045 8.68 8.72 0 156
> > 159502 7045
> > Fetch 0 0.00 0.00 0 0
> > 0 0
> > ------- ------ -------- ---------- ---------- ---------- ----------
> > ----------
> > total 7046 8.68 8.72 0 156
> > 159502 7045
> >
> > Misses in library cache during parse: 0
> > Optimizer mode: ALL_ROWS
> > Parsing user id: 63
> >
> > Elapsed times include waiting on following events:
> > Event waited on Times Max. Wait Total
> > Waited
> > ---------------------------------------- Waited ----------
> > ------------
> > log file sync 7045 0.04
> > 33.33
> > SQL*Net message to client 7045 0.00
> > 0.00
> > SQL*Net message from client 7045 0.04
> > 4.66
> > log file switch completion 2 0.09
> > 0.16
> >
> > Is elapsed time = cpu time + waits? Because in this case we have 8.72for elapsed time and
> > 8.68 for cpu, log file sync waits is 33 seconds so shouldnt elapsed be
> > around 42 seconds?
> >
> > Or the elapsed time is calculated in a different way :-?
> >
> > Alex
> >
> >
>

--
http://www.freelists.org/webpage/oracle-l
Received on Wed Nov 21 2007 - 12:44:55 CST

Original text of this message

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