LOB reads

This is a blog note that started life in September 2001 (which was before I started blogging, I think), got drafted as a blog in January 2014 because of a question on the Oracle-L list server, and has finally got to publication following a question on the ODC database forum. (But the comments in the blog don’t look as if they are relevant to the question.)

The question on Oracle-l was:  Why is the same CLOB datablock read multiple times?

The answer is basically: client programs tend to set a “sensible” fetch buffer size for LOBs and if the buffer size is less than the size of the LOB the block(s) the LOB is in have to be visited multiple times and for nocache LOBs that means the block(s) will be read multiple times.

This can be seen quite easily in SQL*Plus which has two helpful parameters (one dating back to at least v5):

set long N
set longchunksize M

The “long” setting tells SQL*Plus how much of the LOB to display on screen, the “longchunksize” tells SQL*Plus how much of the LOB to fetch from the database on each call. The default value is 80 for both settings. So let’s set up some data and do a few simple demonstrations using nothing more subtle than autotrace.

rem
rem     Script:         lob_fetch_2.sql
rem     Author:         Jonathan Lewis
rem     Dated:          July 2012
rem     Purpose:        
rem
rem     Last tested 
rem             18.3.0.0
rem             12.1.0.2
rem             11.2.0.2
rem

create table t1 (
        id      number , 
        v1      varchar2(60),
        c1      clob, 
        c2      clob
)
lob(c1) store as (enable storage in row cache)
lob(c2) store as (enable storage in row cache)
;

begin
        for i in 1..1000 loop
                insert into t1 values(i, lpad(i,60), lpad(i,60), empty_clob());
        end loop;
        commit;
end;
/

execute dbms_stats.gather_table_stats(null,'t1')

I’ve got a table with two CLOB columns, both declared to enable storage in row and cache. I’ve also got a varchar2() column, and I’ve loaded one of the CLOB columns and the varchar2() column with a 60 character string, setting the other CLOB column explicitly to the empty_clob() value – which is not the same as setting it to NULL.

Now I’ll do 3 selects, fetching the id column and one other column, showing only the autotrace statistics:

set long 80
set longchunksize 80

set arraysize 5000

set autotrace traceonly statistics

prompt  ==============
prompt  Varchar2 fetch
prompt  ==============

select id, v1 from t1;

prompt  ================
prompt  Small CLOB fetch
prompt  ================

select id, c1 from t1;

prompt  ================
prompt  Empty CLOB fetch
prompt  ================

select id, c2 from t1;

set autotrace off

I’ve explicitly set long and longchunksize to 80 (the defaults) just to make it clear that that’s what they are for this test; and I’ve set the arraysize to 5000 so that I can get the 1,000 rows of data in the smallest number of fetches. Here are the three sets of autotrace statistics:

==============
Varchar2 fetch
==============

1000 rows selected.


Statistics
----------------------------------------------------------
         11  recursive calls
         11  db block gets
         75  consistent gets
          0  physical reads
       2040  redo size
      70545  bytes sent via SQL*Net to client
        624  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
       1000  rows processed

================
Small CLOB fetch
================

1000 rows selected.


Statistics
----------------------------------------------------------
          4  recursive calls
          5  db block gets
       2036  consistent gets
          0  physical reads
        992  redo size
     707454  bytes sent via SQL*Net to client
     296624  bytes received via SQL*Net from client
       2002  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
       1000  rows processed

================
Enpty CLOB fetch
================

1000 rows selected.


Statistics
----------------------------------------------------------
          3  recursive calls
          5  db block gets
       2036  consistent gets
          0  physical reads
       1048  redo size
     585454  bytes sent via SQL*Net to client
     296624  bytes received via SQL*Net from client
       2002  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
       1000  rows processed

Key points to note (ignoring minor details like the recursive calls to parse the statements):

• The query for the the varchar2() column did two SQL*Net roundtrips and 75 consistent gets.
• The query for the small, inline, CLOB did 2,002 SQL*Net roundtrips and 2,036 consistent gets
• The query for the empty CLOB did exactly the same number of SQL*Net roundtrips and consistent gets as for the small CLOB

