Posted by I was doing some work for a client, and LOB processing seemed incredibly slow. After some poking around, it appears that LOB processing is quite sensitive when it comes to flashback mode in the database. Test bench is a simple table with three clobs. 4kb will be insert into each clob in 5000 individual inserts. The “wait” option is applied to the commit to ensure that the standard PLSQL commit optimizations do not come into play.
Database is 11.2.0.1 running in flashback mode.
SQL> create table t_nocache ( x1 clob, x2 clob, x3 clob )
2 lob ( x1 ) store as ( nocache )
3 lob ( x2 ) store as ( nocache )
4 lob ( x3 ) store as ( nocache )
5 ;
Table created.
SQL> set timing on
SQL> begin
2 for i in 1 .. 5000 loop
3 insert into t_nocache values (rpad('x',4000,'x'),rpad('x',4000,'x'),rpad('x',4000,'x'));
4 commit WRITE WAIT IMMEDIATE;
5 end loop;
6 end;
7 /
PL/SQL procedure successfully completed.
Elapsed: 00:00:13.21
So for NOCACHE, the elapsed time is 13 seconds, and then we can inspect where the time was lost:
SQL> @sessev
Sid required: 17
EVENT TOTAL_WAITS TOTAL_TIMEOUTS SECS PCT MAX_WAIT
-------------------------------------------- ----------- -------------- ---------- -------- ----------
Data file init write 2 0 0 00.00% 0
events in waitclass Other 2 0 0 00.00% 0
db file single write 2 0 0 00.00% 0
control file parallel write 14 0 0 00.00% 0
CPU 0 00.00% 0
log file switch (checkpoint incomplete) 2 0 .01 00.11% 1
log file switch completion 3 0 .01 00.11% 0
control file sequential read 70 0 .01 00.11% 0
Disk file operations I/O 11 0 .04 00.44% 1
db file sequential read 563 0 .13 01.44% 2
buffer busy waits 1 0 .25 02.77% 25
direct path write 14996 0 1.19 13.16% 2
log file sync 4999 0 1.82 20.13% 7
direct path read 14865 0 2.24 24.78% 4
flashback log file sync 14999 0 3.34 36.95% 9
15 rows selected.
SQL> select * from V$FLASHBACK_DATABASE_STAT;
BEGIN_TIME END_TIME FLASHBACK_DATA DB_DATA REDO_DATA ESTIMATED_FLASHBACK_SIZE
-------------------- -------------------- -------------- ---------- ---------- ------------------------
05-feb-2013 15:37:02 05-feb-2013 15:42:06 125911040 126820352 136450048 0
Test 1 – CACHE lob
SQL> create table t_cache ( x1 clob, x2 clob, x3 clob )
2 lob ( x1 ) store as ( cache )
3 lob ( x2 ) store as ( cache )
4 lob ( x3 ) store as ( cache )
5 ;
SQL> set timing on
SQL> begin
2 for i in 1 .. 5000 loop
3 insert into t_cache values (rpad('x',4000,'x'),rpad('x',4000,'x'),rpad('x',4000,'x'));
4 commit WRITE WAIT IMMEDIATE;
5 end loop;
6 end;
7 /
PL/SQL procedure successfully completed.
Elapsed: 00:00:07.89
So for CACHE, the elapsed time is 8 seconds, and then we can inspect where the time was lost:
SQL> @sessev
Sid required: 17
EVENT TOTAL_WAITS TOTAL_TIMEOUTS SECS PCT MAX_WAIT
-------------------------------------------- ----------- -------------- ---------- -------- ----------
Data file init write 1 0 0 00.00% 0
control file sequential read 35 0 0 00.00% 0
control file parallel write 7 0 0 00.00% 0
events in waitclass Other 1 0 0 00.00% 0
flashback log file sync 1 0 0 00.00% 0
CPU 0 00.00% 0
db file single write 1 0 0 00.00% 0
Disk file operations I/O 8 0 .02 00.38% 1
log file switch completion 1 0 .1 01.88% 10
buffer busy waits 1 0 .25 04.71% 25
log file switch (checkpoint incomplete) 2 0 .45 08.47% 45
log file sync 4998 0 1.24 23.35% 6
db file sequential read 7136 0 1.24 23.35% 4
db file scattered read 8415 0 2.01 37.85% 2
14 rows selected.
There is an increase in scattered read (ie, bringing blocks into the cache) but the flashback log sync wait has vanished.
SQL> select * from V$FLASHBACK_DATABASE_STAT;
BEGIN_TIME END_TIME FLASHBACK_DATA DB_DATA REDO_DATA ESTIMATED_FLASHBACK_SIZE
-------------------- -------------------- -------------- ---------- ---------- ------------------------
05-feb-2013 15:37:02 05-feb-2013 15:44:18 128581632 129851392 208777728 0
Flashback log size growth is minimal (ie it was already 125MB from the previous test, and had grown to 128M). Presumably as the flashback process kicks in from time to time in background, this would be expected to grow, but it is no longer synchronous to the foreground process.
Learning is not a spectator sport 
Great! Recently my customer asked me about possible ways to reduce flashback log amount. It seems that we can do something now.
Thank you.
Nice finding, have You tried with securefiles lobs ?
Regards
GregG
Connor, can I get a copy of your sessev.sql ? Thanks
Apologies I should have posted it
undefine sid
accept sid prompt ‘Sid (Default=this session): ‘
col event format a44
select EVENT
,TOTAL_WAITS
,TOTAL_TIMEOUTS
,SECS
,rpad(to_char(100 * ratio_to_report(secs) over (), ‘FM00.00’) || ‘%’,8) pct
,max_wait
from (
select EVENT
,TOTAL_WAITS
,TOTAL_TIMEOUTS
,TIME_WAITED/100 SECS
,max_wait
from v$session_event
where sid = nvl(to_number(‘&sid’), ( select sys_context(‘USERENV’,’SID’) from dual ))
and event not like ‘SQL*Net%’
union all
select ‘CPU’, null, null, value/100 , 0 from v$sesstat
where statistic# = ( select statistic# from v$statname where name = ‘CPU used by this session’)
and sid = nvl(to_number(‘&sid’), ( select sys_context(‘USERENV’,’SID’) from dual ))
order by 4
)
/
undefine sid