Re: tkprof elapsed time

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@xxxxxxxxx> 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@xxxxxxxxx> 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
> >
> >
>

Other related posts: