X-list: oracle-l Return-Path: Subject: Re: tim= values in trace file From: Niall Litchfield Message-id: 7765c8970601051302h2eb089ffpa305761a69341073@mail.gmail.com Date: 2006-01-05 22:02:23 On 1/5/06, Paul Baumgartel wrote: > > Do the timestamp values in Oracle10g trace files wrap? Note in the > following that the timestamp of all of the fetch calls is less than that of > the exec call. > > This particular query did in fact run for around 20 minutes; I'm trying to > determine whether the CPU or elapsed value on the first FETCH call is > correct (they can't both be correct, as the CPU is around double the > elapsed). > > TIA. > > PARSING IN CURSOR #26 len=1221 dep=1 uid=16121 oct=3 lid=16121 > tim=8192891567 hv=3617545717 ad='acf1cb30' > SELECT ... > END OF STMT > PARSE #26:c=0,e=3257,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,tim=8192891556 > EXEC > #26:c=46875,e=47706,p=0,cr=144,cu=0,mis=1,r=0,dep=1,og=1,tim=8192940296 > *** 2006-01-04 17:16:54.070 > FETCH > #26:c=2222703125,e=1152767754,p=0,cr=1924,cu=0,mis=0,r=1,dep=1,og=1,tim=1152767754 > FETCH #26:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=1152768071 > FETCH #26:c=0,e=12,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=1152768173 > FETCH #26:c=0,e=12,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=1152768264 > FETCH #26:c=0,e=11,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=1,tim=1152768353 > FETCH #26:c=0,e=19,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1152768449 > They can wrap. In this case however I think its a bug where the e= value is getting set with the timestamp rather than the elapsed time. I'm almost certain that I have seen this documented on metalink. -- Niall Litchfield Oracle DBA http://www.niall.litchfield.dial.pipex.com