报ORA-00338: 日志 3 (用于线程 2) 比控制文件更新错误

lxhbww

请教各个大侠solaris10u10+oracle11.2.0.2 二节点rac+active dg
在二个节点都有时会报如下错误
节点一
Mon May 07 23:20:23 2012
Errors in file /app/oracle/diag/rdbms/xxxxx/xxxxx1/trace/xxxxx1_nsa2_17394.trc:
ORA-00338: 日志 2 (用于线程 1) 比控制文件更新
ORA-00312: 联机日志 2 线程 1: '+ORAARCH/xxxxx/onlinelog/group_2.98799.770934459'
ORA-00338: 日志 2 (用于线程 1) 比控制文件更新
ORA-00312: 联机日志 2 线程 1: '+ORADATA/xxxxx/onlinelog/group_2.266.770934457'
Errors in file /app/oracle/diag/rdbms/xxxxx/xxxxx1/trace/xxxxx1_nsa2_17394.trc:
ORA-00338: 日志 2 (用于线程 1) 比控制文件更新
ORA-00312: 联机日志 2 线程 1: '+ORAARCH/xxxxx/onlinelog/group_2.98799.770934459'
ORA-00338: 日志 2 (用于线程 1) 比控制文件更新
ORA-00312: 联机日志 2 线程 1: '+ORADATA/xxxxx/onlinelog/group_2.266.770934457'
Mon May 07 23:20:23 2012
Thread 1 advanced to log sequence 69279 (LGWR switch)

Current log# 1 seq# 69279 mem# 0: +ORADATA/xxxxx/onlinelog/group_1.257.770934453

Current log# 1 seq# 69279 mem# 1: +ORAARCH/xxxxx/onlinelog/group_1.257.770934455
Archived Log entry 257114 added for thread 1 sequence 69278 ID 0xf6470f0 dest 1:
Thread 1 cannot allocate new log, sequence 69280
Checkpoint not complete

Current log# 1 seq# 69279 mem# 0: +ORADATA/xxxxx/onlinelog/group_1.257.770934453

Current log# 1 seq# 69279 mem# 1: +ORAARCH/xxxxx/onlinelog/group_1.257.770934455

节点二
ORA-00338: 日志 3 (用于线程 2) 比控制文件更新
ORA-00312: 联机日志 3 线程 2: '+ORAARCH/xxxxx/onlinelog/group_3.98800.770934463'
ORA-00338: 日志 3 (用于线程 2) 比控制文件更新
ORA-00312: 联机日志 3 线程 2: '+ORADATA/xxxxx/onlinelog/group_3.265.770934461'
Errors in file /app/oracle/diag/rdbms/xxxxx/xxxxx2/trace/xxxxx2_nsa2_6578.trc:
ORA-00338: 日志 3 (用于线程 2) 比控制文件更新
ORA-00312: 联机日志 3 线程 2: '+ORAARCH/xxxxx/onlinelog/group_3.98800.770934463'
ORA-00338: 日志 3 (用于线程 2) 比控制文件更新
ORA-00312: 联机日志 3 线程 2: '+ORADATA/xxxxx/onlinelog/group_3.265.770934461'
Thread 2 advanced to log sequence 109348 (LGWR switch)

Current log# 4 seq# 109348 mem# 0: +ORADATA/xxxxx/onlinelog/group_4.258.770934465

Current log# 4 seq# 109348 mem# 1: +ORAARCH/xxxxx/onlinelog/group_4.98801.770934467
Sun May 06 00:22:21 2012
Archived Log entry 246723 added for thread 2 sequence 109347 ID 0xf6470f0 dest 1:
这是什么原因？能不能怎么处理可以解决这问题？

[ 本帖最后由 lxhbww 于 2012-5-23 10:21 编辑 ]

sunguo40

额 收藏学习 才发现的好论坛 好文章真多

