07 March, 2010

Misinterpreting RESTORE DATABASE VALIDATE

The documentation on the RMAN command RESTORE ... VALIDATE (link to the 10.2 documentation) is likely to be misunderstood. It says "Lets RMAN decide which backup sets, datafile copies, and archived logs need to be restored, and then scans them to verify their contents. No files are restored. Use VALIDATE to verify that the backups required to restore the specified files are intact and usable."
However, the fact of the matter is that a RESTORE DATABASE VALIDATE only checks the BackupSets corresponding to a Database Backup. You must remember that BackupSets corresponding to ArchiveLog Backup(s) are *separate*. These are NOT validated by a RESTORE DATABASE VALIDATE command. Furthermore, ArchiveLogs are required at the RECOVER phase. Therefore, in principle, there is no reason for a RESTORE VALIDATE to check ArchiveLogs as they are not required in the RESTORE phase ! (I know : Many DBAs will not agree with the last sentence !. But it is mportant to realise the difference between RESTORE and RECOVER).

If you want to validate ArchiveLog backups, you must run a separate RESTORE ARCHIVELOG .... VALIDATE command (specifying ALL or FROM ... UNTIL ... clauses for the range of ArchiveLogs).


In this example, I show how a RESTORE DATABASE VALIDATE alone is not sufficient. The DBA may have assumed that it checks for ArchiveLogs as well.


Create an RMAN Backup


ora10204>NLS_DATE_FORMAT=DD_MON_HH24_MI_SS;export NLS_DATE_FORMAT
ora10204>rman target /

Recovery Manager: Release 10.2.0.4.0 - Production on Sun Mar 7 22:54:29 2010

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

connected to target database: ORT24FS (DBID=4163910544)

RMAN> backup database plus archivelog;


Starting backup at 07_MAR_22_54_39
current log archived
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=138 devtype=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: sid=137 devtype=DISK
channel ORA_DISK_1: starting archive log backupset
channel ORA_DISK_1: specifying archive log(s) in backup set
input archive log thread=1 sequence=68 recid=643 stamp=713055279
channel ORA_DISK_1: starting piece 1 at 07_MAR_22_54_42
channel ORA_DISK_1: finished piece 1 at 07_MAR_22_54_43
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225441_5s7hklr9_.bkp tag=TAG20100307T225441 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:02
Finished backup at 07_MAR_22_54_43

Starting backup at 07_MAR_22_54_43
using channel ORA_DISK_1
using channel ORA_DISK_2
channel ORA_DISK_1: starting full datafile backupset
channel ORA_DISK_1: specifying datafile(s) in backupset
input datafile fno=00001 name=/oracle_fs/Databases/ORT24FS/system01.dbf
input datafile fno=00002 name=/oracle_fs/Databases/ORT24FS/undotbs01.dbf
input datafile fno=00010 name=/oracle_fs/Databases/ORT24FS/index_tbs_01.dbf
channel ORA_DISK_1: starting piece 1 at 07_MAR_22_54_44
channel ORA_DISK_2: starting full datafile backupset
channel ORA_DISK_2: specifying datafile(s) in backupset
input datafile fno=00004 name=/oracle_fs/Databases/ORT24FS/users01.dbf
input datafile fno=00003 name=/oracle_fs/Databases/ORT24FS/sysaux01.dbf
input datafile fno=00005 name=/oracle_fs/Databases/ORT24FS/example01.dbf
input datafile fno=00009 name=/oracle_fs/Databases/ORT24FS/table_tbs_01.dbf
channel ORA_DISK_2: starting piece 1 at 07_MAR_22_54_44
channel ORA_DISK_1: finished piece 1 at 07_MAR_22_55_49
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp tag=TAG20100307T225444 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:01:05
channel ORA_DISK_2: finished piece 1 at 07_MAR_22_56_54
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp tag=TAG20100307T225444 comment=NONE
channel ORA_DISK_2: backup set complete, elapsed time: 00:02:10
Finished backup at 07_MAR_22_56_55

Starting backup at 07_MAR_22_56_55
current log archived
using channel ORA_DISK_1
using channel ORA_DISK_2
channel ORA_DISK_1: starting archive log backupset
channel ORA_DISK_1: specifying archive log(s) in backup set
input archive log thread=1 sequence=69 recid=645 stamp=713055302
channel ORA_DISK_1: starting piece 1 at 07_MAR_22_56_55
channel ORA_DISK_2: starting archive log backupset
channel ORA_DISK_2: specifying archive log(s) in backup set
input archive log thread=1 sequence=73 recid=653 stamp=713055402
input archive log thread=1 sequence=74 recid=655 stamp=713055415
channel ORA_DISK_2: starting piece 1 at 07_MAR_22_56_55
channel ORA_DISK_1: finished piece 1 at 07_MAR_22_56_56
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvl_.bkp tag=TAG20100307T225655 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
channel ORA_DISK_2: finished piece 1 at 07_MAR_22_56_56
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvy_.bkp tag=TAG20100307T225655 comment=NONE
channel ORA_DISK_2: backup set complete, elapsed time: 00:00:01
channel ORA_DISK_1: starting archive log backupset
channel ORA_DISK_1: specifying archive log(s) in backup set
input archive log thread=1 sequence=70 recid=647 stamp=713055325
input archive log thread=1 sequence=71 recid=649 stamp=713055333
input archive log thread=1 sequence=72 recid=651 stamp=713055358
channel ORA_DISK_1: starting piece 1 at 07_MAR_22_56_57
channel ORA_DISK_1: finished piece 1 at 07_MAR_22_56_58
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hos0q_.bkp tag=TAG20100307T225655 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:02
Finished backup at 07_MAR_22_56_58

Starting Control File and SPFILE Autobackup at 07_MAR_22_56_58
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2010_03_07/o1_mf_s_713055418_5s7hotwl_.bkp comment=NONE
Finished Control File and SPFILE Autobackup at 07_MAR_22_57_02

RMAN>



We can see that the ArchiveLog Sequence# at the beginning of the backup was 68. By the time the backup completed, it had gone to 72. There had been some transactions and log switches (causing new ArchiveLogs) while the Database (i.e. Datafiles) Backup was running.


22:53:58 SQL> show user
USER is "HEMANT"
22:54:41 SQL> create table abc_1 as select * from dba_objects;

Table created.

22:54:53 SQL> alter system switch logfile;

System altered.

22:55:06 SQL> create table abc_4 as select * from abc;

Table created.

22:55:20 SQL> alter system switch logfile;

System altered.

22:55:24 SQL> alter system switch logfile;

System altered.

22:55:33 SQL> insert into abc_4 select * from abc;

0 rows created.

22:55:41 SQL> alter system switch logfile;

System altered.

22:55:57 SQL> insert into abc_1 select * from dba_objects;

50745 rows created.

22:56:21 SQL> commit;
alter s
Commit complete.

22:56:36 SQL> ystem switch logfile;

System altered.

22:56:40 SQL>
22:56:57 SQL> select l.sequence#, l.status from v$log l order by 1;

SEQUENCE# STATUS
---------- ----------------
73 ACTIVE
74 ACTIVE
75 CURRENT

22:57:12 SQL>



To "be safe" we have run another ArchiveLog Backup :


RMAN> backup archivelog all;

Starting backup at 07_MAR_22_58_31
current log archived
using channel ORA_DISK_1
using channel ORA_DISK_2
channel ORA_DISK_1: starting archive log backupset
channel ORA_DISK_1: specifying archive log(s) in backup set
input archive log thread=1 sequence=68 recid=643 stamp=713055279
input archive log thread=1 sequence=69 recid=645 stamp=713055302
channel ORA_DISK_1: starting piece 1 at 07_MAR_22_58_34
channel ORA_DISK_2: starting archive log backupset
channel ORA_DISK_2: specifying archive log(s) in backup set
input archive log thread=1 sequence=70 recid=647 stamp=713055325
input archive log thread=1 sequence=71 recid=649 stamp=713055333
input archive log thread=1 sequence=72 recid=651 stamp=713055358
input archive log thread=1 sequence=73 recid=653 stamp=713055402
channel ORA_DISK_2: starting piece 1 at 07_MAR_22_58_34
channel ORA_DISK_1: finished piece 1 at 07_MAR_22_58_35
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtr6_.bkp tag=TAG20100307T225834 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
channel ORA_DISK_2: finished piece 1 at 07_MAR_22_58_35
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtv9_.bkp tag=TAG20100307T225834 comment=NONE
channel ORA_DISK_2: backup set complete, elapsed time: 00:00:01
channel ORA_DISK_1: starting archive log backupset
channel ORA_DISK_1: specifying archive log(s) in backup set
input archive log thread=1 sequence=74 recid=655 stamp=713055415
input archive log thread=1 sequence=75 recid=657 stamp=713055514
channel ORA_DISK_1: starting piece 1 at 07_MAR_22_58_36
channel ORA_DISK_1: finished piece 1 at 07_MAR_22_58_37
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrw0w_.bkp tag=TAG20100307T225834 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:02
Finished backup at 07_MAR_22_58_37

