This test shows how an RMAN session that is attempting a RECOVER database will , "automaticaly" restore and apply ArchiveLogs only upto the last ArchiveLog BackupSet *known* to the controlfile that is being used.
Thus, here the controlfile backup was taken after ArchiveLog Sequence #8 had been backedup (to BackupPiece "ARCH_18.BKP"). When I used this controlfile, I was able to RESTORE database (because the controlfile had captured information about the Database BackupSet) and found that the RECOVER command would only restore and apply (till Sequence #8) ArchiveLogs from ARCH_18.BKP . Although I did have more ArchiveLogs (backed up to ARCH_19.BKP), RMAN did not restore them simply because the controlfile wasn't "aware" of ARCH_19.BKP and it's contents !
As I explained in my previous blog post, I had to manually CATALOG ARCH_19.BKP before RMAN would restore and apply ArchiveLogs #9 through to #12 !
ora10204>rman target /
Recovery Manager: Release 10.2.0.4.0 - Production on Tue Apr 14 22:15:31 2009
Copyright (c) 1982, 2007, Oracle. All rights reserved.
connected to target database: ORT24FS (DBID=4163910544)
RMAN> backup full format '/oracle_fs/Backups/DB_%s.BKP' database;
Starting backup at 14-APR-09
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=143 devtype=DISK
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=00003 name=/oracle_fs/Databases/ORT24FS/sysaux01.dbf
input datafile fno=00005 name=/oracle_fs/Databases/ORT24FS/example01.dbf
input datafile fno=00002 name=/oracle_fs/Databases/ORT24FS/undotbs01.dbf
input datafile fno=00004 name=/oracle_fs/Databases/ORT24FS/users01.dbf
channel ORA_DISK_1: starting piece 1 at 14-APR-09
channel ORA_DISK_1: finished piece 1 at 14-APR-09
piece handle=/oracle_fs/Backups/DB_16.BKP tag=TAG20090414T221554 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:46
channel ORA_DISK_1: starting full datafile backupset
channel ORA_DISK_1: specifying datafile(s) in backupset
including current control file in backupset
channel ORA_DISK_1: starting piece 1 at 14-APR-09
channel ORA_DISK_1: finished piece 1 at 14-APR-09
piece handle=/oracle_fs/Backups/DB_17.BKP tag=TAG20090414T221554 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01
Finished backup at 14-APR-09
RMAN> sql 'alter system switch logfile ';
sql statement: alter system switch logfile
RMAN> backup archivelog all format '/oracle_fs/Backups/ARCH_%s.BKP';
Starting backup at 14-APR-09
current log archived
using channel ORA_DISK_1
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=1 recid=6 stamp=684194412
input archive log thread=1 sequence=2 recid=7 stamp=684194751
input archive log thread=1 sequence=3 recid=8 stamp=684195060
input archive log thread=1 sequence=4 recid=9 stamp=684195157
input archive log thread=1 sequence=5 recid=10 stamp=684195171
input archive log thread=1 sequence=6 recid=11 stamp=684195195
input archive log thread=1 sequence=7 recid=12 stamp=684195410
input archive log thread=1 sequence=8 recid=13 stamp=684195427
channel ORA_DISK_1: starting piece 1 at 14-APR-09
channel ORA_DISK_1: finished piece 1 at 14-APR-09
piece handle=/oracle_fs/Backups/ARCH_18.BKP tag=TAG20090414T221707 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:04
Finished backup at 14-APR-09
RMAN>
RMAN> sql "alter database backup controlfile to ''/oracle_fs/Backups/CNTRL_%s.BKP'' ";
sql statement: alter database backup controlfile to ''/oracle_fs/Backups/CNTRL_%s.BKP''
RMAN> sql 'alter system switch logfile ';
sql statement: alter system switch logfile
RMAN> sql 'alter system switch logfile ';
sql statement: alter system switch logfile
RMAN> sql 'alter system switch logfile ';
sql statement: alter system switch logfile
RMAN> backup archivelog all format '/oracle_fs/Backups/ARCH_%s.BKP';
Starting backup at 14-APR-09
current log archived
using channel ORA_DISK_1
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=1 recid=6 stamp=684194412
input archive log thread=1 sequence=2 recid=7 stamp=684194751
input archive log thread=1 sequence=3 recid=8 stamp=684195060
input archive log thread=1 sequence=4 recid=9 stamp=684195157
input archive log thread=1 sequence=5 recid=10 stamp=684195171
input archive log thread=1 sequence=6 recid=11 stamp=684195195
input archive log thread=1 sequence=7 recid=12 stamp=684195410
input archive log thread=1 sequence=8 recid=13 stamp=684195427
input archive log thread=1 sequence=9 recid=14 stamp=684195520
input archive log thread=1 sequence=10 recid=15 stamp=684195532
input archive log thread=1 sequence=11 recid=16 stamp=684195541
input archive log thread=1 sequence=12 recid=17 stamp=684195577
channel ORA_DISK_1: starting piece 1 at 14-APR-09
channel ORA_DISK_1: finished piece 1 at 14-APR-09
piece handle=/oracle_fs/Backups/ARCH_19.BKP tag=TAG20090414T221937 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:04
Finished backup at 14-APR-09
RMAN>
RMAN> shutdown abort;
Oracle instance shut down
RMAN> quit
Recovery Manager complete.
ora10204>pwd
/oracle_fs/Backups
ora10204>ls -l
total 655432
-rw-r----- 1 ora10204 dba 17949696 Apr 14 22:17 ARCH_18.BKP
-rw-r----- 1 ora10204 dba 17962496 Apr 14 22:19 ARCH_19.BKP
-rw-r----- 1 ora10204 dba 7061504 Apr 14 22:18 CNTRL_%s.BKP
-rw-r----- 1 ora10204 dba 620388352 Apr 14 22:16 DB_16.BKP
-rw-r----- 1 ora10204 dba 7110656 Apr 14 22:16 DB_17.BKP
ora10204>
ora10204>cd /oracle_fs/Databases/ORT24FS
ora10204>pwd
/oracle_fs/Databases/ORT24FS
ora10204>ls
control01.ctl control03.ctl redo01.dbf redo03.dbf system01.dbf undotbs01.dbf
control02.ctl example01.dbf redo02.dbf sysaux01.dbf temp01.dbf users01.dbf
ora10204>rm *
ora10204>cd /oracle_fs/Arch*/ORT24FS
ora10204>ls
1_10_684114477.dbf 1_1_684114477.dbf 1_4_684114477.dbf 1_7_684114477.dbf
1_11_684114477.dbf 1_2_684114477.dbf 1_5_684114477.dbf 1_8_684114477.dbf
1_12_684114477.dbf 1_3_684114477.dbf 1_6_684114477.dbf 1_9_684114477.dbf
ora10204>rm *
ora10204>rman target /
Recovery Manager: Release 10.2.0.4.0 - Production on Tue Apr 14 22:21:47 2009
Copyright (c) 1982, 2007, Oracle. All rights reserved.
connected to target database (not started)
RMAN> startup nomount;
Oracle instance started
Total System Global Area 880803840 bytes
Fixed Size 2087992 bytes
Variable Size 167773128 bytes
Database Buffers 704643072 bytes
Redo Buffers 6299648 bytes
RMAN>
RMAN> restore controlfile from '/oracle_fs/Backups/CNTRL_%s.BKP';
Starting restore at 14-APR-09
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=156 devtype=DISK
channel ORA_DISK_1: copied control file copy
output filename=/oracle_fs/Databases/ORT24FS/control01.ctl
output filename=/oracle_fs/Databases/ORT24FS/control02.ctl
output filename=/oracle_fs/Databases/ORT24FS/control03.ctl
Finished restore at 14-APR-09
RMAN> alter database mount;
database mounted
released channel: ORA_DISK_1
RMAN> restore database;
Starting restore at 14-APR-09
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=156 devtype=DISK
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 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
channel ORA_DISK_1: reading from backup piece /oracle_fs/Backups/DB_16.BKP
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/Backups/DB_16.BKP tag=TAG20090414T221554
channel ORA_DISK_1: restore complete, elapsed time: 00:00:46
Finished restore at 14-APR-09
RMAN>
RMAN> recover database;
Starting recover at 14-APR-09
using channel ORA_DISK_1
starting media recovery
channel ORA_DISK_1: starting archive log restore to default destination
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=7
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=8
channel ORA_DISK_1: reading from backup piece /oracle_fs/Backups/ARCH_18.BKP
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/Backups/ARCH_18.BKP tag=TAG20090414T221707
channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_7_684114477.dbf thread=1 sequence=7
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_8_684114477.dbf thread=1 sequence=8
unable to find archive log
archive log thread=1 sequence=9
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 04/14/2009 22:24:25
RMAN-06054: media recovery requesting unknown log: thread 1 seq 9 lowscn 647566
RMAN>
RMAN> catalog backuppiece '/oracle_fs/Backups/ARCH_19.BKP';
cataloged backuppiece
backup piece handle=/oracle_fs/Backups/ARCH_19.BKP recid=13 stamp=684195957
RMAN> restore archivelog all;
Starting restore at 14-APR-09
using channel ORA_DISK_1
archive log thread 1 sequence 7 is already on disk as file /oracle_fs/ArchiveLogs/ORT24FS/1_7_684114477.dbf
archive log thread 1 sequence 8 is already on disk as file /oracle_fs/ArchiveLogs/ORT24FS/1_8_684114477.dbf
channel ORA_DISK_1: starting archive log restore to default destination
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=2
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=3
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=4
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=5
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=6
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_13/o1_mf_annnn_TAG20090413T233810_4y6q33rm_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_13/o1_mf_annnn_TAG20090413T233810_4y6q33rm_.bkp tag=TAG20090413T233810
channel ORA_DISK_1: restore complete, elapsed time: 00:00:09
channel ORA_DISK_1: starting archive log restore to default destination
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=1
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=2
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=3
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=4
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=5
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=6
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=9
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=10
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=11
channel ORA_DISK_1: restoring archive log
archive log thread=1 sequence=12
channel ORA_DISK_1: reading from backup piece /oracle_fs/Backups/ARCH_19.BKP
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/Backups/ARCH_19.BKP tag=TAG20090414T221937
channel ORA_DISK_1: restore complete, elapsed time: 00:00:07
Finished restore at 14-APR-09
RMAN>
RMAN> recover database;
Starting recover at 14-APR-09
using channel ORA_DISK_1
starting media recovery
archive log thread 1 sequence 9 is already on disk as file /oracle_fs/ArchiveLogs/ORT24FS/1_9_684114477.dbf
archive log thread 1 sequence 10 is already on disk as file /oracle_fs/ArchiveLogs/ORT24FS/1_10_684114477.dbf
archive log thread 1 sequence 11 is already on disk as file /oracle_fs/ArchiveLogs/ORT24FS/1_11_684114477.dbf
archive log thread 1 sequence 12 is already on disk as file /oracle_fs/ArchiveLogs/ORT24FS/1_12_684114477.dbf
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_9_684114477.dbf thread=1 sequence=9
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_10_684114477.dbf thread=1 sequence=10
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_11_684114477.dbf thread=1 sequence=11
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_12_684114477.dbf thread=1 sequence=12
unable to find archive log
archive log thread=1 sequence=13
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 04/14/2009 22:26:52
RMAN-06054: media recovery requesting unknown log: thread 1 seq 13 lowscn 647656
RMAN> alter database open resetlogs;
database opened
RMAN>
As I have also explained in the earlier blogpost, had I used a FlashbackRecoveryArea, RMAN would have "automatically" CATALOGed all the Backupsets in the FRA. You can actually see that in the previous test where RMAN reports :
In today's Backup and Recovery Test, I did not use an FRA (i.e. I haven't set "db_file_recovery_dest" in my parameter file) so RMAN wouldn't CATALOG ARCH_19.BKP even though this BackupPiece was in the same location as the one it did know about !
searching for all files in the recovery area
cataloging files...
cataloging done
Note : Another way for RMAN to have been "aware" of ARCH_19.BKP would have been if I had used a Recovery Catalog database. Then, RMAN would have read the names of all "future" (i.e. those after the controlfile backup) BackupPieces from the Catalog and attempted to restore and apply ArchiveLogs from them as well.
.
.
.