Logwriter I/O

Posted by

If you are on any version of the database past 10.2.0.4, then savvy DBA’s may have noticed the following message popping up occasionally in their trace files


Warning: log write time 540ms, size 444KB

In itself, that is quite a nice little addition – an informational message letting you know that perhaps your log writer performance is worth closer investigation.  MOS Note 601316.1 talks a little more about this message.

So let’s say you have seen this warning, and you are interested in picking up more information.  Well… you could start scanning trace files from time to time, and parsing out the content etc, or do some analysis perhaps using Active Session History, but given that these warnings are (by default) triggered at above 500ms, there’s a chance you might miss them via ASH.

In 12c, this has become a lot simpler – because it looks like the same data is now exposed via a view, v$lgwrio_outlier


sql> select function_name,io_size,file_name,io_latency
  2  from   V$LGWRIO_OUTLIER;

FUNCTION_NAME IO_SIZE FILE_NAME                        IO_LATENCY
------------- ------- ------------------------------- -----------
LGWR               16 /u03/oradata/MYDB/control01.ctl         745
LGWR               16 /u03/oradata/MYDB/control01.ctl         506
LGWR               12 /u02/oradata/MYDB/redo09.dbf            705
LGWR                1 /u02/oradata/MYDB/redo08.dbf            502
LGWR                5 /u02/oradata/MYDB/redo07.dbf            538
LGWR              211 /u02/oradata/MYDB/redo10.dbf           1783
LGWR             1024 /u02/oradata/MYDB/redo10.dbf            597
LGWR                0 /u02/oradata/MYDB/redo10.dbf            597
LGWR               10 /u02/oradata/MYDB/redo10.dbf            597
LGWR                2 /u02/oradata/MYDB/redo10.dbf            775
LGWR                0 /u02/oradata/MYDB/redo07.dbf            683
LGWR                0 /u02/oradata/MYDB/redo09.dbf            704
LGWR                1 /u02/oradata/MYDB/redo10.dbf            504
LGWR                0 /u02/oradata/MYDB/redo10.dbf            690
LGWR               16 /u03/oradata/MYDB/control01.ctl         504
LGWR               58 /u02/oradata/MYDB/redo08.dbf            705 
LGWR                1 /u02/oradata/MYDB/redo08.dbf            704
...

Obviously the trace files are also tagged with the timestamp of occurrence, whereas the view does not expose this infromation.

But let’s just say two things here – (a) where there is a will there is a way, and (b) like most V$ views, it is based on an X$ object, which might contain more information Smile

For other types of I/O in the database, you can also take a look at V$IO_OUTLIER

Got some thoughts? Leave a comment

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.