Starting Control File and SPFILE Autobackup at 07_MAR_22_58_37
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2010_03_07/o1_mf_s_713055517_5s7hrxjg_.bkp comment=NONE
Finished Control File and SPFILE Autobackup at 07_MAR_22_58_39

RMAN>



The Log Sequence# has gone higher.


22:59:34 SQL> select l.sequence#, l.status from v$log l order by 1;

SEQUENCE# STATUS
---------- ----------------
74 ACTIVE
75 ACTIVE
76 CURRENT

22:59:39 SQL> alter system checkpoint;

System altered.

22:59:45 SQL> select l.sequence#, l.status from v$log l order by 1;

SEQUENCE# STATUS
---------- ----------------
74 INACTIVE
75 INACTIVE
76 CURRENT

22:59:55 SQL>



We now shutdown the database.


RMAN> shutdown

database closed
database dismounted
Oracle instance shut down

RMAN> exit


Recovery Manager complete.
ora10204>



We delete database files to simulate loss of database.


ora10204>pwd
/oracle_fs/Databases/ORT24FS
ora10204>ls -l *.dbf
-rw-r----- 1 ora10204 dba 104865792 Mar 7 23:00 example01.dbf
-rw-r----- 1 ora10204 dba 104865792 Mar 7 23:00 index_tbs_01.dbf
-rw-r----- 1 ora10204 dba 52429312 Mar 7 23:00 redo01.dbf
-rw-r----- 1 ora10204 dba 52429312 Mar 7 22:56 redo02.dbf
-rw-r----- 1 ora10204 dba 52429312 Mar 7 22:58 redo03.dbf
-rw-r----- 1 ora10204 dba 304095232 Mar 7 23:00 sysaux01.dbf
-rw-r----- 1 ora10204 dba 985669632 Mar 7 23:00 system01.dbf
-rw-r----- 1 ora10204 dba 104865792 Mar 7 23:00 table_tbs_01.dbf
-rw-r----- 1 ora10204 dba 131080192 Mar 6 22:51 temp01.dbf
-rw-r----- 1 ora10204 dba 954212352 Mar 7 23:00 undotbs01.dbf
-rw-r----- 1 ora10204 dba 1343496192 Mar 7 23:00 users01.dbf
ora10204>rm e*.dbf i*.dbf s*.dbf t*.dbf u*.dbf
ora10204>ls -l
total 175176
-rw-r----- 1 ora10204 dba 7290880 Mar 7 23:00 control01.ctl
-rw-r----- 1 ora10204 dba 7290880 Mar 7 23:00 control02.ctl
-rw-r----- 1 ora10204 dba 7290880 Mar 7 23:00 control03.ctl
-rw-r----- 1 ora10204 dba 52429312 Mar 7 23:00 redo01.dbf
-rw-r----- 1 ora10204 dba 52429312 Mar 7 22:56 redo02.dbf
-rw-r----- 1 ora10204 dba 52429312 Mar 7 22:58 redo03.dbf
ora10204>



We delete archivelogs to simulate loss of archivelogs from disk.


ora10204>pwd
/oracle_fs/ArchiveLogs/ORT24FS
ora10204>ls -l
total 12492
-rw-r----- 1 ora10204 dba 778752 Mar 7 22:54 1_68_709685307.dbf
-rw-r----- 1 ora10204 dba 6007296 Mar 7 22:55 1_69_709685307.dbf
-rw-r----- 1 ora10204 dba 19968 Mar 7 22:55 1_70_709685307.dbf
-rw-r----- 1 ora10204 dba 2048 Mar 7 22:55 1_71_709685307.dbf
-rw-r----- 1 ora10204 dba 1536 Mar 7 22:55 1_72_709685307.dbf
-rw-r----- 1 ora10204 dba 5901824 Mar 7 22:56 1_73_709685307.dbf
-rw-r----- 1 ora10204 dba 5120 Mar 7 22:56 1_74_709685307.dbf
-rw-r----- 1 ora10204 dba 31744 Mar 7 22:58 1_75_709685307.dbf
ora10204>rm *.dbf
ora10204>



We delete ArchiveLog *BackupSets*. We want to see if the RECOVER DATABASE VALIDATE really checks them !


ora10204>pwd
/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07
ora10204>ls -ltr *
-rw-r----- 1 ora10204 dba 780288 Mar 7 22:54 o1_mf_annnn_TAG20100307T225441_5s7hklr9_.bkp
-rw-r----- 1 ora10204 dba 602611712 Mar 7 22:55 o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp
-rw-r----- 1 ora10204 dba 1579761664 Mar 7 22:56 o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp
-rw-r----- 1 ora10204 dba 5907968 Mar 7 22:56 o1_mf_annnn_TAG20100307T225655_5s7hoqvy_.bkp
-rw-r----- 1 ora10204 dba 6008832 Mar 7 22:56 o1_mf_annnn_TAG20100307T225655_5s7hoqvl_.bkp
-rw-r----- 1 ora10204 dba 24064 Mar 7 22:56 o1_mf_annnn_TAG20100307T225655_5s7hos0q_.bkp
-rw-r----- 1 ora10204 dba 5925376 Mar 7 22:58 o1_mf_annnn_TAG20100307T225834_5s7hrtv9_.bkp
-rw-r----- 1 ora10204 dba 6787072 Mar 7 22:58 o1_mf_annnn_TAG20100307T225834_5s7hrtr6_.bkp
-rw-r----- 1 ora10204 dba 37888 Mar 7 22:58 o1_mf_annnn_TAG20100307T225834_5s7hrw0w_.bkp
ora10204>rm o1_mf_a*.bkp
ora10204>ls -l
total 2133316
-rw-r----- 1 ora10204 dba 602611712 Mar 7 22:55 o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp
-rw-r----- 1 ora10204 dba 1579761664 Mar 7 22:56 o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp
ora10204>



Now we use RMAN's RESTORE DATABASE VALIDATE command


ora10204>rman target /

Recovery Manager: Release 10.2.0.4.0 - Production on Sun Mar 7 23:06:00 2010

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

connected to target database (not started)

RMAN> startup mount

Oracle instance started
database mounted

Total System Global Area 880803840 bytes

Fixed Size 2087992 bytes
Variable Size 205521864 bytes
Database Buffers 666894336 bytes
Redo Buffers 6299648 bytes

RMAN> restore database validate;

Starting restore at 07_MAR_23_06_18
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=157 devtype=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: sid=155 devtype=DISK

channel ORA_DISK_1: starting validation of datafile backupset
channel ORA_DISK_2: starting validation of datafile backupset
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp tag=TAG20100307T225444
channel ORA_DISK_1: validation complete, elapsed time: 00:00:25
channel ORA_DISK_2: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp tag=TAG20100307T225444
channel ORA_DISK_2: validation complete, elapsed time: 00:00:25
Finished restore at 07_MAR_23_06_46

RMAN>



Surprising isn't it ? It didn't warn us that ArchiveLog BackupSets are missing.

Let's try again


RMAN> restore database validate until time "to_date('2010-03-07 22:58:37','YYYY-MM-DD HH24:MI:SS')";

Starting restore at 07_MAR_23_09_13
using channel ORA_DISK_1
using channel ORA_DISK_2

channel ORA_DISK_1: starting validation of datafile backupset
channel ORA_DISK_2: starting validation of datafile backupset
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp tag=TAG20100307T225444
channel ORA_DISK_1: validation complete, elapsed time: 00:00:04
channel ORA_DISK_2: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp tag=TAG20100307T225444
channel ORA_DISK_2: validation complete, elapsed time: 00:00:05
Finished restore at 07_MAR_23_09_18

