I always think twice while talking to a guru. Here is my comment for your test case:
'tim' columns in these examples are not accurate.
PARSING IN CURSOR #1 len=40 dep=0 uid=54 oct=1 lid=54
tim=1019495629370923 hv=1851325355 ad='6cb3450'
alter table TESTLONG modify ( text clob)
END OF STMT
PARSE
#1:c=10000,e=11122,p=1,cr=1,cu=0,mis=1,r=0,dep=0,og=4,tim=101949562937
0823
Time difference : 1019495629370823 - 1019495629370923 = -100 microseconds
But your elapsed time for PARSE call is 11122 microseconds. I think your second 'tim' should not be less than (1019495629370923 + 11122). Because, 'tim' column is obtained from V$TIMER when a line is written to dump. Most probably, this is a bug.
I think "PARSING IN CURSOR"/"PARSE" statement doesn't always indicate when the statement is handled by Oracle. Because, there may be some recursive statements handled before the parent statements are actually handled. Statistics of these statements are not included in the parent statements.
Also, as you stated in your last case, "alter session set events '10046.." or "alter session set sql_trace=true" don't include PARSE calls. If it's the first statement in raw trace file, no problem, but If not, or if a statement doesn't iclude a PARSE call, tkprof reports wrong results. Because, we know SOME statistics in raw trace files include SOME statistics of SOME recursive statements' statistics. tkprof substructs them by starting from PARSE call to current line. If tkprof can not find a PARSE call for a statement, it assumes substruction from the beginning of file to current line. This makes wrong reports. itrprof(Sorry Jared) reports an error code for this problem.
I recommend the followings the tkprof users:
- Enabling SQL and Event 10046 trace files from the other sessions may
cause missing statistics in the trace files.
- If this is not possible, enable the traces when the traced session
is IDLE.
regards...
regards...
Jonathan Lewis wrote:
Don't lose any sleep on it, but here's another:PARSING IN CURSOR #1 len=40 dep=0 uid=54 oct=1 lid=54
tim=1019495629370923 hv=1851325355 ad='6cb3450'
alter table TESTLONG modify ( text clob)
END OF STMT
PARSE
#1:c=10000,e=11122,p=1,cr=1,cu=0,mis=1,r=0,dep=0,og=4,tim=101949562937
0823NB - not recursive, not SYS, and a hard parse to boot.
But this one is much more interesting:
PARSING IN CURSOR #1 len=68 dep=0 uid=54 oct=42 lid=54
tim=1019495629353714 hv=287842151 ad='6cba5e8'
alter session set events '10046 trace name context forever, level 8'
END OF STMT
EXEC
#1:c=0,e=13,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=1019495629321662Note the complete absence of PARSE #1, and the
'massive' 32,000 microsecond back-step.In general, however, the PARSE seems to be a
fairly persistent 110 micro seconds out of step.Jonathan Lewis
http://www.jlcomp.demon.co.ukAuthor of:
Practical Oracle 8i: Building Efficient DatabasesNext Seminar - Australia - July/August
http://www.jlcomp.demon.co.uk/seminar.htmlHost to The Co-Operative Oracle Users' FAQ
http://www.jlcomp.demon.co.uk/faq/ind_faq.html-----Original Message-----
To: Multiple recipients of list ORACLE-L <[EMAIL PROTECTED]>
Date: 23 April 2002 14:18
light.|Do you have any more examples? and if so, is the
|second time always suffixed with '00'. I'm wondering
|if the concluding time is still centiseconds (or
|whatever precision is appropriate to cause the
|'problem')
|
|Cheers
|Connor
|--
Please see the official ORACLE-L FAQ: http://www.orafaq.com
--
Author: Jonathan Lewis
INET: [EMAIL PROTECTED]Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
San Diego, California -- Public Internet access / Mailing Lists
--------------------------------------------------------------------
To REMOVE yourself from this mailing list, send an E-Mail message
to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from). You may
also send the HELP command for other information (like subscribing).
--
Danisment Gazi Unal
http://www.ubTools.com
