Re: LOB Operation and SQL*Net Message From Client and cursor #0
Date: Thu, 2 May 2013 07:21:51 +0100
Message-ID: <4755756309A644A59C8FC16B97543956_at_Primary>
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_at_verizon.net> To: <jonathan_at_jlcomp.demon.co.uk>; "'Oracle-L'" <oracle-l_at_freelists.org> 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_at_verizon.net
| Cell: 214.695.8605
|
|
|
-- http://www.freelists.org/webpage/oracle-lReceived on Thu May 02 2013 - 08:21:51 CEST