Re: Why is the same CLOB datablock read multiple times?

From: Sayan Malakshinov <xt.and.r_at_gmail.com>
Date: Wed, 29 Jan 2014 00:59:11 +0400
Message-ID: <CAOVevU6YJJCapJHJVUdOgVsPTgF1KHOYYPm5dZk_41kg60LhwA_at_mail.gmail.com>



Sorry, I did not notice the version, and i was wrong about empty_lobs, because it can not effect to this.
May be nhibernate gets big lobs by pieces?

On Wed, Jan 29, 2014 at 12:24 AM, Jure Bratina <jure.bratina_at_gmail.com>wrote:

> Hi Sayan,
>
> All the CLOBs in the table have dbms_lob.getlength(lob_column) > 0. The 10
> records the problematic SQL returns have all approx. 280kB of data.
>
> Regarding securefiles, the database is 10.2.0.4, so there's no possibility
> to use securefiles.
>
> Thank you and regards
>
>
>
> On Tue, Jan 28, 2014 at 9:09 PM, Sayan Malakshinov <xt.and.r_at_gmail.com>wrote:
>
>> It looks like lobs was created with lob_column=empty_clob().
>> In that case you can try to update it like this: update tab set
>> lob_column=null where dbms_lob.get_length(lob_column)=0
>> Why do you use basic files? i think it would be better to use secure
>> files.
>>
>>
>> On Tue, Jan 28, 2014 at 11:57 PM, Jure Bratina <jure.bratina_at_gmail.com>wrote:
>>
>>> 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
>>>
>>
>>
>>
>> --
>> Best regards,
>> Sayan Malakshinov
>> Senior performance tuning engineer
>> PSBank
>> http://orasql.org
>>
>
>

-- 
Best regards,
Sayan Malakshinov
Senior performance tuning engineer
PSBank
http://orasql.org

--
http://www.freelists.org/webpage/oracle-l
Received on Tue Jan 28 2014 - 21:59:11 CET

Original text of this message