Re: Help understand raw trace data.

From: Cary Millsap <cary.millsap_at_method-r.com>
Date: Sat, 12 Sep 2009 07:50:20 -0500
Message-ID: <3a2a84fc0909120550y3cd56786sd52ec48d87c4daf0_at_mail.gmail.com>



Fred,

I think I can help you figure out what your problem is, but I need to see at least the next line after these:

       WAIT #0: nam='SQL*Net message from client' ela= 2682513 driver id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2681254673

  • 2009-09-04 11:32:44.610

It would be good to see your whole trace file. Contact me offline if you want, and I can give you information about how to upload it to our method-r.com site. It will not help me to see your *tkprof* output.

Cary Millsap
Method R Corporation

http://method-r.com
http://carymillsap.blogspot.com
http://twitter.com/cary_millsap


On Sat, Sep 12, 2009 at 1:27 AM, Balakrishna Y <krishna000_at_gmail.com> wrote:

> Hi ,
>
> I think this trace is not helping much .. why dont you take trace on entire
> transaction and paste the raw trace with tkprof on this should help people
> understanding better.
>
> Regards
>
> Bala
>
> On Sun, Sep 6, 2009 at 12:38 AM, Fred Tilly <ftilly_at_btinternet.com>wrote:
>
>> Jack,
>>
>> Why am I sending so much data and what would cause the long delays in the
>> SQL*Net more data top client.
>>
>> Thanks
>>
>> Fred
>>
>>
>>
>> It's early for me, but what exactly is your question?
>>
>>
>>
>> Jack van Zanen
>>
>> -------------------------
>> This e-mail and any attachments may contain confidential material for the
>> sole use of the intended recipient. If you are not the intended recipient,
>> please be aware that any disclosure, copying, distribution or use of this
>> e-mail or any attachment is prohibited. If you have received this e-mail in
>> error, please contact the sender and delete all copies.
>> Thank you for your cooperation
>>
>>
>> 2009/9/6 Fred Tilly <ftilly_at_btinternet.com>
>> Hi,
>>
>> The procedure accepts the following parameters:
>>
>> ALOGID NUMBER;
>> AINTREF VARCHAR2(50);
>> ACLIENTTYPE NUMBER;
>> ACLIENTID VARCHAR2(20);
>> ACLIENTSUBID VARCHAR2(50);
>> ASTARTTIME varchar2(20);
>> ACHANNEL NUMBER;
>> AINITUSERGROUP NUMBER;
>> AINITUSERGROUPNAME VARCHAR2(50);
>> AINITUSERID VARCHAR2(100);
>> AINITUSERNAME VARCHAR2(50);
>> AREFERENCE VARCHAR2(50);
>> ADATA VARCHAR2(500);
>> AVERIFIED CHAR(1);
>> ACLIENTCATEGORY NUMBER;
>> ACLIENTNAME VARCHAR2(255);
>> AENDDATE varchar2(20);
>>
>> And it is being called via JDBC, but I have no access to the
>> calling routine.
>>
>> The main problem is that this query is used by a telephone based
>> application and at times takes 2 seconds or more to respond but most of the
>> time it has a subsecond response. However the database is being blamed but I
>> do not think this is the case, I am looking at gathering evidence and the
>> trace was my starting point.
>>
>>
>> Thanks
>>
>> Fred
>>
>> --
>> http://www.freelists.org/webpage/oracle-l
>>
>>
>>
>>
>>
>> Fred
>>
>> What is the signature of the procedure ORA_INTERACTION? are the parameters
>> constrained or unconstrained, CHARs or VARCHAR2s, and byte or char
>> semantics?
>>
>> And what are the datatypes of the actual arguments? Come to that, describe
>> the calling client (JDBC?)
>>
>> Regards Nigel
>>
>> 2009/9/4 Fred Tilly <ftilly_at_btinternet.com>
>> Hi,
>>
>> I have a stored procedure that runs a simple select statement and
>> returns a series of parameters, the total size of the parameters returned in
>> bytes should be 1032 bytes. However when I trace the procedure call I see
>> the following in the trace file:
>>
>> PARSING IN CURSOR #32 len=112 dep=0 uid=60 oct=47 lid=60
>> tim=2677334787 hv=2159500523 ad='2db0cc60'
>> BEGIN ORA_INTERACTION(:1, :2, :3, :4, :5, :6, :7, :8, :9, :10, :11,
>> :12, :13, :14, :15, :16, :17); END;
>> END OF STMT
>> PARSE
>> #32:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2677334785
>> EXEC #18:c=0,e=20,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=2677334986
>> FETCH
>> #18:c=0,e=35,p=0,cr=4,cu=0,mis=0,r=1,dep=1,og=1,tim=2677335035
>> WAIT #32: nam='SQL*Net message to client' ela= 1 driver
>> id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2677335092
>> WAIT #32: nam='SQL*Net more data to client' ela= 22 driver
>> id=1952673792 #bytes=2134 p3=0 obj#=68676 tim=2677335132
>> <snip> a further 15 SQL*Net more data to client
>>
>> EXEC #32:c=0,e=1233159,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=2678568000
>> WAIT #32: nam='SQL*Net message from client' ela= 3385 driver
>> id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2678571444
>> XCTEND rlbk=0, rd_only=1
>> WAIT #0: nam='SQL*Net message to client' ela= 0 driver
>> id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2678571535
>> WAIT #0: nam='SQL*Net message from client' ela= 555 driver
>> id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2678572105
>> XCTEND rlbk=0, rd_only=1
>> WAIT #0: nam='SQL*Net message to client' ela= 0 driver
>> id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2678572143
>> WAIT #0: nam='SQL*Net message from client' ela= 2682513 driver
>> id=1952673792 #bytes=1 p3=0 obj#=68676 tim=2681254673
>> *** 2009-09-04 11:32:44.610
>>
>> My question is why so many calls to " SQL*Net more data to client"
>> if I am only passing what I think is 1032 bytes.
>>
>> Thanks
>>
>> Fred
>>
>> --
>> http://www.freelists.org/webpage/oracle-l
>>
>>
>>
>> --
>> http://www.freelists.org/webpage/oracle-l
>>
>>
>>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Sat Sep 12 2009 - 07:50:20 CDT

Original text of this message