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

From: Jonathan Lewis <jonathan_at_jlcomp.demon.co.uk>
Date: Thu, 2 May 2013 15:25:11 +0100
Message-ID: <83BEB7F7442E4BF3A34DC8871D855046_at_Primary>


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 time).

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

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 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_at_verizon.net
| Cell: 214.695.8605
|
| > -----Original Message-----
| > From: oracle-l-bounce_at_freelists.org
[mailto:oracle-l-bounce_at_freelists.org] 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
#0
| >
| >
| >
| > 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.
|
|
|
| -----
| No virus found in this message.
| Checked by AVG - www.avg.com
| Version: 2013.0.2904 / Virus Database: 3162/6280 - Release Date: 04/28/13
|

--
http://www.freelists.org/webpage/oracle-l
Received on Thu May 02 2013 - 16:25:11 CEST

Original text of this message