RE: RE: TKPROF output

SQL*Net to Client doesn't measure what it looks like.  It really seems to 
measure how long it takes to assemble the message that is going to be sent to 
the client.  It doesn't measure the actual send. 

The entire round trip (send, handshaking, wait for next command) is all in 
SQL*Net FROM client.  As Ron Crisco has mentioned this is well documented in 
Cary's book "Optimizing Oracle Performance".  

It appears there are two things that need to be investigated:

1) Arraysize appears to be too small.  Maybe these are huge rows, but even so, 
a larger array size seems needed.  Fewer round trips, fewer fetches, fewer 
SQL*Net to/from Client messages.

2) What is the client side doing with the data? Does it really need 164,741 
rows? The average SQL*Net seems to be about 0.0036 seconds which does seem 
reasonably fast, but when you do over 27,000 calls it adds up!

-----------------------
Ric Van Dyke
Hotsos Enterprises
-----------------------
 
The 10th Hotsos Symposium 
4-8 March 2012  Start making plans now! 
 
 
-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx [mailto:oracle-l-bounce@xxxxxxxxxxxxx] On 
Behalf Of D'Hooge Freek
Sent: Thursday, March 31, 2011 8:24 AM
To: Niall Litchfield
Cc: ORACLE-L
Subject: RE: RE: TKPROF output

Niall,

Yes you are right.
As I come to think of it 0.000000364 seconds per sql*net message to client is 
maybe a tad low to be realistic   :-)

I also verified with some traces I had from my systems and the total time spend 
on sql*net message to client seems to be always 0 (or near zero), while the 
time spend on sql*net message from client is more realistic.


Regards,

Freek D'Hooge
Uptime
Oracle Database Administrator
email: freek.dhooge@xxxxxxxxx
tel +32(0)3 451 23 82
http://www.uptime.be
disclaimer: www.uptime.be/disclaimer
---
From: Niall Litchfield [mailto:niall.litchfield@xxxxxxxxx] 
Sent: donderdag 31 maart 2011 12:57
To: D'Hooge Freek
Cc: ORACLE-L
Subject: Re: RE: TKPROF output

I think the SQL*Net Message to/from Client events  are (a bit) unfortunately 
named. They are (IIRC - strace would show) sendmsg and recvmsg syscalls and 
associated timings. As the link send by Remigiusz describes the send call ends 
when the data is placed in the send buffer and the receive call when the 
response (and data) is received. This means effectively that SQL*Net message 
from client covers pretty much the whole latency and message to client just 
signals the start (I'd be really geekily interested if anyone has examples of 
SQL*Net Message to client syscalls taking any length of time at all.)  This is 
pretty much no use for telling us if the network is slow, the app server is 
slow or the user is kicking back watching the cricket. It does tell us though 
that time "outside" the database is being spent. 
 
I too thought of asking for the histograms, but I don't think there will be 
many slow examples. Total time spent in 27k calls was 100s (with 1s of that 
spent in 1 call) that leaves 99s for the remaining and too many cs scale 
requests must mean a number of sub ms events which is unlikely on normal 
networks. I would like to see the old system data.   
 
On Thu, Mar 31, 2011 at 7:41 AM, D'Hooge Freek <Freek.DHooge@xxxxxxxxx> wrote:
True, but compaired to the time spend for sending the data it seems high.
Also the max wait time is 1 second. It would be interesting to see the 
histogram for this.

Lyall,

Can you run orasrp on the raw trace file to get the histograms 
(http://www.oracledba.ru/orasrp/)

Remigiusz,

Thanks for the link, I will certainly check it out.

regards,

Freek D'Hooge
Uptime
Oracle Database Administrator
email: freek.dhooge@xxxxxxxxx
tel +32(0)3 451 23 82
http://www.uptime.be
disclaimer: www.uptime.be/disclaimer

From: Niall Litchfield [niall.litchfield@xxxxxxxxx]
Sent: 31 March 2011 08:26
To: D'Hooge Freek; ORACLE-L
Subject: Re: RE: TKPROF output


Freek, I don't think the comms are slow per se. If my math is right the avg 
wait is 3ms . There are a lot of them though. Of course we don't know rowsize 
or what the original system looks like.
On 31 Mar 2011 07:03, "D&apos;Hooge Freek" <Freek.DHooge@xxxxxxxxx> wrote:

Hi,

The main wait time is "sql*net message from client", meaning that you are 
waiting on response from the aplication server.
Can you check in the raw trace file if these waits are happening between the 
fetches or not?

If they are happening between the fetches, it means that the application server 
is slow to request more rows from the query result.
Reason for this could be some processing that happens on the application server 
or maybe a network problem (like a wrong dns server on the application server).

If the waits are happening after all the fetches are completed, then these 
waits are probably not relevant (unless you are sure that the trace was stopped 
at the moment the application showed the result of the query).
How did you trace this session?


regards,

Freek D'Hooge
Uptime
Oracle Database Administrator
email: freek.dhooge@xxxxxxxxx
tel +32(0)3 451 23 82
http://www.uptime.be
disclaimer: www.uptime.be/disclaimer
---
From: oracle-l-bounce@xxxxxxxxxxxxx [oracle-l-bounce@xxxxxxxxxxxxx] On Behalf 
Of lyallbarbour@xxxxxxxxxxxxxxx [lyallbarbour@xxxxxxxxxxxxxxx]
Sent: 30 March 2011 20:55

To: oracle-l@xxxxxxxxxxxxx
Subject: TKPROF output


Trying to understand Fetch in a TKPROF output. We have an application on Oracle 
Apps Server 10.1 D...
 SQL*Net message from client                 27457        1.07        100.33--

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



-- 
Niall Litchfield
Oracle DBA
http://www.orawin.info
--
http://www.freelists.org/webpage/oracle-l


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

Other related posts: