10046 Trace question

From: rjamya <rjamya_at_gmail.com>
Date: Tue, 26 Apr 2005 13:31:30 -0400
Message-ID: <9177895d05042610314c9beb5b@mail.gmail.com>

Hi all,
I am testing performance of a query that produced some interesting outputs in the raw trace file. I cannot explain this, can someone?

Raj

Forwarded message ---------- From: Jamadagni, Rajendra

PARSING IN CURSOR #1 len=1540 dep=0 uid=44 oct=3 lid=44 tim=1088413968080921 hv=3734675936 ad='27ee5260'
SELECT distinct pscp_pa_id, pr_brnd_id, brnd_name, pa_agnc_id, pa_advr_id, ....
END OF STMT
PARSE #1:c=50000,e=62605,p=0,cr=109,cu=0,mis=1,r=0,dep=0,og=0,tim=1088413968080915

EXEC #1:c=0,e=655,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1088413968171161 
WAIT #1: nam='SQL*Net message to client' ela= 23 p1=1650815232 p2=1 p3=0 
WAIT #1: nam='global cache cr request' ela= 528 p1=32 p2=93812

p3=504403158399474816
WAIT #1: nam='db file sequential read' ela= 460 p1=32 p2=93812 p3=1 WAIT #1: nam='global cache cr request' ela= 446 p1=32 p2=93832 p3=504403158349232736
WAIT #1: nam='db file sequential read' ela= 396 p1=32 p2=93832 p3=1 WAIT #1: nam='db file sequential read' ela= 385 p1=31 p2=55448 p3=1 *** 2005-04-26 13:20:17.483
FETCH #1:c=114080000,e=111402747,p=3,cr=817052,cu=0,mis=0,r=1,dep=0,og=4,tim=1088414079574042

WAIT #1: nam='SQL*Net message from client' ela= 1012 p1=1650815232 p2=1 p3=0

FETCH #1:c=0,e=28,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1088414079575522 WAIT #1: nam='SQL*Net message to client' ela= 2 p1=1650815232 p2=1 p3=0 WAIT #1: nam='SQL*Net message from client' ela= 1137 p1=1650815232 p2=1 p3=0

XCTEND rlbk=0, rd_only=1

See the FETCH line, before that there are 3 'db file sequential reads' but FETCH line reports 817052 cr reads. It seems we are missing whle lot of trace lines, but trust me, this is what I have. They query appears to hang, and then comes back. The difference between tim for PARSE and FETCH agrees with e= value on the FETCH line.

Am I interpreting this wrong? or should i expect to see many more lines in here for cr reads? The trace is enabled by alter session 10046^12. I have trimmed the sqltext and binds information for obvious information.

Any ideas? This is 9204 btw.
Raj

select standard_disclaimer from company_requirements where category = 'MANDATORY';

--
http://www.freelists.org/webpage/oracle-l

Received on Tue Apr 26 2005 - 13:35:52 CDT