数据库alert出现Private strand flush not complete信息

dayson

Hi,maclen:
     最近遇到这样一个问题，我在为数据库加大redo和增加redo日志组后，每当数据库发生切换日志前（包括手工切换），alert日志都会产生如下告警信息：
Wed Apr 25 19:54:56 2012
Thread 1 cannot allocate new log, sequence 24289
Private strand flush not complete
  Current log# 1 seq# 24288 mem# 0: /db01/app/system/CLE812/redo01_01.log
  Current log# 1 seq# 24288 mem# 1: /db01/app/system/CLE812/redo01_02.log
Thread 1 advanced to log sequence 24289 (LGWR switch)
  Current log# 2 seq# 24289 mem# 0: /db01/app/system/CLE812/redo02_01.log
  Current log# 2 seq# 24289 mem# 1: /db01/app/system/CLE812/redo02_02.log
Wed Apr 25 19:54:57 2012
Archived Log entry 988 added for thread 1 sequence 24288 ID 0xffffffff91ea48eb dest 1:
通过检查redo状态，发现一切正常
SQL> select * from v$log;

    GROUP#    THREAD#  SEQUENCE#      BYTES  BLOCKSIZE    MEMBERS ARCHIVED STATUS           FIRST_CHANGE# FIRST_TIME  NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- -------- ---------------- ------------- ----------- ------------ -----------
         1          1      24288  524288000        512          2 YES      INACTIVE             340125485 2012-4-25 1    340212844 2012-4-25 1
         2          1      24289  524288000        512          2 NO       CURRENT              340212844 2012-4-25 1 281474976710
         3          1      24285  524288000        512          2 YES      INACTIVE             339543243 2012-4-25 9    339736138 2012-4-25 1
         4          1      24286  524288000        512          2 YES      INACTIVE             339736138 2012-4-25 1    339942592 2012-4-25 1
         5          1      24287  524288000        512          2 YES      INACTIVE             339942592 2012-4-25 1    340125485 2012-4-25 1
检查db_wrirte_processes 发现此参数设置为8
SQL> show parameter db_write_

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_writer_processes                  integer     8

此参数对于16核的系统来说，并不小。
此库为运行在AIX6.1上的oracle 11.2.0.2.0的一个单实例库，另外一个运行在linux上的oracle 11.2.0.1.0的库在调整redo后，也出现类似情况。前台业务并未出现异常。

真心希望能得到您的帮助，谢谢！

