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

From: Larry Elkins <elkinsl_at_verizon.net>
Date: Sat, 04 May 2013 08:30:00 -0500
Message-id: <000701ce48cb$7aa815c0$6ff84140$_at_net>



Had to put this in the backburner for a bit, but had already tired 400 for long and longc with no impact, and tried with 4000 after your suggestion. The round trips remained at 534,073 for all the tests.

Copied the table to an 11.2.0.2 DB sitting on a non-VM database server, SQL*Plus with the 4000 settings. I've made sure the table was cached for all these tests to eliminate PIO differences (which I would be able to account for anyway since the would be recorded in the trace). So, for both 10g VM and 11g non-vm, here's what we would see:

TRIPS:          534,073
ROWS:           300,700
LOBREADS:       233,700 (66,700 null nclobs)
LOBREAD TIME: 5.918873 seconds, median 24 microseconds, avg 25.3268 microsecond, with a few outlier on the high side, and a fastest of 23 microseconds.

Though the 10g trace doesn't record the LOBREADS, a 10051 trace would dump OPI calls, albeit without timing information. Total time was 6 minutes (11g non-vm) versus 8 minutes (10g, heavily loaded vm). Total db time "non-idle" time + unaccounted stayed right around 50 seconds for both environments, 46-48 for 11g and 50-52 for 10g test.

Though this is really starting to compare apples to oranges, the main things I was looking for were (1) to see how much accounted for time would fall under LOBREAD, and (2) to see if the bulk of the time still falls on SQL*Net message from client, just in case there was in issue in measurements around all the LOB activity in 10g. Lastly, there was some question if the VM layer was adding much. If we had shown completion in 10% - 20% of original times, then this would warrant looking into deeper, though it still could have been due to numerous other factors, not necessarily VM versus non-VM.

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 9:25 AM
> To: 'Oracle-L'
> Subject: Re: LOB Operation and SQL*Net Message From Client and cursor #0
>
>
> 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.)

--
http://www.freelists.org/webpage/oracle-l
Received on Sat May 04 2013 - 15:30:00 CEST

Original text of this message