Flashback log file sync

From: Mladen Gogala <gogala.mladen_at_gmail.com>
Date: Sat, 12 May 2012 05:37:02 +0000 (UTC)
Message-ID: <pan.2012.05.12.05.37.02_at_gmail.com>

In the thread about LOB storage, Jonathan objected that I haven't really shown any numbers, which is true. I decided to fix my laziness and wrote a Perl script to load 614 files with approximately 2.3 GB of into a simple table having 3 columns: fileno, filename and content of type BLOB. While loading, I was also monitoring the script execution and wait events. The outcome is more than interesting:

 1 select event,time_waited,average_wait   2 from v$session_event
  3 where sid=204
  4* order by time_waited
SQL> / EVENT TIME_WAITED AVERAGE_WAIT

-------------------- ----------- ------------
Disk file operations	       0	  .02

 I/O

events in waitclass 0 .12
Other

log file sync		       1	  1.4
SQL*Net message to c	       1	    0

lient

log file switch comp 46 9.25

EVENT TIME_WAITED AVERAGE_WAIT

-------------------- ----------- ------------

letion

SQL*Net more data fr 988 0
om client

SQL*Net message from 1098 2.26
 client

db file sequential r 5617 1.49
ead

EVENT TIME_WAITED AVERAGE_WAIT

-------------------- ----------- ------------
direct path write	   18902	  .67
flashback log file s	   29509	 4.53

ync

direct path read 35703 1.29

11 rows selected.

The event which caused the most time to be spent waiting was, as is to be expected, "direct path read". After all, the script was loading BLOB objects into the database. The second most time consuming event was, quite unexpectedly, "flashback log file sync". Much, much more time was spent on writing flashback logs than on writing the redo logs. As opposed to redo log, flashback is a horrific monster. This data is for a user session, which means that flashback log file sync is happening synchronously. In other words, there is a very hefty performance price to be paid for flashback, much much more than for redo logs and recoverability. The mechanisms and parameters to control flashback are not exposed which means that there is no control over that mechanism. The only possibility is to turn it on and off. Apparently, flashback will exact a heavy performance penalty on the DML intensive applications.

The loading script worked well:

SQL> select bytes/1048576 from dba_segments   2 where owner='SCOTT' and

  3        segment_type='LOBSEGMENT' and
  4        segment_name='SYS_LOB0000087552C00003$$';

BYTES/1048576

---

         2304

Elapsed: 00:00:00.05
SQL> select count(*) from scott.bin_files;

  COUNT(*)

---

       614

Elapsed: 00:00:00.00
SQL> This is the original:
[mgogala_at_medo tmp]$ du -sh ~/mp3/misc 2.3G /home/mgogala/mp3/misc
[mgogala_at_medo tmp]$ ls /home/mgogala/mp3/misc|wc -l 614

This is the "business end" of the script:

my $dbh = db_connect("scott", "tiger"); my _at_files = glob("/home/mgogala/mp3/misc/*");

my $cnt   = 0;
my $ins   = "insert into bin_files values(?,?,?)";
my $sth=$dbh->prepare($ins);

foreach my $f (_at_files) {

    my $cont=slurp($f);
$sth->bind_param(1,$cnt++);
$sth->bind_param(2,$f);
$sth->bind_param(3,$cont,{ora_type=>SQLT_BIN});
$sth->execute();

}
$dbh->commit();

This is the target table:

SQL> desc scott.bin_files
 Name Null? Type

• --------

  ---

  FILENO NUMBER(4) FILENAME VARCHAR2(256) CONTENT BLOB SQL>

Version is 11.2.0.3, 64 bit on Linux, storage in row is disabled.

I will do some tests with deleting rows and re-loading the files and see whether the LOB segment will grow, but that will be another thread. This is only to show what a hefty performance penalty is exacted by having flashback turned on.

-- 
http://mgogala.byethost5.com

Received on Sat May 12 2012 - 00:37:02 CDT