Maclean Liu(刘相兵

Private strand flush not complete

==》 这是由 9i以后的 log parallelism 特性造成的告警 ， 一般可以忽略该问题


Advise:

1.  可以忽略该问题

2.  禁用 in memory undo 特性 可以 避免 "Private strand flush not complete" 信息出现在alert.log 中 ，对于10g以后的Oracle数据库 禁用 in memory undo特性 可能会造成5%以内的性能损失


SQL> alter system set "_in_memory_undo" = FALSE scope=both;

System altered.

Maclean Liu(刘相兵

ODM FINDING:

Alert Log Messages: Private Strand Flush Not Complete

Applies to:
Oracle Server - Enterprise Edition - Version: 10.2.0.1 to 11.2.0.3 - Release: 10.2 to 11.2
Information in this document applies to any platform.


Private strand flush not complete
Symptoms
"Private strand flush not complete" messages are being populated to the alert log, example:

Mon Jan 23 16:09:36 2012
Thread 1 cannot allocate new log, sequence 18358
Private strand flush not complete
Current log# 7 seq# 18357 mem# 0: /u03/oradata/bitst/redo07.log
Thread 1 advanced to log sequence 18358
Current log# 8 seq# 18358 mem# 0: /u03/oradata/bitst/redo08.log
>>

>>
Changes

When you switch logs all private strands have to be flushed to the current log before the switch is allowed to proceed.
Cause

The message means that we haven't completed writing all the redo information to the log when we are trying to switch. It is similar in nature to a "checkpoint not complete" except that is only involves the redo being written to the log. The log switch can not occur until all of the redo has been written.

A "strand" is new terminology for 10g and it deals with latches for redo .

Strands are a mechanism to allow multiple allocation latches for processes to write redo more efficiently in the redo buffer and is related to the log_parallelism parameter present in 9i.

The concept of a strand is to ensure that the redo generation rate for an instance is optimal and that when there is some kind of redo contention then the number of strands is dynamically adjusted to compensate.

The initial allocation for the number of strands depends on the number of CPU's and is started with 2 strands with one strand for active redo generation.

For large scale enterprise systems the amount of redo generation is large and hence these strands are *made active* as and when the foregrounds encounter this redo contention (allocated latch related contention) when this concept of dynamic strands comes into play.

There is always shared strands and a number of private strands .

Oracle 10g has some major changes in the mechanisms for redo (and undo), which seem to be aimed at reducing contention.

Instead of redo being recorded in real time, it can be recorded 'privately' and pumped into the redo log buffer on commit.

Similarly the undo can be generated as 'in memory undo' and applied in bulk. This affect the memory used for redo management and the possibility to flush it in pieces. The message you get is related to internal Cache Redo File management.

...You can disregard these messages as normal messages.
Solution

These messages are not a cause for concern unless there is a significant time gap between the "cannot allocate new log" message and the "advanced to log sequence" message.

Increasing the value for db_writer_processes can in some situations avoid the message from being generated.



Hdr: 7005709 10.2.0.3 RDBMS 10.2.0.3 TXN MGMT LOCAL PRODID-5 PORTID-59
Abstract: LOG FILE SWITCH (PRIVATE STRAND FLUSH INCOMPLETE) WHEN _IN_MEMORY_UNDO=TRUE

PROBLEM:
--------
Oracle 10.2.0.3.0
This is a large database for Oracle Applications plus a lot of custom code.   

Last night a user noticed slowness between 9 and 10 pm.  When we now run AWR
and ADDM reports, we see high waits for "log file switch (private strand
flush
incomplete)".  

This looks similar to Bug 6806770 except that we're HPUX 11.11, non-Itanium.  

As per the bug, we currently have _in_memory_undo=TRUE.  
We had this setting set to false  for a while as a workaround for another bug

(5028099), but re-enabled it after  applying a patch (6733906).

$ >grep memory spfilecfap.ora
*._in_memory_undo=TRUE

DIAGNOSTIC ANALYSIS:
--------------------
One night a user noticed slowness between 9 and 10 pm.  When we now
run AWR and ADDM reports, we see high waits for "log file switch (private
strand flush incomplete)".

We had _in_memory_undo=FALSE from Jan 15 until March 16, when we applied
patch 6733906.  Before Jan 15, we had numerous alert log messages like what's
below.  Since Mar 16, we've had approx. 25 more of these messages.  In
between Jan 15 and Mar 16 we had none of the messages.  

Thread 1 cannot allocate new log, sequence 92288
Private strand flush not complete

WORKAROUND:
-----------
The only workaround is to set parameter  _in_memory_undo = FALSE  to disable
IMU

RELATED BUGS:
-------------
6806770 - still at status 11



Slow Running User Process And Top Database Wait Event Is 'log file switch (private strand flush incomplete)'


Applies to:
Oracle Server - Enterprise Edition - Version: 10.2.0.1 to 10.2.0.3 - Release: 10.2 to 10.2
Information in this document applies to any platform.
Symptoms
Checked for relevance on 31-Oct-2011

A user process is running very slow and the top database wait event is always 'log file switch (private strand flush incomplete)'.

AWR Report shows the following Top 5 Timed Events.

    log file switch (private strand flush incomplete)
    buffer busy waits
    log file sync
    db file sequential read
    log file switch (checkpoint incomplete)

Cause
Unpublished Bug 5605290 which causes deadlocks between the CKPT and LGWR or DBWR processes, and can manifest itself in many ways.
Solution
Unpublished Bug 5605290 is fixed in the 10.2.0.4 patchset, so applying it will resolve this issue.  In addition there is a workaround available to prevent the problem until able to get the database patched up.

sqlplus / as sysdba
alter system set "_in_memory_undo" = FALSE scope=both;

dayson

Thanks very much !