Because we were selecting a LOB column SQL*Plus switched from array fetches to single row fetches. In the first fetch of each pair of fetches it fetched the non-CLOB columns and the “LOB locator”; then in the second fetch of each pair it fetched the CLOB data – and it did this even when the LOB locator could (in principle) have told it that there was no data to fetch. (If you select both clob columns in the same query the number of SQL*Net roundtrips will go up to 3 per row in this test.)

Remember I said there was a difference between empty_clob() and NULL ? If you update the table to set c2 to null before running the query to select c2 you’ll see only 1,000 (and a few) SQL*Net roundtrips – you still get single row processing because you’re selecting a LOB column but when the NULL  arrives at SQL*Plus the code will know that there is no LOB data to retrieve.

Now try this:

truncate table t1;

begin
        for i in 1..1000 loop
                insert into t1 values(i, lpad(i,60), lpad(i,180), empty_clob());
        end loop;
        commit;
end;
/

execute dbms_stats.gather_table_stats(null,'t1')

set long 170
select id, c1 from t1;

Pause for thought as you work out what the stats will look like
.
.
.
.
.
The longchunksize (still at the default of 80) is now too small to collect all the data that should be displayed in one SQL*Net roundtrip – it’s going to take 3 roundtrips to get 170 bytes, so we might expect to see about 4,000 SQL*Net roundtrips and a similar number of consistent gets. This is what the stats look like:

Statistics
----------------------------------------------------------
          2  recursive calls
          0  db block gets
       4030  consistent gets
          0  physical reads
          0  redo size
    1485454  bytes sent via SQL*Net to client
     866624  bytes received via SQL*Net from client
       4002  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
       1000  rows processed

Sure enough we do single row fetches, one SQL*Net roundtrip for each row with its LOB locator, then three more roundtrips for each LOB for a total of 4,000 round trips and (approximately) 4,000 consistent gets.

One last test – let’s change the c1 clob to nocache and disable storage in row then repeat the last experiment where the long setting is larger than the longchunksize setting.

alter table t1 move lob(c1) store as (disable storage in row nocache);
execute dbms_stats.gather_table_stats(null,'t1')
select id, c1 from t1;

Statistics
----------------------------------------------------------
          2  recursive calls
          0  db block gets
       4001  consistent gets
       6000  physical reads
          0  redo size
    1485454  bytes sent via SQL*Net to client
     866624  bytes received via SQL*Net from client
       4002  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
       1000  rows processed

Now there’s a surprise!  I was expecting to see 3000 physical reads as each “out of row, nocache” LOB was accessed three times to pick up the three pieces of longchunksize using direct path reads. So why have I got 6,000 physical reads? Time to enable extended tracing (event 10046, level 8) and repeat.

Here’s a sample from the trace file – this trace is from 18.3, but the LOBREAD lines are a feature that appeared some time around 11.2.0.2.

FETCH #140355181475400:c=58,e=57,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=3617692013,tim=5288719901
WAIT #140355181475400: nam='SQL*Net message from client' ela= 78 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288720015

WAIT #0: nam='direct path read' ela= 12 file number=2 first dba=2867 block cnt=1 obj#=132008 tim=5288720198
WAIT #0: nam='direct path read' ela= 8 file number=2 first dba=2867 block cnt=1 obj#=132008 tim=5288720288
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288720326
LOBREAD: type=PERSISTENT LOB,bytes=80,c=247,e=246,p=2,cr=1,cu=0,tim=5288720350

WAIT #0: nam='SQL*Net message from client' ela= 82 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288720483
WAIT #0: nam='direct path read' ela= 12 file number=2 first dba=2867 block cnt=1 obj#=132008 tim=5288720733
WAIT #0: nam='direct path read' ela= 8 file number=2 first dba=2867 block cnt=1 obj#=132008 tim=5288720836
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288720873
LOBREAD: type=PERSISTENT LOB,bytes=80,c=0,e=261,p=2,cr=1,cu=0,tim=5288720898

WAIT #0: nam='SQL*Net message from client' ela= 121 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288721071
WAIT #0: nam='direct path read' ela= 11 file number=2 first dba=2867 block cnt=1 obj#=132008 tim=5288721216
WAIT #0: nam='direct path read' ela= 8 file number=2 first dba=2867 block cnt=1 obj#=132008 tim=5288721300
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288721335
LOBREAD: type=PERSISTENT LOB,bytes=20,c=0,e=236,p=2,cr=1,cu=0,tim=5288721359

WAIT #0: nam='SQL*Net message from client' ela= 73 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288721506
WAIT #140355181475400: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288721664
FETCH #140355181475400:c=51,e=51,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=3617692013,tim=5288721695
WAIT #140355181475400: nam='SQL*Net message from client' ela= 74 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288721801

WAIT #0: nam='direct path read' ela= 12 file number=2 first dba=2868 block cnt=1 obj#=132008 tim=5288721939
WAIT #0: nam='direct path read' ela= 47 file number=2 first dba=2868 block cnt=1 obj#=132008 tim=5288722065
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288722122
LOBREAD: type=PERSISTENT LOB,bytes=80,c=357,e=357,p=2,cr=1,cu=0,tim=5288722204

WAIT #0: nam='SQL*Net message from client' ela= 81 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288722351
WAIT #0: nam='direct path read' ela= 10 file number=2 first dba=2868 block cnt=1 obj#=132008 tim=5288722489
WAIT #0: nam='direct path read' ela= 11 file number=2 first dba=2868 block cnt=1 obj#=132008 tim=5288722671
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288722720
LOBREAD: type=PERSISTENT LOB,bytes=80,c=0,e=349,p=2,cr=1,cu=0,tim=5288722746

WAIT #0: nam='SQL*Net message from client' ela= 76 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288722874
WAIT #0: nam='direct path read' ela= 11 file number=2 first dba=2868 block cnt=1 obj#=132008 tim=5288723013
WAIT #0: nam='direct path read' ela= 10 file number=2 first dba=2868 block cnt=1 obj#=132008 tim=5288723160
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=132008 tim=5288723199
LOBREAD: type=PERSISTENT LOB,bytes=20,c=0,e=302,p=2,cr=1,cu=0,tim=5288723224

As you can see, the client seems to FETCH one row then do two direct path reads to read 80 bytes from a LOB, then another two direct path reads for the next 80 bytes, then another two direct path reads for the last 20 bytes. So the 6,000 reads is (strangely) doubling the 3,000 I was expecting to see and the trace file seems to say it’s really happening that way.

Unfortunately I decided to take snapshots of the session stats at this point – and that made things even worse (claiming, for example, 4,000 “consistent gets” but 7,000 “no work consistent gets”), the stats seem to be rather messed up and the whole thing looked very different when I ran this particular test on 12.1.0.2 (which claimed only one direct path read per CLOB rather than the three I was expecting).

Bottom line, though: notwithstanding any oddities of reporting, when your client progam is fetching LOBs from the database, you probably have to put up with:
single row fetches – that get the LOB locator then multiple fetches for each LOB, with the number of LOBREAD calls dependent on the buffer size the client allocates for pulling LOB data from the database.

So when handling LOBs make sure you know how the client can be configured to minimise SQL*Net roundtrips, and check a few simple examples looking at the the trace files, session stats and session events before you start loading data at production volumes.

Update (Sept 2021)

There have been some significant changes of mechanism (or maybe of counting) by the time we get to 21c. We still see single row processing taking place in SQL*Plus if there’s a LOB in the select list, and LOB data being fetched through extra visits to the server; but:

• the SQL*Net roundtrips due to the LOB fetching may not be counted
• multiple “small enough” LOBs for a single row may be fetched in the same LOB read (to be tested),
• there’s an SQL*Plus setting “set lobprefetch N” which defaults to 0 but can be set as high as 32767 to allow “small enough” LOBs to be fetched in the same round trip as the row itself (though it’s still single row fetches). If you “set markup csv on”, the lobprefetch is one of the setting that is automatically changed at the same time.
• you really need to remember that with “max_string_size = extended”, declarations of strings in excess of the old 4,000 byte limit will be stored internally as LOBs; and a “create table as select” may give you a load of LOB columns that you don’t really really you’ve got.  (And 3rd party “database-agnistic” tools may create some “text” columns that are also “inivisibly” created as LOBs.)