20211013_【深入解析】ORA-01207 file is more recent than control file - old control file

1. 问题描述

   当数据库异常宕机并且控制文件损坏时，使用备份的控制文件进行恢复数据库会遇到以下错误，
ORA-01207: file is more recent than control file,通过分析并恢复该问题总结以下经验，
1） v$log中日志文件信息是从控制文件中获取，所以old controlfile中显示的日志文件scn不准确，造成数据库media recover无法完成。
2） 重建控制文件后，v$database.CHECKPOINT_CHANGE和v$datafile.CHECKPOINT_CHANGE以数据文件头和日志文件中的最大值为准。
3)  日志文件和数据文件未损坏可以进行完全恢复。
4） 日志切换时并不会立即触发完全检查点，当所有日志状态为current/active时，日志切换进程会产生等待，
alert日志显示，“Thread 1 cannot allocate new log, sequence 56”,本次切换日志会立即触发高级别全量检查点。 

复制

2. 问题模拟

2.1 备份控制文件

SQL> @log      <-- before backup the controlfile
    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARCHIVED   STATUS     MEMBER                     F_SCN                N_SCN

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

         2          1         20  104857600          1 YES        INACTIVE   /oradata/enmo/redo02a.log  792401               792405

         3          1         21  104857600          1 YES        INACTIVE   /oradata/enmo/redo03a.log  792405               792409

         1          1         22  104857600          1 NO         CURRENT    /oradata/enmo/redo01a.log  792409               281474976710655



SQL>
[oracle@sourcedb enmo]$ pwd

/oradata/enmo

[oracle@sourcedb enmo]$ cp control01.ctl ./bak/
复制

2.2 模拟数据库事务及日志切换

sqlplus / as sysdba

alter system archive log current;
/
/
/

SQL> @log   <-- before transaction



    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARCHIVED   STATUS     MEMBER                     F_SCN                N_SCN

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

         3          1         33  104857600          1 YES        INACTIVE   /oradata/enmo/redo03a.log  792467               792470

         1          1         34  104857600          1 YES        INACTIVE   /oradata/enmo/redo01a.log  792470               792473

         2          1         35  104857600          1 NO         CURRENT    /oradata/enmo/redo02a.log  792473               281474976710655



SQL>



create table t1 tablespace users as select * from obj$;

alter system switch logfile;

insert into t1 select * from t1;

commit;

select count(1) from t1;

alter system switch logfile;

delete from t1;

commit;

select count(1) from t1;



SQL> @log   <-- after transaction



    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARCHIVED   STATUS     MEMBER                     F_SCN                N_SCN

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

         2          1         35  104857600          1 YES        ACTIVE     /oradata/enmo/redo02a.log  792473               792548

         3          1         36  104857600          1 YES        ACTIVE     /oradata/enmo/redo03a.log  792548               792555

         1          1         37  104857600          1 NO         CURRENT    /oradata/enmo/redo01a.log  792555               281474976710655



SQL>

复制

2.3 模拟故障

### 异常关闭数据库，请勿在生产库执行

ps -ef|grep smon|grep -v grep|awk '{print $2}'|xargs kill -9



### 恢复old controlfile

[oracle@sourcedb enmo]$ rm -f control01.ctl

[oracle@sourcedb enmo]$ mv ./bak/control01.ctl .



### 启动数据库

SQL> alter database open;

alter database open

*

ERROR at line 1:

ORA-01122: database file 1 failed verification check

ORA-01110: data file 1: '/oradata/enmo/system01.dbf'

ORA-01207: file is more recent than control file - old control file




SQL>

复制

3. 问题恢复

3.1 use old control recove

SQL> @log



    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARCHIVED   STATUS     MEMBER                                                       F_SCN                N_SCN

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

         2          1         20  104857600          1 YES        INACTIVE   /oradata/enmo/redo02a.log                                    792401               792405

         3          1         21  104857600          1 YES        INACTIVE   /oradata/enmo/redo03a.log                                    792405               792409

         1          1         22  104857600          1 NO         CURRENT    /oradata/enmo/redo01a.log                                    792409               281474976710655



SQL> alter database open;

alter database open

*

ERROR at line 1:

ORA-01122: database file 1 failed verification check

ORA-01110: data file 1: '/oradata/enmo/system01.dbf'

ORA-01207: file is more recent than control file - old control file




SQL> recover database using backup controlfile until cancel;

ORA-00279: change 792409 generated at 10/08/2021 20:11:27 needed for thread 1

ORA-00289: suggestion : /arch1/1_22_1085429073.dbf

ORA-00280: change 792409 for thread 1 is in sequence #22




Specify log: {<RET>=suggested | filename | AUTO | CANCEL}

/oradata/enmo/redo01a.log

ORA-00326: log begins at change 792555, need earlier change 792409

ORA-00334: archived log: '/oradata/enmo/redo01a.log'




ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below

ORA-01194: file 1 needs more recovery to be consistent

ORA-01110: data file 1: '/oradata/enmo/system01.dbf'




SQL>  recover database using backup controlfile until cancel;

ORA-00279: change 792409 generated at 10/08/2021 20:11:27 needed for thread 1

ORA-00289: suggestion : /arch1/1_22_1085429073.dbf

ORA-00280: change 792409 for thread 1 is in sequence #22




Specify log: {<RET>=suggested | filename | AUTO | CANCEL}

/oradata/enmo/redo03a.log

ORA-00326: log begins at change 792548, need earlier change 792409

ORA-00334: archived log: '/oradata/enmo/redo03a.log'




ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below

ORA-01194: file 1 needs more recovery to be consistent

ORA-01110: data file 1: '/oradata/enmo/system01.dbf'




SQL>

复制

3.2 重建控制文件恢复

SQL> alter database backup controlfile to trace as '/home/oracle/ctl.txt';



Database altered.



SQL>



SQL> startup nomount;

ORACLE instance started.



Total System Global Area 2137886720 bytes

Fixed Size                  2254952 bytes

Variable Size             285214616 bytes

Database Buffers         1845493760 bytes

Redo Buffers                4923392 bytes

SQL> CREATE CONTROLFILE REUSE DATABASE "ENMO" NORESETLOGS  ARCHIVELOG

  2      MAXLOGFILES 21

  3      MAXLOGMEMBERS 5

  4      MAXDATAFILES 100

  5      MAXINSTANCES 1

  6      MAXLOGHISTORY 292

  7  LOGFILE

  8    GROUP 1 '/oradata/enmo/redo01a.log'  SIZE 100M BLOCKSIZE 512,

  9    GROUP 2 '/oradata/enmo/redo02a.log'  SIZE 100M BLOCKSIZE 512,

 10    GROUP 3 '/oradata/enmo/redo03a.log'  SIZE 100M BLOCKSIZE 512

 11  -- STANDBY LOGFILE

 12  --   GROUP 4 '/oradata/enmo/std01.log'  SIZE 50M BLOCKSIZE 512,

 13  --   GROUP 5 '/oradata/enmo/std02.log'  SIZE 50M BLOCKSIZE 512,

 14  --   GROUP 6 '/oradata/enmo/std03.log'  SIZE 50M BLOCKSIZE 512,

 15  --   GROUP 7 '/oradata/enmo/std04.log'  SIZE 50M BLOCKSIZE 512

 16  DATAFILE

 17    '/oradata/enmo/system01.dbf',

 18    '/oradata/enmo/sysaux01.dbf',

 19    '/oradata/enmo/undotbs01.dbf',

 20    '/oradata/enmo/users01.dbf',

 21    '/oradata/enmo/hsql01.dbf',

 22    '/oradata/enmo/hsql02.dbf'

 23  CHARACTER SET ZHS16GBK

 24  ;



Control file created.



SQL>



[oracle@sourcedb orastar_script]$ sqlplus / as sysdba



SQL*Plus: Release 11.2.0.4.0 Production on Fri Oct 8 20:51:33 2021



Copyright (c) 1982, 2013, Oracle.  All rights reserved.




Connected to:

Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

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



SQL> @log



    GROUP#    THREAD#  SEQUENCE#      BYTES    MEMBERS ARCHIVED   STATUS     MEMBER                                                       F_SCN                N_SCN

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

         2          1         35  104857600          1 NO         INACTIVE   /oradata/enmo/redo02a.log                                    792473               792548

         3          1         36  104857600          1 NO         INACTIVE   /oradata/enmo/redo03a.log                                    792548               792555

         1          1         37  104857600          1 NO         CURRENT    /oradata/enmo/redo01a.log                                    792555               281474976710655



SQL> @dbf



Session altered.




CHECKPOINT_CHANGE#

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

            792555




     FILE# NAME                                                         CHECKPOINT_CHANGE# CHECKPOINT_TIME     LAST_CHANGE# LAST_TIME

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

         1 /oradata/enmo/system01.dbf                                               792555

         2 /oradata/enmo/sysaux01.dbf                                               792555

         3 /oradata/enmo/undotbs01.dbf                                              792555

         4 /oradata/enmo/users01.dbf                                                792555

         5 /oradata/enmo/hsql01.dbf                                                 792555

         6 /oradata/enmo/hsql02.dbf                                                 792555



6 rows selected.




     FILE# NAME                                                         STATUS            TS#     RFILE# RESETLOGS_CHANGE# RESETLOGS_TIME      CHECKPOINT_CHANGE# CHECKPOINT_TIME     CHECKPOINT_COUNT ERROR                REC FUZ

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

         1 /oradata/enmo/system01.dbf                                   ONLINE              0          1            791853 2021-10-08 20:04:33             792473 2021-10-08 20:12:51              367                      YES YES

         2 /oradata/enmo/sysaux01.dbf                                   ONLINE              1          2            791853 2021-10-08 20:04:33             792473 2021-10-08 20:12:51              367                      YES YES

         3 /oradata/enmo/undotbs01.dbf                                  ONLINE              2          3            791853 2021-10-08 20:04:33             792473 2021-10-08 20:12:51              367                      YES YES

         4 /oradata/enmo/users01.dbf                                    ONLINE              4          4            791853 2021-10-08 20:04:33             792473 2021-10-08 20:12:51              367                      YES YES

         5 /oradata/enmo/hsql01.dbf                                     ONLINE              5          5            791853 2021-10-08 20:04:33             792473 2021-10-08 20:12:51              139                      YES YES

         6 /oradata/enmo/hsql02.dbf                                     ONLINE              5          6            791853 2021-10-08 20:04:33             792473 2021-10-08 20:12:51              144                      YES YES



6 rows selected.



SQL> recover database;

Media recovery complete.

SQL> alter database open;



Database altered.



SQL>

复制

5. 经验总结

1） v$log中日志文件信息是从控制文件中获取，所以old controlfile中显示的日志文件scn不准确，造成数据库media recover无法完成。
2） 重建控制文件后，v$database.CHECKPOINT_CHANGE和v$datafile.CHECKPOINT_CHANGE以数据文件头和日志文件中的最大值为准。
3)  日志文件和数据文件未损坏可以进行完全恢复。
4） 日志切换时并不会立即触发完全检查点，当所有日志状态为current/active时，日志切换进程会产生等待，
alert日志显示，“Thread 1 cannot allocate new log, sequence 56”,本次切换日志会立即触发高级别全量检查点。 

复制