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 15:25:11 +0100

Even worse - in some respects.

You said the 358,953 trips amounted to roughly 73MB, which (allowing for 
overheads) is about 0.75 gigabits.

On a 10Gb link that should a minimum of around 0.075 seconds (I know that 
still leaves a lot of missing time to account for, but it does highlight 
the problem of measurement.)

Have you tried setting the SQL*Plus environment to optimize the test:
set long 4000
set longchunksize 4000

This should reduce your roundtrips to 2 per row rather than 3.5 - it might 
be interesting to see how varying longchunksize affects the reports you get 
from the monitor tool.

Trying to identify the timing, my LOBREAD times were reported as ca. 25 
microseconds when I enabled sql_trace, but anything from 160 to 1,200 
microseconds when I started using strace as well (which shows that the time 
includes some of the instrumentation time). I think the LOBREAD time is 
likely to be true since extra lobreads (of an inline lob, at any rate) 
don't do extra buffer gets etc. Any other time in the database is the 
effect of unloading and loading the network buffer (plus instrumentation 

(And I've just realised that since you're on 10g you probably don't have 
LOBREAD lines appearing in the trace file.)


Jonathan Lewis

Author: Oracle Core (Apress 2011)

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

|I was unclear in the original email. The .001353 was *total* time the tool 
reported for network transfer, 358,963 trips.
| For this particular test, duration 211 seconds, no PIO's recorded for the 
query, less than .5 seconds CPU, 180 seconds message from
| client, and 30 seconds unaccounted for time (mostly LOB related?). I have 
a tool that can help with the unaccounted for time and
| help with your suggestions on timestamps.
| The opnet tool attributed 14 seconds to application time (SQL*Plus), 
.001353 network, and the rest DB, so basically 197 seconds
| attributed to the DB. From the 10046 if we take the 30 seconds 
unaccounted plus .5 CPU that is still far short of the 197 seconds
| opnet is putting on the DB. And I'll have to ask the infrastructure folks 
about the point Mark made regarding the turns themselves.
| The main thing I was going for was the question if there are any known 
instrumentation issues such as LOB operations, for example,
| getting attributed to the wrong event, such as message from client, and 
if there were other known accounting issues with LOBS. From
| some readings, and comments in this thread, it seems some (maybe much) of 
the LOB activity could fall into the unaccounted bucket.
| Haven't come across anything yet regarding LOB activity getting 
attributed to the wrong event.
| If I make any other progress in resolving the discrepancy I'll get back 
to the list.
| Larry G. Elkins
| elkinsl@xxxxxxxxxxx
| Cell: 214.695.8605
| > -----Original Message-----
| > From: oracle-l-bounce@xxxxxxxxxxxxx 
[mailto:oracle-l-bounce@xxxxxxxxxxxxx] On Behalf Of Jonathan Lewis
| > Sent: Thursday, May 02, 2013 1:22 AM
| > To: 'Oracle-L'
| > Subject: Re: LOB Operation and SQL*Net Message From Client and cursor 
| >
| >
| >
| > 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 
| >
| >
| > 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.
| -----
| No virus found in this message.
| Checked by AVG -
| Version: 2013.0.2904 / Virus Database: 3162/6280 - Release Date: 04/28/13


Other related posts: