Re: Source for tim=nnnnn in 10046 trace

From: Norman Dunbar <oracle_at_dunbar-it.co.uk>
Date: Thu, 22 Aug 2013 14:58:21 +0100
Message-ID: <521618FD.3000909_at_dunbar-it.co.uk>



Afternoon Raj,

On 22/08/13 13:48, rjamya wrote:
> Anyone know how/from where this value is sourced? is it from v$timer? it is
> time in microseconds since when?

I was on Cary's Mastering Oracle Trace Data course back in 2011 in London. From my notes I see the following:

Tim = nnnnnn
This call completed at time nnnnn. +/- 1 uSecond. The tim value is given in uSeconds but the answer to "uSeconds since what?" varies platform by platform. All that really matters is for the tim values to be consistent within a given trace file, which they usually* are!

*Usually has a footnote:

They're most likely not to be consistent within a given trace file on Microsoft Windows systems, where tim values wrap more frequently than on other systems.

Then, a few pages further on in my notebook, I have noted this, whihc Cary advised us of:

Prior to 11.2 - One Oracle uSecond was = 1,024 nSeconds instead of 1,000. So all tims are wrong. Use mrtime (part of the MrTools kit) to sort the tim values.

For 11.2.0.1 - Tim values are correct for WAIT times but as above for PARSE/FETCH/EXEC tims. Again, use MrTim to fix the tim values.

For 11.2.0.2 - Cary doesn't know!

> Plus i suspect it is platform dependent ...

Very much so, yes!

If you strace a database process you will see lots of calls to gettimeofday() at least, in the notebook Cary supplied you do. That was on 10.1.0.3.0 on Red Hat Enterprise Linux ES 3. These are used to get the e= uSeconds for a database call. Getrusage calls also abound in the strace output, and these are used for the c= uSeconds values.

The above are for the database calls - parse, exec, fetch. Wait (aka system calls - Hi Cary!) use a different mechanism. The strace output shows calls to gettimeofday() to get the ela= values.

Ahem, times may have changed since then. (Sorry, pun intended - it's what I do!)

So, basically, it's not really relevant what the tim values are "from", they just are, but unless you are on Windows, the tim values should be all "from" the same point in tim. (!) Subject to the above errors caused by there being 1,024 nano seconds in a micro second, according to Oracle.

HTH Cheers,
Norm.

-- 
Norman Dunbar
Dunbar IT Consultants Ltd

Registered address:
27a Lidget Hill
Pudsey
West Yorkshire
United Kingdom
LS28 7LG

Company Number: 05132767
--
http://www.freelists.org/webpage/oracle-l
Received on Thu Aug 22 2013 - 15:58:21 CEST

Original text of this message