Liu Maclean(刘相兵

ODM FINDING:

Error:  ORA 338  
Text:   log <name> of thread <num> is more recent than control file
-------------------------------------------------------------------------------
Cause:  The control file change sequence number in the redo log file is
        greater than the number in the control file.
        This implies that the wrong control file is being used.
        Note that repeatedly causing this error to happen by reopening the
        database may cause the error to stop happening without correcting the
        problem.
        Every attempt to open the database advances the control file change
        sequence number.
Action: Use the correct control file or perform recovery using a backup of the
        control file.


APPLIES TO:

Oracle Database - Enterprise Edition - Version 11.2.0.1 and later
Information in this document applies to any platform.
SYMPTOMS

Below errors are repeatedly reported in the alert log of one RAC node.
Note that the actual issue applies to RAC and non RAC databases.

ORA-00338: log <Log_Number> of thread <thread_number> is more recent than control file
ORA-00312: online log <Log_Number> thread <thread_number>: 'redo.log'
CAUSE

The ORA-00338 normally indicates an incorrect control file may be used:

00338, 00000, "log %s of thread %s is more recent than control file"
// *Cause:  The control file change sequence number in the log file is
//         greater than the number in the control file. This implies that
//         the wrong control file is being used. Note that repeatedly causing
//         this error can make it stop happening without correcting the real
//         problem. Every attempt to open the database will advance the
//         control file change sequence number until it is great enough.
// *Action: Use the current control file or do backup control file recovery to
//         make the control file current. Be sure to follow all restrictions
//         on doing a backup control file recovery.


The error is reported when the log sequence number is greater than the sequence number in the control file.
The process that detects this, posts the entries to the alert log.

Given the normal cause of the error, please verify first that the correct control file is being used.

In this particular case the control file updates could not keep up with the rate of log switches, e.g. 5 to 6 per minute.
The difference in log sequence numbers came from the excessive redo log switches that occurred prior to the error.
Note that also "Log file switch (checkpoint incomplete)" messages were reported.

In this case, the customer mentioned that fast log switches were forced by the 'storage side backup settings', meaning their backup implementation/application issued fast 'alter system switch log file' commands.

SOLUTION

After having verified the correct control file is being used, the issue can be resolved by reducing the fast explicit redo log switches.


In case the log switches is not forced manually or by an application (like in this case) then below checks/actions can be performed:

Check the redo log file size, make sure it is adequate to the workload.

Below document shows an example for how to re-size redo log file

Note 1035935.6 - Example of How To Resize the Online Redo Logfiles

After adjusting the redo log file size, monitor your database alert log to determine the time between log switches.
Oracle recommends redo log switch each 20~30 minutes.

NOTE:
You can use the V$INSTANCE_RECOVERY view column OPTIMAL_LOGFILE_SIZE to determine a recommended size for your online redo logs.
This field shows the redo log file size in megabytes that is considered optimal based on the current setting of FAST_START_MTTR_TARGET.
If this field consistently shows a value greater than the size of your smallest online log, then you should configure all your online logs to be at least this size.
Check which session is generating a lot of redo.
Below document shows how to find which session generates lot of redo or archive data:

Note 167492.1 - SQL: How to Find Sessions Generating Lots of Redo or Archive logs
Another potential cause for getting such error is that listed redo log is Not valid (i.e contain zeros),validate the redo log first to decide if it is even a valid redo. If there are zeros, and it is the current online log then we need to look at the restore/recovery options.

Example:

SQL> alter system dump logfile '/u02/app/oracle/oradata/EBSPROD/redo/log02a.dbf' validate;
alter system dump logfile '/u02/app/oracle/oradata/EBSPROD/redo/log02a.dbf' validate
*
ERROR at line 1:
ORA-00339: archived log does not contain any redo
ORA-00334: archived log: '/u02/app/oracle/oradata/EBSPROD/redo/log02a.dbf'

...


SQL> alter system dump logfile '/u02/app/oracle/oradata/EBSPROD/redo/log02b.dbf' validate;
alter system dump logfile '/u02/app/oracle/oradata/EBSPROD/redo/log02b.dbf' validate
*
ERROR at line 1:
ORA-00339: archived log does not contain any redo
ORA-00334: archived log: '/u02/app/oracle/oradata/EBSPROD/redo/log02b.dbf'

clevernby

DataGuard + 2 member/group +  excessive redo log switch ,also checkpoint incomplete messages been reported
个人觉得触发bug可能性高，如果standby可以managed recover对应seq#的日志，就忽略吧
可以开SR请求oracle协助

增加redo log大小，降低切换频率应该可以缓解错误出现几率。

[ 本帖最后由 clevernby 于 2012-6-20 10:01 编辑 ]

lxhbww

错误日志见附件.请刘大抽空再帮分析下，谢谢!

[ 本帖最后由 lxhbww 于 2012-6-20 09:07 编辑 ]

Maclean Liu(刘相兵

请压缩打包后上传 完整的alert.log 和/app/oracle/diag/rdbms/xxxxx/xxxxx1/trace/xxxxx1_nsa2_17394.trc