RMAN>



Hmm. The RESTORE DATABASE VALIDATE doesn't really check if ArchiveLogs required to achieve consistent recovery (whether Complete or Incomplete) are available !



Run a RESTORE and RECOVER ?


RMAN> restore database until time "to_date('2010-03-07 22:58:37','YYYY-MM-DD HH24:MI:SS')";

Starting restore at 07_MAR_23_11_17
using channel ORA_DISK_1
using channel ORA_DISK_2

channel ORA_DISK_1: starting datafile backupset restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
restoring datafile 00001 to /oracle_fs/Databases/ORT24FS/system01.dbf
restoring datafile 00002 to /oracle_fs/Databases/ORT24FS/undotbs01.dbf
restoring datafile 00010 to /oracle_fs/Databases/ORT24FS/index_tbs_01.dbf
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp
channel ORA_DISK_2: starting datafile backupset restore
channel ORA_DISK_2: specifying datafile(s) to restore from backup set
restoring datafile 00003 to /oracle_fs/Databases/ORT24FS/sysaux01.dbf
restoring datafile 00004 to /oracle_fs/Databases/ORT24FS/users01.dbf
restoring datafile 00005 to /oracle_fs/Databases/ORT24FS/example01.dbf
restoring datafile 00009 to /oracle_fs/Databases/ORT24FS/table_tbs_01.dbf
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp tag=TAG20100307T225444
channel ORA_DISK_1: restore complete, elapsed time: 00:01:45
channel ORA_DISK_2: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp tag=TAG20100307T225444
channel ORA_DISK_2: restore complete, elapsed time: 00:02:10
Finished restore at 07_MAR_23_13_28

RMAN> recover database;

Starting recover at 07_MAR_23_13_41
using channel ORA_DISK_1
using channel ORA_DISK_2

starting media recovery

channel ORA_DISK_1: starting archive log restore to default destination
channel ORA_DISK_2: starting archive log restore to default destination
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=70
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=69
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtr6_.bkp
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=71
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=72
ORA-19870: error reading backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtr6_.bkp
ORA-19505: failed to identify file "/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtr6_.bkp"
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3
failover to previous backup
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=73
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtv9_.bkp
ORA-19870: error reading backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtv9_.bkp
ORA-19505: failed to identify file "/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtv9_.bkp"
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3
channel ORA_DISK_2: starting archive log restore to default destination
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=74
channel ORA_DISK_1: starting archive log restore to default destination
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=75
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrw0w_.bkp
ORA-19870: error reading backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrw0w_.bkp
ORA-19505: failed to identify file "/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrw0w_.bkp"
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=69
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvl_.bkp
ORA-19870: error reading backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvl_.bkp
ORA-19505: failed to identify file "/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvl_.bkp"
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3
failover to previous backup
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 03/07/2010 23:13:47
RMAN-20506: no backup of archivelog found
RMAN-06053: unable to perform media recovery because of missing log
RMAN-06025: no backup of log thread 1 seq 69 lowscn 3064318 found to restore

RMAN>



The RECOVER attempted to restore ArchiveLogs from BackupPieces that it assumed were present !!


RMAN> crosscheck backup;

using channel ORA_DISK_1
using channel ORA_DISK_2
crosschecked backup piece: found to be 'AVAILABLE'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hknro_.bkp recid=474 stamp=713055284
crosschecked backup piece: found to be 'AVAILABLE'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_nnndf_TAG20100307T225444_5s7hko8j_.bkp recid=475 stamp=713055285
crosschecked backup piece: found to be 'AVAILABLE'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2010_03_07/o1_mf_s_713055418_5s7hotwl_.bkp recid=479 stamp=713055418
crosschecked backup piece: found to be 'AVAILABLE'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2010_03_07/o1_mf_s_713055517_5s7hrxjg_.bkp recid=483 stamp=713055517
Crosschecked 10 objects

crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225441_5s7hklr9_.bkp recid=473 stamp=713055282
crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvy_.bkp recid=476 stamp=713055415
crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hoqvl_.bkp recid=477 stamp=713055415
crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225655_5s7hos0q_.bkp recid=478 stamp=713055417
crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtv9_.bkp recid=480 stamp=713055514
crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrtr6_.bkp recid=481 stamp=713055514
crosschecked backup piece: found to be 'EXPIRED'
backup piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2010_03_07/o1_mf_annnn_TAG20100307T225834_5s7hrw0w_.bkp recid=482 stamp=713055516
Crosschecked 7 objects


RMAN>



The CROSSCHECK now discovers that the BackupPieces for the ArchiveLog BackupSets are missing !


Bottom Line : The RESTORE DATABASE VALIDATE doesn't confirm that the restored database is recoverable. You must separately run RESTORE ARCHIVELOG ... VALIDATE !


RMAN> restore archivelog all validate;

Starting restore at 07_MAR_23_24_27
using channel ORA_DISK_1
using channel ORA_DISK_2

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 03/07/2010 23:24:28
RMAN-06026: some targets not found - aborting restore
RMAN-06025: no backup of log thread 1 seq 75 lowscn 3064629 found to restore
RMAN-06025: no backup of log thread 1 seq 74 lowscn 3064620 found to restore
RMAN-06025: no backup of log thread 1 seq 73 lowscn 3064476 found to restore
RMAN-06025: no backup of log thread 1 seq 72 lowscn 3064467 found to restore
RMAN-06025: no backup of log thread 1 seq 71 lowscn 3064463 found to restore
RMAN-06025: no backup of log thread 1 seq 70 lowscn 3064429 found to restore
RMAN-06025: no backup of log thread 1 seq 69 lowscn 3064318 found to restore
RMAN-06025: no backup of log thread 1 seq 68 lowscn 3063044 found to restore
RMAN-06025: no backup of log thread 1 seq 67 lowscn 3062407 found to restore
RMAN-06025: no backup of log thread 1 seq 66 lowscn 3062290 found to restore
RMAN-06025: no backup of log thread 1 seq 65 lowscn 3062155 found to restore
RMAN-06025: no backup of log thread 1 seq 64 lowscn 3061937 found to restore
RMAN-06025: no backup of log thread 1 seq 63 lowscn 3061572 found to restore
RMAN-06025: no backup of log thread 1 seq 62 lowscn 3057850 found to restore
RMAN-06025: no backup of log thread 1 seq 61 lowscn 2969959 found to restore
RMAN-06025: no backup of log thread 1 seq 60 lowscn 2954519 found to restore
RMAN-06025: no backup of log thread 1 seq 59 lowscn 2951005 found to restore
RMAN-06025: no backup of log thread 1 seq 58 lowscn 2947827 found to restore
RMAN-06025: no backup of log thread 1 seq 57 lowscn 2944286 found to restore
RMAN-06025: no backup of log thread 1 seq 56 lowscn 2939934 found to restore
RMAN-06025: no backup of log thread 1 seq 55 lowscn 2937195 found to restore
RMAN-06025: no backup of log thread 1 seq 54 lowscn 2882223 found to restore
RMAN-06025: no backup of log thread 1 seq 53 lowscn 2872012 found to restore
RMAN-06025: no backup of log thread 1 seq 52 lowscn 2865847 found to restore
RMAN-06025: no backup of log thread 1 seq 51 lowscn 2859351 found to restore
RMAN-06025: no backup of log thread 1 seq 50 lowscn 2852840 found to restore
RMAN-06025: no backup of log thread 1 seq 49 lowscn 2846285 found to restore
RMAN-06025: no backup of log thread 1 seq 48 lowscn 2839930 found to restore
RMAN-06025: no backup of log thread 1 seq 47 lowscn 2834297 found to restore
RMAN-06025: no backup of log thread 1 seq 46 lowscn 2828584 found to restore
RMAN-06025: no backup of log thread 1 seq 45 lowscn 2822885 found to restore
RMAN-06025: no backup of log thread 1 seq 44 lowscn 2815789 found to restore
RMAN-06025: no backup of log thread 1 seq 43 lowscn 2809530 found to restore
RMAN-06025: no backup of log thread 1 seq 42 lowscn 2803035 found to restore
RMAN-06025: no backup of log thread 1 seq 41 lowscn 2796478 found to restore
RMAN-06025: no backup of log thread 1 seq 40 lowscn 2789872 found to restore
RMAN-06025: no backup of log thread 1 seq 39 lowscn 2785329 found to restore
RMAN-06025: no backup of log thread 1 seq 38 lowscn 2785249 found to restore
RMAN-06025: no backup of log thread 1 seq 37 lowscn 2785175 found to restore
RMAN-06025: no backup of log thread 1 seq 36 lowscn 2785101 found to restore
RMAN-06025: no backup of log thread 1 seq 35 lowscn 2783479 found to restore
RMAN-06025: no backup of log thread 1 seq 34 lowscn 2777838 found to restore
RMAN-06025: no backup of log thread 1 seq 33 lowscn 2772060 found to restore
RMAN-06025: no backup of log thread 1 seq 32 lowscn 2766294 found to restore
RMAN-06025: no backup of log thread 1 seq 31 lowscn 2766115 found to restore
RMAN-06025: no backup of log thread 1 seq 30 lowscn 2766041 found to restore
RMAN-06025: no backup of log thread 1 seq 29 lowscn 2765896 found to restore
RMAN-06025: no backup of log thread 1 seq 28 lowscn 2765626 found to restore
RMAN-06025: no backup of log thread 1 seq 27 lowscn 2758329 found to restore
RMAN-06025: no backup of log thread 1 seq 26 lowscn 2752032 found to restore
RMAN-06025: no backup of log thread 1 seq 25 lowscn 2745302 found to restore
RMAN-06025: no backup of log thread 1 seq 24 lowscn 2738701 found to restore
RMAN-06025: no backup of log thread 1 seq 23 lowscn 2732175 found to restore
RMAN-06025: no backup of log thread 1 seq 22 lowscn 2729394 found to restore
RMAN-06025: no backup of log thread 1 seq 21 lowscn 2729288 found to restore
RMAN-06025: no backup of log thread 1 seq 20 lowscn 2729177 found to restore
RMAN-06025: no backup of log thread 1 seq 19 lowscn 2729066 found to restore
RMAN-06025: no backup of log thread 1 seq 18 lowscn 2725897 found to restore
RMAN-06025: no backup of log thread 1 seq 17 lowscn 2720244 found to restore
RMAN-06025: no backup of log thread 1 seq 16 lowscn 2714572 found to restore
MAN-06025: no backup of log thread 1 seq 15 lo
RMAN>


OR


RMAN> restore archivelog from sequence 69 until sequence 73 validate;

Starting restore at 07_MAR_23_38_43
using channel ORA_DISK_1
using channel ORA_DISK_2

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 03/07/2010 23:38:44
RMAN-06026: some targets not found - aborting restore
RMAN-06025: no backup of log thread 1 seq 73 lowscn 3064476 found to restore
RMAN-06025: no backup of log thread 1 seq 72 lowscn 3064467 found to restore
RMAN-06025: no backup of log thread 1 seq 71 lowscn 3064463 found to restore
RMAN-06025: no backup of log thread 1 seq 70 lowscn 3064429 found to restore
RMAN-06025: no backup of log thread 1 seq 69 lowscn 3064318 found to restore

RMAN>


Bottom Line : The RESTORE DATABASE VALIDATE doesn't confirm that the restored database is recoverable. You must separately run RESTORE ARCHIVELOG ... VALIDATE !
(The CROSSCHECK doesn't read the whole backuppiece to check for corruption, it only checks the header of each backuppiece, so the RESTORE ... VALIDATE is still preferred).

.
.
.

21 comments:

Rafi said...

Hi Hemant,
This is rafi here.I follow you on forum.It is very good explaination by you.I came to know some thing new.Thanks very much.

Best regards,
Rafi
My Blog:rafioracledba.blogspot.com

Marko Sutic said...

Hi Hemant,

great blog article!

I have little doubts about how often to perform backup validations. I've seen that some DBA's are performing validations just after taking backups and I don't know is that good practice or not.
I'm validating backups often, but "restore validate" is not part of my RMAN backup script.

What is your opinion about that?

Thank you for sharing your knowledge.

Regards,
Marko

Hemant K Chitale said...

Rafi,
Thanks.

Hemant K Chitale

Hemant K Chitale said...

Marko,
Frankly, I don't think of doing a VALIDATE regularly.
It may be worthwhile only occassionally -- consider that it takes time to read through the BackupSets !


Hemant K Chitale

Roopesh Uniyal said...

Hey Hemant,

Good that you actually tested it. Indeed there is a difference between RESTORE and RECOVER and Archivelogs are required only at the recovery stage. I was actually confused with the statement that RESTORE VALIDATE looks for DataFiles and ArchiveLogs....

Anyway Thanks once again in putting some time to this query.

Roopesh

Marko said...

Thanks Hemant for your answer.

I share your opinion.

Regards,
Marko

Unknown said...

Hi Hemant, I'm a programmer and I need help on my below query. We have a table with 5million records, insert into this table has become very slow although we have done stats gathering for this table&indexes. And I noticed that next extent size is not set, is this is the reason why it has become slow. Can I go ahead change this using 'ALTER TABLE tablename STORAGE (NEXT 1M PCTINCREASE 0);'. Please advise me a solution.

Hemant K Chitale said...

Gopi,

The Extent Size "not having been set" wouldn't be causing "slow inserts".

If the Tablespace is LMT with UNIFORM or AUTOALLOCATE, you can't even change the NEXT extent size.

Identify the cause of the slow insert. Look for the wait events in the session.

Hemant

Anonymous said...

Hemant

article is really great

Is there any way we can tell what are all archive logs required to restore and recover database as of some point of time?

Like querying any v$views?

thanks
roopla

Hemant K Chitale said...

Roopla,
You can query V$ARCHIVED_LOG for FIRST_CHANGE# and FIRST_TIME besides SEQUENCE#. That way, you an match SCN (FIRST_CHANGE#), Time and Sequence to determine which ArchiveLogs you need. The RMAN LIST BACKUP command shows you the Checkpoint SCN for all datafiles in a backup, so you need ArchiveLogs from the point of the earliest Checkpoint SCN in that backup set.


Hemant K Chitale

RAJESHKUMAR GOVINDARAJAN said...

thanks for sharing it. very useful information.

Thanks and Regards,
Rajeshkumar Govindarajan.

RAJESHKUMAR GOVINDARAJAN said...

very useful hemant, thanks for sharing it. your blog is very useful to learn new things especially RMAN concepts.

Regards,
Rajeshkumar Govindarajan.

Anonymous said...

use "restore database preview" instead

restore database preview actually simulates the restore and does not actually do it. It will warn you however if there are any missing files or archive logs.



Fimihan Awolowo

Pankaj Yadav said...

Thanks Hemant This is very good.

Pankaj

Humberto Fioravante Ferro said...

Good article, Hemant. Very good indeed - thank you!

Anonymous said...

RESTORE VALIDATE DATABASE ARCHIVELOG ALL anyone? Just ask what you wish for....!

Hemant K Chitale said...

Anonymous,
Not exactly the same thing. The ALL causes it to look for ArchiveLog backups that may well be older than the ones I really need for the database.

Hemant K Chitale

Anonymous said...

Hi, Hemant

Thank you for the response, but if you try to run RESTORE PREVIEW DATABASE ARCHIVELOG ALL you will get a list of archivelogs *not* found that you *may* or *may not* need to restore the database up to the last SCN (as you point out) and below that list you will get the datafile backups needed to restore the DB *and* a list of archivelogs *not* found that you *do need* to restore the DB (it is, obviously, a subset of the above mentioned list).
Moreover, if you run RESTORE DATABASE PREVIEW (or RESTORE PREVIEW DATABASE (it's the same, I don't know why), you won't get the list of (as you say) "ArchiveLog backups that may well be older than the ones I really need for the database", but *only* the list of the archivelogs that you need to restore the DB but aren't available to rman (for whatever reason) and you don't even need to type ARCHIVELOG ALL. Tested on XE 10g.

Anonymous/Peter

Thanks very much.

Hemant K Chitale said...

Yes, the RESTORE ... PREVIEW is different from the VALIDATE


Hemant K Chitale

Dhiren Patel said...

1) crosscheck backup
2) restore database preview.

Above will check for both backupset of database + archive log.

Hemant K Chitale said...

Dhiren,
Yes, the PREVIEW is different from the VALIDATE.

This blog post is specifically about the VALIDATE --- about misunderstandings around it.


Hemant K Chitale