上篇中我们着重讨论了Log File的Invalid状态，现在我们研究一下这种状态如果进行处理，会对数据库有何种影响。

4、Invalid状态日志对Startup作用

Online Redo Log对于数据库启动起到至关重要的作用。如果在关闭的时候是一个不完全的过程，Oracle在mount到open的过程中，是需要日志进行Instance Recovery的。即使不需要进行Instance Recovery，Oracle也会在启动时候检查日志文件的状态和一致性。

继上篇的实验继续，整理状态如下：

SQL> select group#, sequence#, members, status, first_change#, next_change# from v$log;

GROUP# SEQUENCE# MEMBERS STATUS FIRST_CHANGE# NEXT_CHANGE#

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

1 79 4 ACTIVE 1603673 1603724

2 80 2 CURRENT 1603724 281474976710

3 78 2 ACTIVE 1603669 1603673

为了增加严重性，我们向current添加Invalid日志。

SQL> alter database add logfile member '/u01/flash_recovery_area/WILSON/onlinelog/redolog02a.log' to group 2;

Database altered

SQL> select group#, sequence#, members, status, first_change#, next_change# from v$log;

GROUP# SEQUENCE# MEMBERS STATUS FIRST_CHANGE# NEXT_CHANGE#

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

1 79 4 ACTIVE 1603673 1603724

2 80 3 CURRENT 1603724 281474976710

3 78 2 ACTIVE 1603669 1603673

SQL> select group#, status, type, member from v$logfile;

GROUP# STATUS TYPE MEMBER

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

（篇幅原因，省略部分……）

1 ONLINE /u01/flash_recovery_area/WILSON/onlinelog/redolog01b.log

2 INVALID ONLINE /u01/flash_recovery_area/WILSON/onlinelog/redolog02a.log

9 rows selected

重启数据库，观察情况。

SQL> conn / as sysdba

Connected.

SQL> shutdown immediate;

Database closed.

Database dismounted.

ORACLE instance shut down.

SQL> startup

ORACLE instance started.

Total System Global Area 849530880 bytes

Fixed Size 1339824 bytes

Variable Size 536874576 bytes

Database Buffers 306184192 bytes

Redo Buffers 5132288 bytes

Database mounted.

Database opened.

启动成功，此时日志和日志组情况如下：

SQL> select group#, sequence#, members, status, first_change#, next_change# from v$log;

Warning: connection was lost and re-established

GROUP# SEQUENCE# MEMBERS STATUS FIRST_CHANGE# NEXT_CHANGE#

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

1 79 4 INACTIVE 1603673 1603724

2 80 3 CURRENT 1603724 281474976710

3 78 2 INACTIVE 1603669 1603673

SQL> select group#, status, type, member from v$logfile;

GROUP# STATUS TYPE MEMBER

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

（篇幅原因，省略……）

1 ONLINE /u01/flash_recovery_area/WILSON/onlinelog/redolog01b.log

2 INVALID ONLINE /u01/flash_recovery_area/WILSON/onlinelog/redolog02a.log

9 rows selected

这个过程几个问题需要注意：首先Oracle虽然日志组成员出现Invalid状态，但是还是启动了，明显是利用正确的日志成员。其次是启动之后，文件的Invalid状态没有变化。

在alert log中，我们的确看到了这个引起的问题。

Mon Sep 10 04:18:12 2012

ALTER DATABASE OPEN

LGWR: STARTING ARCH PROCESSES

Mon Sep 10 04:18:12 2012

ARC0 started with pid=20, OS id=4600

ARC0: Archival started

LGWR: STARTING ARCH PROCESSES COMPLETE

ARC0: STARTING ARCH PROCESSES

Errors in file /u01/diag/rdbms/wilson/wilson/trace/wilson_lgwr_4483.trc:

ORA-00313: open failed for members of log group 2 of thread 1

Errors in file /u01/diag/rdbms/wilson/wilson/trace/wilson_lgwr_4483.trc:

ORA-00313: open failed for members of log group 2 of thread 1

Thread 1 opened at log sequence 80

Current log# 2 seq# 80 mem# 0: /u01/oradata/WILSON/onlinelog/o1_mf_2_7xt44w3k_.log

Current log# 2 seq# 80 mem# 1: /u01/flash_recovery_area/WILSON/onlinelog/o1_mf_2_7xt450rv_.log

Successful open of redo thread 1

MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set

Mon Sep 10 04:18:14 2012

ARC2 started with pid=23, OS id=4612

Oracle在启动的时候，从mount到open状态中的确发现了当前日志Current组成员的问题，并且报错ORA_00313错误。之后，Oracle就是用了正确的两个成员mem#0和mem#1启动，抛弃了那个错误的日志文件。

在输出的Dump文件中，我们找到如下过程：

[oracle@bspdev trace]$ pwd

/u01/diag/rdbms/wilson/wilson/trace

[oracle@bspdev trace]$ ls -l | grep wilson_lgwr_4483.trc

-rw-r----- 1 oracle oinstall 1451 Sep 10 04:18 wilson_lgwr_4483.trc

[oracle@bspdev trace]$ cat wilson_lgwr_4483.trc

Trace file /u01/diag/rdbms/wilson/wilson/trace/wilson_lgwr_4483.trc

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options

ORACLE_HOME = /u01/oracle

System name: Linux

Node name: bspdev.localdomain

Release: 2.6.18-308.el5

Version: #1 SMP Tue Feb 21 20:05:41 EST 2012

Machine: i686

Instance name: wilson

Redo thread mounted by this instance: 1

Oracle process number: 11

Unix process pid: 4483, image: oracle@bspdev.localdomain (LGWR)

*** 2012-09-10 04:18:13.977

*** SESSION ID:(11.1) 2012-09-10 04:18:13.977

*** CLIENT ID:() 2012-09-10 04:18:13.977

*** SERVICE NAME:() 2012-09-10 04:18:13.977

*** MODULE NAME:() 2012-09-10 04:18:13.977

*** ACTION NAME:() 2012-09-10 04:18:13.977

DDE rules only execution for: ORA 313

----- START Event Driven Actions Dump ----

---- END Event Driven Actions Dump ----

----- START DDE Actions Dump -----

Executing SYNC actions

----- START DDE Action: 'DB_STRUCTURE_INTEGRITY_CHECK' (Async) -----

Successfully dispatched

----- END DDE Action: 'DB_STRUCTURE_INTEGRITY_CHECK' (SUCCESS, 0 csec) -----

Executing ASYNC actions

----- END DDE Actions Dump (total 0 csec) -----

ORA-00313: open failed for members of log group 2 of thread 1

DDE: Problem Key 'ORA 313' was flood controlled (0x1) (no incident)

ORA-00313: open failed for members of log group 2 of thread 1

[oracle@bspdev trace]$

[oracle@bspdev trace]$ oerr ora 313

00313, 00000, "open failed for members of log group %s of thread %s"

// *Cause: The online log cannot be opened. May not be able to find file.

// *Action: See accompanying errors and make log available.

[oracle@bspdev trace]$

上面Dump的Trace文件中，说明在oracle进行启动过程中，进行了数据库结构完整性检查。这个中间发现了日志文件的不一致，报错之后，使用正确的文件启动数据库。

那么，最后讨论一下，这个Invalid状态到底记录在哪里？Invalid在库启动之后就出现了。可以验证的方面只有两个，控制文件或者Redo log文件头。下面我们通过简单实验证明。

5、Invalid状态来源

虽然Redo Log状态是Invalid，但是如果在Invalid的文件头中记录这个，就意味着：如果我们使用相同的日志文件，只是拷贝过去，和正常文件相同时候，看看启动是否报错。

SQL> shutdown immediate;

Database closed.

Database dismounted.

ORACLE instance shut down.

SQL>

[oracle@bspdev trace]$ cd /u01/flash_recovery_area/WILSON/onlinelog/

[oracle@bspdev onlinelog]$ ls -l

total 307560

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 o1_mf_1_7xt44qt6_.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:27 o1_mf_2_7xt450rv_.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 o1_mf_3_7xt45bvp_.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 redolog01a.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 redolog01b.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:16 redolog02a.log

[oracle@bspdev onlinelog]$ cp /u01/oradata/WILSON/onlinelog/o1_mf_2_7xt44w3k_.log /u01/flash_recovery_area/WILSON/onlinelog/redolog02a.log

[oracle@bspdev onlinelog]$ ls -l

total 307560

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 o1_mf_1_7xt44qt6_.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:27 o1_mf_2_7xt450rv_.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 o1_mf_3_7xt45bvp_.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 redolog01a.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:18 redolog01b.log

-rw-r----- 1 oracle oinstall 52429312 Sep 10 04:28 redolog02a.log

复制之后，重新启动。

SQL> startup

ORACLE instance started.

Total System Global Area 849530880 bytes

Fixed Size 1339824 bytes

Variable Size 536874576 bytes

Database Buffers 306184192 bytes

Redo Buffers 5132288 bytes

Database mounted.

Database opened.

--Alert Log中

ALTER DATABASE OPEN

LGWR: STARTING ARCH PROCESSES

Mon Sep 10 04:29:23 2012

ARC0 started with pid=20, OS id=5005

ARC0: Archival started

LGWR: STARTING ARCH PROCESSES COMPLETE

ARC0: STARTING ARCH PROCESSES

Errors in file /u01/diag/rdbms/wilson/wilson/trace/wilson_lgwr_4888.trc:

ORA-00313: open failed for members of log group 2 of thread 1

Errors in file /u01/diag/rdbms/wilson/wilson/trace/wilson_lgwr_4888.trc:

ORA-00313: open failed for members of log group 2 of thread 1

Thread 1 opened at log sequence 80

Current log# 2 seq# 80 mem# 0: /u01/oradata/WILSON/onlinelog/o1_mf_2_7xt44w3k_.log

Current log# 2 seq# 80 mem# 1: /u01/flash_recovery_area/WILSON/onlinelog/o1_mf_2_7xt450rv_.log

启动之后，文件的状态依旧为Invalid。

SQL> select group#,status from v$logfile;

GROUP# STATUS

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

3

2

1

2 INVALID

9 rows selected.

SQL> select group#, status from v$log;

GROUP# STATUS

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

1 INACTIVE

3 INACTIVE

2 CURRENT

那么，我们就可以得出初步的猜想：Invalid状态是记录在控制文件中的。

下面是笔者正常启动的日志片段。

Mon Sep 10 04:51:22 2012

ALTER DATABASE OPEN

Beginning crash recovery of 1 threads

Started redo scan

Completed redo scan

read 31 KB redo, 21 data blocks need recovery

Started redo application at

Thread 1: logseq 81, block 346

Recovery of Online Redo Log: Thread 1 Group 3 Seq 81 Reading mem 0

Mem# 0: /u01/oradata/WILSON/onlinelog/o1_mf_3_7xt456o0_.log

Mem# 1: /u01/flash_recovery_area/WILSON/onlinelog/o1_mf_3_7xt45bvp_.log

Recovery of Online Redo Log: Thread 1 Group 1 Seq 82 Reading mem 0

Mem# 0: /u01/oradata/WILSON/onlinelog/o1_mf_1_7xt44nq1_.log

Mem# 1: /u01/flash_recovery_area/WILSON/onlinelog/o1_mf_1_7xt44qt6_.log

Completed redo application of 0.01MB

Completed crash recovery at

Thread 1: logseq 82, block 25, scn 1625420

21 data blocks read, 21 data blocks written, 31 redo k-bytes read

LGWR: STARTING ARCH PROCESSES

Mon Sep 10 04:51:23 2012

ARC0 started with pid=20, OS id=5802

ARC0: Archival started

LGWR: STARTING ARCH PROCESSES COMPLETE

ARC0: STARTING ARCH PROCESSES

Thread 1 advanced to log sequence 83 (thread open)

Thread 1 opened at log sequence 83

Current log# 2 seq# 83 mem# 0: /u01/oradata/WILSON/onlinelog/o1_mf_2_7xt44w3k_.log

Current log# 2 seq# 83 mem# 1: /u01/flash_recovery_area/WILSON/onlinelog/o1_mf_2_7xt450rv_.log

Successful open of redo thread 1

Mon Sep 10 04:51:24 2012

ARC1 started with pid=21, OS id=5806

Mon Sep 10 04:51:24 2012

ARC2 started with pid=22, OS id=5810

Mon Sep 10 04:51:24 2012

ARC3 started with pid=23, OS id=5814

6、结论

本篇中，我们讨论了Invalid日志文件的一些特征和处理方法。在正常情况下，我们是不鼓励系统出现Invalid日志文件的。这样会给系统带来很多潜在的问题。我们一般推荐一次性将所有成员建立完成，或者在添加日志成员之后，手工switch log，消除Invalid现象。

ITPub博客

谈谈Oracle日志文件的INVALID状态（下）

最新文章