LOG_BUFFER, "log file sync" and Oracle 10g

[peter_strauss]

Hello,

In Oracle 10g I believe that the value of LOG_BUFFER is determined dynamically, and can be as high as 14MB or thereabouts.

In Oracle 9i the size of LOG_BUFFER (as recommended by SAP) was around 1MB.

My understanding is that "log file sync" is time waited by shadow processes during the writing of the log buffer to online redo log files, which happens with every COMMIT, whenever the log buffer reaches 1/3 full, or every three seconds.

My question is why do we still expect average "log file sync" times in Oracle 10g to be below 15ms?

Say I have a system that has very high DML activity, but relatively low frequency of COMMITS. Then the Oracle 10g log buffer would be nearly 5MB before it was written to a log file.

Wouldn't this mean high average "log file sync" times would occur (higher than for 9i at least)? Or is this view of things unrealistic; do COMMITS actually happen too frequently to ever allow the log buffer to get so large?

Kind regards,

Peter

[stefan_koehler · Accepted solution]

Hello Peter,

>> In Oracle 10g I believe that the value of LOG_BUFFER is determined dynamically, and can be as high as 14MB or thereabouts.

That is correct.

>> My question is why do we still expect average "log file sync" times in Oracle 10g to be below 15ms?

>> Say I have a system that has very high DML activity, but relatively low frequency of COMMITS. Then the Oracle 10g log buffer would be nearly 5MB before it was written to a log file.

You forget the last point of the documentation "or every three seconds.", so the LGWR writes every 3 seconds periodically to the redolog log files.

The other thing is that you also have "internal flush outs" out of the log buffer - for example:

http://download.oracle.com/docs/cd/B19306_01/server.102/b14237/initparams068.htm#i1127412

If you reach your defined crash recovery time, the DBWR writes the needed dirty blocks down to the datafiles, but before he can do that, he tells the LGWR to flush down the corresponding log buffers if necessary (write-ahead protocol). The DBWR looks every three seconds for that dirty buffer queue to avoid massive i/o after FAST_START_MTTR_TARGET.

There are several more internal actions that force the same.

You can check the statistic "user commits" for checking your user commit rate:

select value from v$sysstat where name = 'user commits'; 

Regards

Stefan

[peter_strauss · Accepted solution]

Hi Stefan,

I was told back in training that the three second limit is almost never reached in an SAP system because the amount of DML activity in a live system is so high that the log buffer fills to one third more frequently than once every three seconds.

You can check the statistic "user commits" for checking your user commit rate:
select value from v$sysstat where name = 'user commits'; 

I get a big number for this. Is it number of commits since startup?

Regards,

Peter

[stefan_koehler · Accepted solution]

Hello Peter,

> I was told back in training that the three second limit is almost never reached in an SAP system because the amount of DML activity in a live system is so high that the log buffer fills to one third more frequently than once every three seconds.

Yeah that is maybe true (i have never investigated this part until now), but i can not imagine that round about over 4 MB of the log buffer are filled within 3 seconds. Maybe this statement is based on a smaller log buffer...

> I get a big number for this. Is it number of commits since startup?

Yes you are right, v$sysstat displays the cumulated statitics since startup of the database.

You can calculate your commit rate for the instance by : <Uptime in seconds> / <commit rate>

There you can see, which limit is hit most of the time. (in the average)

Regards

Stefan

[peter_strauss · Accepted solution]

It still seems to me that there would tend to be much more to write out from the log buffer.

So should we be more forgiving of higher "log file sync" wait times than in 9i with a 1MB log buffer? Should we raise our expectations from the 15ms listed in note 619188?

Regards,

Peter

[stefan_koehler · Accepted solution]

Hello Peter,

>> So should we be more forgiving of higher "log file sync" wait times than in 9i with a 1MB log buffer?

It depends:

- Is the environment (hardware, disks, release, etc.) exactly the same?

- Is the load on the database the same?

If you have a 1 MB log buffer with Oracle 9i, the write cycle changes and can have effects on the performance.

Please have a look at the blog of Christian Bilien, there is a very important information with a nice proof: http://christianbilien.wordpress.com/2007/03/28/log-buffer-issues-in-10g-12/

http://christianbilien.wordpress.com/2007/03/28/log-buffer-issues-in-10g-22/

=> When the log buffer is 1/3 full or the total of redo entries is 1MB (default LOGIO_SIZE), whichever case occurs first.

>> Should we raise our expectations from the 15ms listed in note 619188?

To be honest, in our biggest SAP system (now round about 3.6 TB and with round about 2.200 concurrent users) we have an average "log file sync" from round about 7 ms. We use a SAN environment.

I am a little bit snoopy now:

- Do you have performance problems?

- What is your average wait time on log file sync?

Regards

Stefan

[peter_strauss · Accepted solution]

Hello Martin,

Thanks for those performance blog links. I've been looking for some good study material like this.

My question was theoretical, and I was assuming that everything except the Oracle version was the same.

And yes, you are right! I am sitting here with a real log file sync performance problem on my hands.

The customer is in testing and during the tests we are seeing log file sync times up as high as 100ms, which I guess is bad however you look at it. When I was looking into this and saw that the size of the log buffer is much bigger in 10g it got me wondering...

Your real live example is very helpful. I'm slowly getting a grip on the theory but I lack experience so sometimes I don't know what to expect from a system.

The customer I am dealing with only has about 1.5TB and a few hundred concurrent users.

Regards,

Peter

[stefan_koehler · Accepted solution]

Hello Peter,

i didn't change my name and you can call me Stefan furthermore

>> The customer is in testing and during the tests we are seeing log file sync times up as high as 100ms, which I guess is bad however you look at it.

Yeah i would call it bad, too. Maybe some of my experience with that:

I have simulated some i/o stress in the past and i have found out that everything > 150 ms has really bad impacts on our production system. (especially in spooling - semaphore 43), but this was only bad for our environment.. in some other cases it can be still good enough.

I would do the following things:

- Take a look at the disk design at OS level

- Take a look at the hardware (especially CPU and i/o values)

If all these checks / values are ok (maybe the hardware is really not faster), than i would contact sap and ask for the LOGIO_SIZE.. as i can see you are a sap employee you have better connections to that guys than us (the customers)

Wish you goold luck

Regards

Stefan

[stefan_koehler · Accepted solution]

Hello Peter,

i have to correct my wait time values (i have mixed the two values):

- log file sync / 16 ms

- log file parallel write / 7 ms

http://download.oracle.com/docs/cd/B19306_01/server.102/b14237/waitevents003.htm#sthref3120

http://download.oracle.com/docs/cd/B19306_01/server.102/b14237/waitevents003.htm#sthref3104

Regards

Stefan