Re: LOB Operation and SQL*Net Message From Client and cursor #0

  • From: "Jonathan Lewis" <jonathan@xxxxxxxxxxxxxxxxxx>
  • To: "'Oracle-L'" <oracle-l@xxxxxxxxxxxxx>
  • Date: Thu, 2 May 2013 07:21:51 +0100


Questioning the tool is a good idea.

Looking at the trace your turnaround between packets on cursor# 0 is in the 
order of 350 microseconds - which is 0.00035, which is nearly 4 times 
faster than the tool is reporting.  You might calibrate the tim= figures by 
running the query for at least 30 minutes so you get a couple of date 
stamps in the trace that you can use to check that the time change from the 
date stamps agrees with the tim= in microseconds. I don't think you've 
described the network - but I think it would have to be 10Mb to be slow 
enough to give you an average of .001353 s for a couple of hundred bytes.


The difference between the application and the SQL*Plus array processing 
may be an OCI choice in SQL*Plus, it may simply be a choice to ignore the 
arraysize when there are LOBs involved - interestingly there is a "lob 
attribute" column (which seems to be about client temporary lobs) in 
v$session_connect_info, you might compare what you see there for an 
application connection and an SQL*Plus connection.



Regards

Jonathan Lewis
http://jonathanlewis.wordpress.com/all-postings

Author: Oracle Core (Apress 2011)
http://www.apress.com/9781430239543

----- Original Message ----- 
From: "Larry Elkins" <elkinsl@xxxxxxxxxxx>
To: <jonathan@xxxxxxxxxxxxxxxxxx>; "'Oracle-L'" <oracle-l@xxxxxxxxxxxxx>
Sent: Thursday, May 02, 2013 2:18 AM
Subject: RE: LOB Operation and SQL*Net Message From Client and cursor #0


| Jonathan,
|
| Double-checked again, and indeed the SQL*Plus client is doing R=1. 
Working too many things at the same time and was going from
| memory, so I forwarded some details to myself today. When I bypassed the 
LOB, then yes, array fetches. Thanks for sanity checking
| that for me, that is what I had thought I would normally see.
|
| For the vendor application, we see the array fetch, but it is 43, not 100 
as I stated before. Here's an example showing the #0 waits
| around the fetch from the actual cursor, from a trace without the 10051 
event:
|
| WAIT #0: nam='SQL*Net message from client' ela= 319 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361239085
| WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361239118
| WAIT #0: nam='SQL*Net message from client' ela= 267 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361239406
| WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361239435
| WAIT #0: nam='SQL*Net message from client' ela= 291 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361239754
| WAIT #6: nam='SQL*Net message to client' ela= 0 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361239834
| WAIT #6: nam='SQL*Net more data to client' ela= 15 driver id=1413697536 
#bytes=2019 p3=0 obj#=-1 tim=40419361239903
| WAIT #6: nam='SQL*Net more data to client' ela= 11 driver id=1413697536 
#bytes=2005 p3=0 obj#=-1 tim=40419361239960
| WAIT #6: nam='SQL*Net more data to client' ela= 6 driver id=1413697536 
#bytes=2000 p3=0 obj#=-1 tim=40419361240012
| WAIT #6: nam='SQL*Net more data to client' ela= 7 driver id=1413697536 
#bytes=2000 p3=0 obj#=-1 tim=40419361240070
| FETCH #6:c=0,e=326,p=0,cr=4,cu=0,mis=0,r=43,dep=0,og=4,tim=40419361240108
| WAIT #6: nam='SQL*Net message from client' ela= 903 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361241045
| WAIT #0: nam='SQL*Net message to client' ela= 0 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361241079
| WAIT #0: nam='SQL*Net message from client' ela= 273 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361241373
| WAIT #0: nam='SQL*Net message to client' ela= 0 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361241402
| WAIT #0: nam='SQL*Net message from client' ela= 314 driver id=1413697536 
#bytes=1 p3=0 obj#=-1 tim=40419361241743
|
| With regards to Mark's comment about getting things as close together as 
possible, I verified today the app server box is in the
| same computer room as the database server box. The app server component 
is running within a VM on that box.
|
| And Freek, the LOB is defined as inline, and the largest is well below 
the threshold that would cause it to migrate out of line
| (using DBMS_LOB.GETLENGTH to check size).
|
| Didn't get to do much testing on it today, but I worked with the 
infrastructure guy and an opnet (AppTransactionXpert) trace for my
| SQL*Plus session from my desktop, even though we see some differences in 
how it fetches, still trying to better understand how
| things are being counted by our tools. We limited the number of rows 
compared to the real test, 100,000 or so. We still showed in
| the opnet trace 358,963 trip, 73 million total bytes, showing avg 
application message of 204 bytes and average network packets of
| 258 bytes. The thing that caught my interest is the tool says 0 for 
latency effect, and 0.001353 seconds on network transfer. Not
| being a network person, I would have expected a bit more than 0.001353, 
but they are standing by that number with regards to time on
| the network.
|
|
| Larry G. Elkins
| elkinsl@xxxxxxxxxxx
| Cell: 214.695.8605
|
|
| 

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


Other related posts: