Why is the same CLOB datablock read multiple times?

  • From: Jure Bratina <jure.bratina@xxxxxxxxx>
  • To: oracle-l@xxxxxxxxxxxxx
  • Date: Tue, 28 Jan 2014 20:57:59 +0100

Hi,

I have a question about the high number of reads on a LOB on a 10.2.0.4.0
64bit instance. The problem I'm facing is that selecting a CLOB column
(from nhibernate) causes many reads from the same data block, e.g. :

WAIT #0: nam='direct path read' ela= 442 file number=5 first dba=59461
block cnt=1 obj#=199184 tim=5566091808
WAIT #0: nam='SQL*Net message from client' ela= 4034 driver id=1413697536
#bytes=1 p3=0 obj#=199184 tim=5566095873
WAIT #0: nam='direct path read' ela= 152 file number=5 first dba=59461
block cnt=1 obj#=199184 tim=5566096110
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1413697536
#bytes=1 p3=0 obj#=199184 tim=5566096127
WAIT #0: nam='SQL*Net message from client' ela= 3942 driver id=1413697536
#bytes=1 p3=0 obj#=199184 tim=5566100094
WAIT #0: nam='direct path read' ela= 173 file number=5 first dba=59461
block cnt=1 obj#=199184 tim=5566100334
WAIT #0: nam='SQL*Net message to client' ela= 0 driver id=1413697536
#bytes=1 p3=0 obj#=199184 tim=5566100351
WAIT #0: nam='SQL*Net message from client' ela= 5277 driver id=1413697536
#bytes=1 p3=0 obj#=199184 tim=5566105655
..
[the set of three wait events 'direct path read', 'SQL*Net message to
client' and 'SQL*Net message from client' repeats 14 more times for the
same dba=59461]


So in total the datablock [file_id=5, dba=59461] was read 17 times. The
same happens to other LOB's data blocks. The CLOB is NOCACHE, if I set it
to CACHE the datablock is read only once using 'db file sequential read'
but the SQLNet roundtrips are still present so I guess the difference is
that the first read is from disk, all subsequent reads are served from the
buffer cache and thus no wait event is reported. The data block in question
is a LOB segment block:

Start dump data blocks tsn: 6 file#: 5 minblk 59461 maxblk 59461
buffer tsn: 6 rdba: 0x0140e845 (5/59461)
scn: 0x0000.2be1ebfd seq: 0x02 flg: 0x04 tail: 0xebfd2802
frmt: 0x02 chkval: 0xbad9 type: 0x28=PAGETABLE MANAGED LOB BLOCK

On the other hand if I execute the same query from sqlplus, the LOB's
datablocks are read only once, so the wait events are like this:

WAIT #1: nam='SQL*Net message from client' ela= 146 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6160998955
WAIT #0: nam='direct path read' ela= 11114 file number=5 first dba=59512
block cnt=1 obj#=199184 tim=6161011019
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161012052
WAIT #0: nam='SQL*Net message from client' ela= 3499 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161016400
WAIT #1: nam='SQL*Net message to client' ela= 1 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161017406
FETCH #1:c=0,e=878,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,tim=6161018232
WAIT #1: nam='SQL*Net message from client' ela= 93 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161019249
WAIT #0: nam='direct path read' ela= 8232 file number=5 first dba=59435
block cnt=1 obj#=199184 tim=6161028564
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161029587
WAIT #0: nam='SQL*Net message from client' ela= 3989 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161034417
WAIT #1: nam='SQL*Net message to client' ela= 1 driver id=1111838976
#bytes=1 p3=0 obj#=199184 tim=6161035376
FETCH #1:c=0,e=860,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,tim=6161036189
......

I still get a direct path read for every row the SQL returns, but the same
block doesn't get read multiple times and what's even more important, that
way I avoid waiting for the network roundtrips (SQL*Net message from/to
client) which actually constitute the biggest part of this SQL's response
time. Is there any apparent reason why there are multiple reads on the same
data block?

Thank you in advance for any suggestions

Regards,
Jure Bratina

Other related posts: