Pages

Wednesday, August 1, 2012

How to restore a NOARCHIVELOG database (ORA-01139: RESETLOGS option only valid after an incomplete database recovery) using current control file

What we have done in the previous post was to simply create a backup of our database (put in NOARCHIVELOG mode). Now it's time to cause a fault on the database so we need to recover it. The scenario is the following: what does it happen and how can I recover a database in NOARCHIVELOG mode when a disk failure occurs and I lost my current control file, all my datafiles and only multiplexed control files are available ?

Let's start up the instance and create a table.
[oracle@localhost ~]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.2.0 Production on Tue Jul 17 07:05:13 2012

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

Connected to an idle instance.

SQL> startup
ORACLE instance started.

Total System Global Area  456146944 bytes
Fixed Size                  1344840 bytes
Variable Size             352324280 bytes
Database Buffers           96468992 bytes
Redo Buffers                6008832 bytes
Database mounted.
Database opened.
SQL> create table hr.after_backup_table (a number);

Table created.
My datafiles are located here.
SQL> select name from V$DATAFILE;

NAME
--------------------------------------------------------------------------------
/home/oracle/app/oracle/oradata/orcl/system01.dbf
/home/oracle/app/oracle/oradata/orcl/sysaux01.dbf
/home/oracle/app/oracle/oradata/orcl/undotbs01.dbf
/home/oracle/app/oracle/oradata/orcl/users01.dbf
/home/oracle/app/oracle/oradata/orcl/example01.dbf
/home/oracle/app/oracle/oradata/orcl/APEX_1930613455248703.dbf

Now let's see what happens when I move all datafiles, redo log and control files to another directory simulating a disks failure. I assume for this scenario to be able to get back with a consistent copy of at least one multiplexed control files. My control files are all in the same path on my test machine.
[oracle@localhost ~]$ cd /home/oracle/app/oracle/oradata/orcl
[oracle@localhost orcl]$ ls
control01.ctl  redo01.log  redo03.log system01.dbf  undotbs01.dbf
APEX_1930613455248703.dbf  example01.dbf  redo02.log  sysaux01.dbf  temp01.dbf
users01.dbf
[oracle@localhost orcl]$ mkdir old
[oracle@localhost orcl]$ mv *ctl *log *dbf  old/
The instance is still running
[oracle@localhost orcl]$ ps -ef|grep smon
oracle    4379     1  0 07:05 ?        00:00:01 ora_smon_orcl
oracle    4560  2820  0 07:15 pts/1    00:00:00 grep smon
From the alert log the instance begins to trace some errors
[oracle@localhost orcl]$ tail -f /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log 
...
Tue Jul 17 07:15:35 2012
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_4563.trc:
ORA-01116: error in opening database file 1
ORA-01110: data file 1: '/home/oracle/app/oracle/oradata/orcl/system01.dbf'
ORA-27041: unable to open file
Linux Error: 2: No such file or directory
Additional information: 3
...
Let's try to shutdown our instance
[oracle@localhost orcl]$ sqlplus / as sysdba
SQL> shutdown immediate;
ORA-00210: cannot open the specified control file
ORA-00202: control file: '/home/oracle/app/oracle/oradata/orcl/control01.ctl'
ORA-27041: unable to open file
Linux Error: 2: No such file or directory
Additional information: 3
Mmmmm... it doesn't work... Of course the instance is not able to find and write any SCN on the current control file. So issue the following command
SQL> shutdown abort;
ORACLE instance shut down.
Let's see what happens when an instance is not able to find a control file. The instance is not able to be open in MOUNT mode
[oracle@localhost old]$ sqlplus / as sysdba
SQL> startup mount;
ORACLE instance started.

Total System Global Area  456146944 bytes
Fixed Size                  1344840 bytes
Variable Size             352324280 bytes
Database Buffers           96468992 bytes
Redo Buffers                6008832 bytes
ORA-00205: error in identifying control file, check alert log for more info

SQL> shutdown immediate;
ORA-01507: database not mounted

ORACLE instance shut down.
SQL> exit
From the alert log we can see the instance is not able to read the control file
[oracle@localhost orcl]$ tail -f /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log 
...
ALTER DATABASE   MOUNT
ORA-00210: cannot open the specified control file
ORA-00202: control file: '/home/oracle/app/oracle/oradata/orcl/control01.ctl'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
...
Imagine you have lost all your database files except one control file that was wisely multiplexed on another disk (in my case it's in the flash recovery area path). We can use it to mount the database, copying it to the original location.
[oracle@localhost old]$ ls
control01.ctl  redo01.log  redo03.log system01.dbf  undotbs01.dbf
APEX_1930613455248703.dbf  example01.dbf  redo02.log  sysaux01.dbf  temp01.dbf
users01.dbf
[oracle@localhost old]$ cp /home/oracle/app/oracle/flash_recovery_area/orcl/control02.ctl ../control01.ctl
Now the instance is able to open in mount mode using the CURRENT control file (compared with a next scenario where I will use the control file from backup).
[oracle@localhost old]$ sqlplus / as sysdba
SQL> startup mount;
ORACLE instance started.

Total System Global Area  456146944 bytes
Fixed Size                  1344840 bytes
Variable Size             352324280 bytes
Database Buffers           96468992 bytes
Redo Buffers                6008832 bytes
Database mounted.
SQL> select controlfile_type from v$database;

CONTROL
-------
CURRENT
Now it's time to restore the datafiles from the backup using RMAN
[oracle@localhost ~]$ rman target /

Recovery Manager: Release 11.2.0.2.0 - Production on Tue Jul 17 07:31:04 2012

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

connected to target database: ORCL (DBID=1229390655, not open)

RMAN> restore database;

Starting restore at 17-07-2012 07:34:44
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=20 device type=DISK

channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00001 to
/home/oracle/app/oracle/oradata/orcl/system01.dbf
channel ORA_DISK_1: restoring datafile 00002 to
/home/oracle/app/oracle/oradata/orcl/sysaux01.dbf
channel ORA_DISK_1: restoring datafile 00003 to
/home/oracle/app/oracle/oradata/orcl/undotbs01.dbf
channel ORA_DISK_1: restoring datafile 00004 to
/home/oracle/app/oracle/oradata/orcl/users01.dbf
channel ORA_DISK_1: restoring datafile 00005 to
/home/oracle/app/oracle/oradata/orcl/example01.dbf
channel ORA_DISK_1: restoring datafile 00006 to
/home/oracle/app/oracle/oradata/orcl/APEX_1930613455248703.dbf
channel ORA_DISK_1: reading from backup piece
/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_07_15/o1_mf_nnndf_TAG20120715T054745_805gzldn_.bkp
channel ORA_DISK_1: piece
handle=/home/oracle/app/oracle/flash_recovery_area/ORCL/backupset/2012_07_15/o1_mf_nnndf_TAG20120715T054745_805gzldn_.bkp
tag=TAG20120715T054745
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:04:07
Finished restore at 17-07-2012 07:38:54
On the alert log you can see all the steps
[oracle@localhost orcl]$ tail -f /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log
...
Full restore complete of datafile 6
/home/oracle/app/oracle/oradata/orcl/APEX_1930613455248703.dbf.  Elapsed time:
0:00:01 
checkpoint is 13565488
last deallocation scn is 754490
Full restore complete of datafile 3
/home/oracle/app/oracle/oradata/orcl/undotbs01.dbf.  Elapsed time: 0:00:04 
checkpoint is 13565488
last deallocation scn is 13460761
Undo Optimization current scn is 13509396
Tue Jul 17 07:35:29 2012
Full restore complete of datafile 5
/home/oracle/app/oracle/oradata/orcl/example01.dbf.  Elapsed time: 0:00:26 
checkpoint is 13565488
last deallocation scn is 985357
Tue Jul 17 07:36:21 2012
Full restore complete of datafile 4
/home/oracle/app/oracle/oradata/orcl/users01.dbf.  Elapsed time: 0:01:27 
checkpoint is 13565488
last deallocation scn is 13511135
Tue Jul 17 07:38:22 2012
Full restore complete of datafile 1
/home/oracle/app/oracle/oradata/orcl/system01.dbf.  Elapsed time: 0:03:31 
checkpoint is 13565488
last deallocation scn is 12237706
Undo Optimization current scn is 13509396
Tue Jul 17 07:38:43 2012
Full restore complete of datafile 2
/home/oracle/app/oracle/oradata/orcl/sysaux01.dbf.  Elapsed time: 0:03:49 
checkpoint is 13565488
last deallocation scn is 13413218
...
And indeed on the file system I can see all my datafiles
[oracle@localhost ~]$ cd app/oracle/oradata/orcl/
[oracle@localhost orcl]$ ll
total 2356872
-rw-rw---- 1 oracle oracle    7348224 Jul 17 07:34 APEX_1930613455248703.dbf
-rw-r----- 1 oracle oracle    9748480 Jul 17 07:40 control01.ctl
-rw-rw---- 1 oracle oracle   85991424 Jul 17 07:35 example01.dbf
drwxrwxr-x 2 oracle oracle       4096 Jul 17 07:33 old
-rw-rw---- 1 oracle oracle 1158684672 Jul 17 07:38 sysaux01.dbf
-rw-rw---- 1 oracle oracle  871374848 Jul 17 07:38 system01.dbf
-rw-rw---- 1 oracle oracle   41951232 Jul 17 07:34 undotbs01.dbf
-rw-rw---- 1 oracle oracle  235937792 Jul 17 07:36 users01.dbf
Now it's time to open the database using the resetlogs option, but...
SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-01139: RESETLOGS option only valid after an incomplete database recovery

[oracle@localhost orcl]$ tail -f /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log
...
alter database open resetlogs
ORA-1139 signalled during: alter database open resetlogs...
Tue Jul 17 07:41:30 2012
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_5091.trc:
ORA-00313: open failed for members of log group 1 of thread 1
ORA-00312: online log 1 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo01.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_5091.trc:
ORA-00313: open failed for members of log group 2 of thread 1
ORA-00312: online log 2 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo02.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_5091.trc:
ORA-00313: open failed for members of log group 3 of thread 1
ORA-00312: online log 3 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo03.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
...
The following error happens because on the restored datafiles is written an SCN that was valid at the time the backup was taken and equal to the control file of that moment. The control file we are using is ahead compared with the SCN written on the datafiles... You have to perform ("simulate") an incomplete recovery, typing CANCEL when requested
SQL> recover database until cancel;
ORA-00279: change 13565488 generated at 07/15/2012 05:44:01 needed for thread
1
ORA-00289: suggestion :
/home/oracle/app/oracle/flash_recovery_area/ORCL/archivelog/2012_07_17/o1_mf_1_5
82_%u_.arc
ORA-00280: change 13565488 for thread 1 is in sequence #582

Specify log: {=suggested | filename | AUTO | CANCEL}
Type CANCEL
CANCEL
Media recovery cancelled.
On alert log you an read
[oracle@localhost orcl]$ tail -f /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log
...
ORA-279 signalled during: ALTER DATABASE RECOVER  database until cancel  ...
ALTER DATABASE RECOVER    CANCEL  
Media Recovery Canceled
Completed: ALTER DATABASE RECOVER    CANCEL 
...
Still any redo log files are available
[oracle@localhost orcl]$ ll
total 2356872
-rw-rw---- 1 oracle oracle    7348224 Jul 17 07:42 APEX_1930613455248703.dbf
-rw-r----- 1 oracle oracle    9748480 Jul 17 07:43 control01.ctl
-rw-rw---- 1 oracle oracle   85991424 Jul 17 07:42 example01.dbf
drwxrwxr-x 2 oracle oracle       4096 Jul 17 07:33 old
-rw-rw---- 1 oracle oracle 1158684672 Jul 17 07:42 sysaux01.dbf
-rw-rw---- 1 oracle oracle  871374848 Jul 17 07:42 system01.dbf
-rw-rw---- 1 oracle oracle   41951232 Jul 17 07:42 undotbs01.dbf
-rw-rw---- 1 oracle oracle  235937792 Jul 17 07:42 users01.dbf
untill the following command completes
SQL> alter database open resetlogs;

Database altered.
On the alert log your database is waiting for the redo log files... Wait some minutes and then you have successfully recovered your database. Of course the hr.after_backup_table table is lost because it was created after the backup.
[oracle@localhost orcl]$ tail -f /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/alert_orcl.log
...
alter database open resetlogs
RESETLOGS after incomplete recovery UNTIL CHANGE 13565488
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 1 of thread 1
ORA-00312: online log 1 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo01.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Clearing online redo logfile 1 /home/oracle/app/oracle/oradata/orcl/redo01.log
Clearing online log 1 of thread 1 sequence number 580
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 1 of thread 1
ORA-00312: online log 1 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo01.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 1 of thread 1
ORA-00312: online log 1 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo01.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Tue Jul 17 07:44:04 2012
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_5107.trc:
ORA-00322: log 1 of thread 1 is not current copy
ORA-00312: online log 1 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo01.log'
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_5107.trc:
ORA-00313: open failed for members of log group 2 of thread 1
ORA-00312: online log 2 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo02.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_m000_5107.trc:
ORA-00313: open failed for members of log group 3 of thread 1
ORA-00312: online log 3 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo03.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Clearing online redo logfile 1 complete
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 2 of thread 1
ORA-00312: online log 2 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo02.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Clearing online redo logfile 2 /home/oracle/app/oracle/oradata/orcl/redo02.log
Clearing online log 2 of thread 1 sequence number 581
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 2 of thread 1
ORA-00312: online log 2 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo02.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 2 of thread 1
ORA-00312: online log 2 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo02.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Clearing online redo logfile 2 complete
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 3 of thread 1
ORA-00312: online log 3 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo03.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Clearing online redo logfile 3 /home/oracle/app/oracle/oradata/orcl/redo03.log
Clearing online redo logfile 3 complete
Resetting resetlogs activation ID 1229364031 (0x49469b3f)
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00367: checksum error in log file header
ORA-00322: log 1 of thread 1 is not current copy
ORA-00312: online log 1 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo01.log'
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00367: checksum error in log file header
ORA-00322: log 2 of thread 1 is not current copy
ORA-00312: online log 2 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo02.log'
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 3 of thread 1
ORA-00312: online log 3 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo03.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Errors in file
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_4965.trc:
ORA-00313: open failed for members of log group 3 of thread 1
ORA-00312: online log 3 thread 1:
'/home/oracle/app/oracle/oradata/orcl/redo03.log'
ORA-27037: unable to obtain file status
Linux Error: 2: No such file or directory
Additional information: 3
Tue Jul 17 07:44:07 2012
Setting recovery target incarnation to 3
Tue Jul 17 07:44:07 2012
Assigning activation ID 1316687987 (0x4e7b1073)
Thread 1 opened at log sequence 1
Current log# 1 seq# 1 mem# 0:
/home/oracle/app/oracle/oradata/orcl/redo01.log
Successful open of redo thread 1
...
That's all.