Search My Oracle Blog

Custom Search

22 April, 2009

Bringing ONLINE a Datafile that is in RECOVER mode because it was OFFLINE

A recent forums thread was about a Datafile that had been taken OFFLINE by the DBA and was in RECOVER mode.LinkLink
When a DBA sees a datafile in 'RECOVER' mode (in DBA_DATAFILES) he shouldn't jump to the conclusion that he needs to RESTORE *and* RECOVER the datafile -- particularly if it does exist !
A RESTORE is required only if the file doesn't exist on disk (accessible to the database) OR is corrupted.

In "normal" circumstances (i.e. when a RESTORE has been issued), a RECOVER needs to roll-forward through all the ArchiveLogs that have been generated since the point in time of the datafile -- i.e. the backup of that datafile.

However, if the Datafile was taken OFFLINE, although Oracle marks it as requiring RECOVERy (as is seeen in DBA_DATA_FILES.STATUS), it doesn't really need all the ArchiveLogs. It only needs those ArchiveLogs that captured the Checkpoint of the Datafile and it's being taken OFFLINE. Subsequent ArchiveLogs (no matter how many they were) are not required. Thus, if the file was taken OFFLINE four days ago, as the DBA, I need only the ArchiveLogs that captured the last set of transactions not checkpointed into the Datafile and the ArchiveLog that captured the issuance of the ALTER DATABASE DATAFILE filename OFFLINE command. I do NOT need 4 days of ArchiveLogs.

Here, I first present one case where I do not have the ArchiveLog that captured the DATAFILE OFFLINE command. As is evident, datafile /usr/tmp/test_offline cannot be RECOVERed and brought ONLINE :


SQL> select log_mode from v$database;

LOG_MODE
------------
ARCHIVELOG

SQL> archive log list;
Database log mode Archive Mode
Automatic archival Enabled
Archive destination /oracle_fs/ArchiveLogs/ORT24FS
Oldest online log sequence 1
Next log sequence to archive 2
Current log sequence 2
SQL> create tablespace test_offline datafile '/usr/tmp/test_offline' size 10M ;

Tablespace created.

SQL> alter system switch logfile;

System altered.

SQL> alter database datafile '/usr/tmp/test_offline' offline;

Database altered.

SQL> select * from dba_data_files where file_name like '/usr/tmp/test%';

FILE_NAME
--------------------------------------------------------------------------------
FILE_ID TABLESPACE_NAME BYTES BLOCKS STATUS
---------- ------------------------------ ---------- ---------- ---------
RELATIVE_FNO AUT MAXBYTES MAXBLOCKS INCREMENT_BY USER_BYTES USER_BLOCKS
------------ --- ---------- ---------- ------------ ---------- -----------
ONLINE_
-------
/usr/tmp/test_offline
6 TEST_OFFLINE AVAILABLE
6
RECOVER


SQL> alter system switch logfile;

System altered.

SQL> /

System altered.

SQL> !rm /oracle_fs/ArchiveLogs/ORT24FS/*

SQL> archive log list;
Database log mode Archive Mode
Automatic archival Enabled
Archive destination /oracle_fs/ArchiveLogs/ORT24FS
Oldest online log sequence 3
Next log sequence to archive 5
Current log sequence 5
SQL> !ls -l /oracle_fs/ArchiveLogs/ORT24FS
total 0

SQL> alter system switch logfile;

System altered.

SQL> archive log list;
Database log mode Archive Mode
Automatic archival Enabled
Archive destination /oracle_fs/ArchiveLogs/ORT24FS
Oldest online log sequence 4
Next log sequence to archive 6
Current log sequence 6
SQL> !ls -l /oracle_fs/ArchiveLogs/ORT24FS
total 8
-rw-r----- 1 ora10204 dba 4608 Apr 22 22:33 1_5_684196024.dbf

SQL> alter database datafile '/usr/tmp/test_offline' online;
alter database datafile '/usr/tmp/test_offline' online
*
ERROR at line 1:
ORA-01113: file 6 needs media recovery
ORA-01110: data file 6: '/usr/tmp/test_offline'


SQL> recover datafile 6;
ORA-00279: change 649615 generated at 04/22/2009 22:29:06 needed for thread 1
ORA-00289: suggestion : /oracle_fs/ArchiveLogs/ORT24FS/1_2_684196024.dbf
ORA-00280: change 649615 for thread 1 is in sequence #2


Specify log: {=suggested | filename | AUTO | CANCEL}
cancel
Media recovery cancelled.
SQL> alter database datafile '/usr/tmp/test_offline' online;
alter database datafile '/usr/tmp/test_offline' online
*
ERROR at line 1:
ORA-01113: file 6 needs media recovery
ORA-01110: data file 6: '/usr/tmp/test_offline'


SQL> drop tablespace test_offline including contents and datafiles;

Tablespace dropped.

SQL>

I needed ArchiveLog 2 to be able to issue the RECOVER command. However, as I had (seemingly inadvertently or because it is very old file) removed that ArchiveLog from disk, I cannot RECOVER the datafile. Note, however, that if I did have a Tape backup of ArchiveLogs 2 and 3 I would have been able to RECOVER that datfile and then bring it ONLINE (without requiring Sequences 4 and 5).


In this next scenario, I delete only the subsequent ArchiveLogs after the first one after the ALTER DATABASE DATAFILE filename OFFLINE command. (We can assume that I either preserved the required ArchiveLogs or restored them from backup).


SQL> create tablespace t_o_2 datafile '/usr/tmp/t_o_2.dbf' size 10M;

Tablespace created.

SQL> archive log list;
Database log mode Archive Mode
Automatic archival Enabled
Archive destination /oracle_fs/ArchiveLogs/ORT24FS
Oldest online log sequence 4
Next log sequence to archive 6
Current log sequence 6
SQL> alter system switch logfile;

System altered.

SQL> alter database datafile '/usr/tmp/t_o_2.dbf' offline;

Database altered.

SQL> alter system switch logfile;

System altered.

SQL> archive log list;
Database log mode Archive Mode
Automatic archival Enabled
Archive destination /oracle_fs/ArchiveLogs/ORT24FS
Oldest online log sequence 6
Next log sequence to archive 8
Current log sequence 8
SQL> !ls -l /oracle_fs/ArchiveLogs/ORT24FS
total 44
-rw-r----- 1 ora10204 dba 4608 Apr 22 22:33 1_5_684196024.dbf
-rw-r----- 1 ora10204 dba 28160 Apr 22 22:36 1_6_684196024.dbf
-rw-r----- 1 ora10204 dba 6656 Apr 22 22:36 1_7_684196024.dbf

SQL> create table t_2 (col_1 number);

Table created.

SQL> insert into t_2 select object_id from dba_objects;

50601 rows created.

SQL> commit;

Commit complete.

SQL> alter system switch logfile;

System altered.

SQL> /

System altered.

SQL> !ls -l /oracle_fs/ArchiveLogs/ORT24FS
total 900
-rw-r----- 1 ora10204 dba 4608 Apr 22 22:33 1_5_684196024.dbf
-rw-r----- 1 ora10204 dba 28160 Apr 22 22:36 1_6_684196024.dbf
-rw-r----- 1 ora10204 dba 6656 Apr 22 22:36 1_7_684196024.dbf
-rw-r----- 1 ora10204 dba 866304 Apr 22 22:38 1_8_684196024.dbf
-rw-r----- 1 ora10204 dba 1536 Apr 22 22:38 1_9_684196024.dbf

SQL> !rm /oracle_fs/ArchiveLogs/ORT24FS/1_8_*.dbf

SQL> !rm /oracle_fs/ArchiveLogs/ORT24FS/1_9_*.dbf

SQL> alter database datafile '/usr/tmp/t_o_2.dbf' online;
alter database datafile '/usr/tmp/t_o_2.dbf' online
*
ERROR at line 1:
ORA-01113: file 6 needs media recovery
ORA-01110: data file 6: '/usr/tmp/t_o_2.dbf'


SQL> recover datafile 6;
ORA-00279: change 649846 generated at 04/22/2009 22:36:10 needed for thread 1
ORA-00289: suggestion : /oracle_fs/ArchiveLogs/ORT24FS/1_6_684196024.dbf
ORA-00280: change 649846 for thread 1 is in sequence #6


Specify log: {=suggested | filename | AUTO | CANCEL}

ORA-00279: change 649874 generated at 04/22/2009 22:36:28 needed for thread 1
ORA-00289: suggestion : /oracle_fs/ArchiveLogs/ORT24FS/1_7_684196024.dbf
ORA-00280: change 649874 for thread 1 is in sequence #7
ORA-00278: log file '/oracle_fs/ArchiveLogs/ORT24FS/1_6_684196024.dbf' no
longer needed for this recovery


Specify log: {=suggested | filename | AUTO | CANCEL}

Log applied.
Media recovery complete.
SQL> select * from dba_data_files where file_name like '/usr/tmp/t_o%';

FILE_NAME
--------------------------------------------------------------------------------
FILE_ID TABLESPACE_NAME BYTES BLOCKS STATUS
---------- ------------------------------ ---------- ---------- ---------
RELATIVE_FNO AUT MAXBYTES MAXBLOCKS INCREMENT_BY USER_BYTES USER_BLOCKS
------------ --- ---------- ---------- ------------ ---------- -----------
ONLINE_
-------
/usr/tmp/t_o_2.dbf
6 T_O_2 AVAILABLE
6
OFFLINE


SQL> alter database datafile '/usr/tmp/t_o_2.dbf' online;

Database altered.

SQL>


Thus, the RECOVER command for /usr/tmp/t_o_2.dbf required only ArchiveLogs 6 and 7. I did NOT need ArchiveLogs 8, 9 and 10 even though they have been generated since after the particular Datafile was taken OFFLINE.
Therefore, although ArchiveLogs 8, 9 and 10 do capture transactions in *other* Datafiles (and, therefore, would be required if I were to RESTORE and/or RCOVER the other Datafiles), I do not need them for this particular Datafile that was "properly and normally" taken OFFLINE.
As further evidence, see these messages from the alert.log file :

Wed Apr 22 22:36:42 2009
alter database datafile '/usr/tmp/t_o_2.dbf' offline
Wed Apr 22 22:36:42 2009
Completed: alter database datafile '/usr/tmp/t_o_2.dbf' offline
Wed Apr 22 22:36:47 2009
Thread 1 cannot allocate new log, sequence 8
Checkpoint not complete
Current log# 1 seq# 7 mem# 0: /oracle_fs/Databases/ORT24FS/redo01.dbf
Wed Apr 22 22:36:49 2009
Thread 1 advanced to log sequence 8 (LGWR switch)
Current log# 2 seq# 8 mem# 0: /oracle_fs/Databases/ORT24FS/redo02.dbf
Wed Apr 22 22:38:15 2009
Thread 1 cannot allocate new log, sequence 9
Checkpoint not complete
Current log# 2 seq# 8 mem# 0: /oracle_fs/Databases/ORT24FS/redo02.dbf
Wed Apr 22 22:38:16 2009
Thread 1 advanced to log sequence 9 (LGWR switch)
Current log# 3 seq# 9 mem# 0: /oracle_fs/Databases/ORT24FS/redo03.dbf
Thread 1 cannot allocate new log, sequence 10
Checkpoint not complete
Current log# 3 seq# 9 mem# 0: /oracle_fs/Databases/ORT24FS/redo03.dbf
Wed Apr 22 22:38:19 2009
Thread 1 advanced to log sequence 10 (LGWR switch)
Current log# 1 seq# 10 mem# 0: /oracle_fs/Databases/ORT24FS/redo01.dbf
Wed Apr 22 22:39:19 2009
alter database datafile '/usr/tmp/t_o_2.dbf' online
Wed Apr 22 22:39:19 2009
ORA-1113 signalled during: alter database datafile '/usr/tmp/t_o_2.dbf' online...
Wed Apr 22 22:39:25 2009
ALTER DATABASE RECOVER datafile 6
Media Recovery Start
parallel recovery started with 2 processes
ORA-279 signalled during: ALTER DATABASE RECOVER datafile 6 ...
Wed Apr 22 22:39:28 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Wed Apr 22 22:39:28 2009
Media Recovery Log /oracle_fs/ArchiveLogs/ORT24FS/1_6_684196024.dbf
ORA-279 signalled during: ALTER DATABASE RECOVER CONTINUE DEFAULT ...
Wed Apr 22 22:39:31 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Wed Apr 22 22:39:31 2009
Media Recovery Log /oracle_fs/ArchiveLogs/ORT24FS/1_7_684196024.dbf
Wed Apr 22 22:39:31 2009
Media Recovery Complete (ORT24FS)
Completed: ALTER DATABASE RECOVER CONTINUE DEFAULT
Wed Apr 22 22:40:15 2009
alter database datafile '/usr/tmp/t_o_2.dbf' online
Wed Apr 22 22:40:15 2009
Starting control autobackup
Control autobackup written to DISK device
handle '/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/c-4163910544-20090422-03'
Completed: alter database datafile '/usr/tmp/t_o_2.dbf' online



Thus, Oracle needed only ArchiveLogs 6 and 7 even as I had deleted 8 and 9 from disk (and have no backups of 8 and 9).
.
.
.

14 April, 2009

Controlfile Backup older than the ArchiveLogs

In my previous blog post about RMAN Backup and Recovery for loss of ALL files, Khurram Siddiqui had asked what I meant when I said "What about the possible situation where my controlfile is older than ArchiveLog backups created subsequent to it ? Then, the RECOVER command would not have known about those Backupsets as they would be missing from the controlfile !"

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 :

searching for all files in the recovery area
cataloging files...
cataloging done
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 !

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.

.
.
.

12 April, 2009

RMAN Backup and Recovery for Loss of ALL files

In response to this forums thread about backup and recovery, I am posting the RMAN Backup and Recovery scenario for the loss of *ALL* files (Database, RedoLogs, ArchiveLogs and spfile).
As long as the last Backup included
a. Database
b. ArchiveLogs generated from the beginning of the Database Backup to the first ArchiveLog after the end of the Database Backup -- having ArchiveLogs after that point is a bonus
c. ControlFile
d. spfile

Note : The controlfile is also always automatically included in backups that run for
Database
SYSTEM Tablespace
Change of database structure (if CONTROLFILE AUTOBACKUP ON is configured)


In this scenario, the Database Backup completes at (Archive)Log Sequence 8, while Log Sequence 9 is the additional file generated by the 'alter system switch logfile' command. (The BACKUP DATABASE had actually also issued it's own switch logfile for (Archive)Log Sequence 8 so Sequence 9 is not, strictly, necessary.)

In the RESTORE sequence, in order to restore the SPFILE, I must STARTUP FORCE NOMOUNT. This causes RMAN to use a "DUMMY" parameter file. This allows me to restore the actual SPFILE but causes the controlfile to be restored to $ORACLE_HOME/dbs and errors on the database name when I try to MOUNT with the controlfile. After I restore the SPFILE, I must SHUTDOWN and STARTUP NOMOUNT again so that I can restore the controlfile to the correct (target) locations.

In the RECOVER sequence, Oracle (RMAN) automatically determines that this is a BACKUP CONTROLFILE. (If I were using the SQLPLUS command-line, I would have to explicitly specify "USING BACKUP CONTROLFILE" in my RECOVER command).
The Recovery halts when attempting to apply Sequence 10, which does not exist.
Note, however, how Oracle detected the BackupSets containing ArchiveLogs 8 and 9 and restored the files. (It used the information in the controlfile that was an autobackup after the ArchiveLog backup).
After the Recovery seemingly failing at Sequence 10, I am able to issue an OPEN RESETLOGS because I know that I have done a valid INCOMPLETE RECOVERY. (ie, all Database Files Recovered upto the last available ArchiveLog but without the Online Redo Logs being available).

Without further ado, here is the sequence of steps : (I start with the BACKUP done before I remove and crash the database)


ora10204>rman target /

Recovery Manager: Release 10.2.0.4.0 - Production on Sun Apr 12 22:53:11 2009

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

connected to target database: ORT24FS (DBID=4137213278)

RMAN> backup database;

Starting backup at 12-APR-09
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=154 devtype=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: sid=141 devtype=DISK
channel ORA_DISK_1: starting full datafile backupset
channel ORA_DISK_1: 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=00008 name=/oracle_fs/Databases/ORT24FS/mssm01.dbf
channel ORA_DISK_1: starting piece 1 at 12-APR-09
channel ORA_DISK_2: starting full datafile backupset
channel ORA_DISK_2: specifying datafile(s) in backupset
input datafile fno=00001 name=/oracle_fs/Databases/ORT24FS/system01.dbf
input datafile fno=00007 name=/oracle_fs/Databases/ORT24FS/assm01.dbf
input datafile fno=00005 name=/oracle_fs/Databases/ORT24FS/example01.dbf
input datafile fno=00006 name=/oracle_fs/Databases/ORT24FS/undotbs.dbf
channel ORA_DISK_2: starting piece 1 at 12-APR-09
channel ORA_DISK_2: finished piece 1 at 12-APR-09
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_nnndf_TAG20090412T225324_4y4037dl_.bkp tag=TAG20090412T225324 comment=NONE
channel ORA_DISK_2: backup set complete, elapsed time: 00:01:15
channel ORA_DISK_1: finished piece 1 at 12-APR-09
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_nnndf_TAG20090412T225324_4y4038mp_.bkp tag=TAG20090412T225324 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:01:41
Finished backup at 12-APR-09

Starting Control File and SPFILE Autobackup at 12-APR-09
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684024906_4y406c2k_.bkp comment=NONE
Finished Control File and SPFILE Autobackup at 12-APR-09

RMAN> sql 'alter system archive log all';

sql statement: alter system archive log all
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03009: failure of sql command on default channel at 04/12/2009 22:56:35
RMAN-11003: failure during parse/execution of SQL statement: alter system archive log all
ORA-00271: there are no logs that need archiving

RMAN> sql 'alter system switch logfile ';

sql statement: alter system switch logfile

RMAN> backup archivelog all;

Starting backup at 12-APR-09
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=7 recid=361 stamp=684022751
input archive log thread=1 sequence=8 recid=362 stamp=684025008
channel ORA_DISK_1: starting piece 1 at 12-APR-09
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=9 recid=363 stamp=684025017
channel ORA_DISK_2: starting piece 1 at 12-APR-09
channel ORA_DISK_2: finished piece 1 at 12-APR-09
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_annnn_TAG20090412T225657_4y409vqv_.bkp tag=TAG20090412T225657 comment=NONE
channel ORA_DISK_2: backup set complete, elapsed time: 00:00:02
channel ORA_DISK_1: finished piece 1 at 12-APR-09
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_annnn_TAG20090412T225657_4y409vod_.bkp tag=TAG20090412T225657 comment=NONE
channel ORA_DISK_1: backup set complete, elapsed time: 00:00:03
Finished backup at 12-APR-09

Starting Control File and SPFILE Autobackup at 12-APR-09
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684025021_4y409ydg_.bkp comment=NONE
Finished Control File and SPFILE Autobackup at 12-APR-09

RMAN> exit


Recovery Manager complete.
ora10204>
ora10204>pwd
/oracle_fs/Databases/ORT24FS
ora10204>ls
assm01.dbf control02.ctl example01.dbf red01.dbf redo04.dbf sysaux01.dbf temp_01.dbf undotbs.dbf
control01.ctl control03.ctl mssm01.dbf redo03.dbf redo05.dbf system01.dbf temp01.dbf users01.dbf
ora10204>pwd
/oracle_fs/Databases/ORT24FS
ora10204>rm *
ora10204>cd /oracle_fs/Arch*/*T24*
ora10204>ls
1_7_682469351.dbf 1_8_682469351.dbf 1_9_682469351.dbf
ora10204>rm *
ora10204>sqlplus

SQL*Plus: Release 10.2.0.4.0 - Production on Sun Apr 12 22:59:19 2009

Copyright (c) 1982, 2007, Oracle. All Rights Reserved.

Enter user-name: / as sysdba
sh
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> utdown abort;
ORACLE instance shut down.
SQL>
SQL> exit
Disconnected from Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ora10204>
ora10204>rm $ORACLE_HOME/dbs/*ORT24FS.ora
ora10204>rman target /

Recovery Manager: Release 10.2.0.4.0 - Production on Sun Apr 12 23:07:28 2009

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

connected to target database (not started)

RMAN> SET DBID=4137213278;

executing command: SET DBID

RMAN> startup force nomount;

startup failed: ORA-01078: failure in processing system parameters
LRM-00109: could not open parameter file '/oracle_fs/ora10204/product/10.2.0.4/dbs/initORT24FS.ora'

starting Oracle instance without parameter file for retrival of spfile
Oracle instance started

Total System Global Area 159383552 bytes

Fixed Size 2082400 bytes
Variable Size 67111328 bytes
Database Buffers 83886080 bytes
Redo Buffers 6303744 bytes

RMAN> restore spfile from '/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684025021_4y409ydg_.bkp';

Starting restore at 12-APR-09
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=36 devtype=DISK

channel ORA_DISK_1: autobackup found: /oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684025021_4y409ydg_.bkp
channel ORA_DISK_1: SPFILE restore from autobackup complete
Finished restore at 12-APR-09

RMAN> alter database mount;

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of alter db command at 04/12/2009 23:09:34
ORA-00205: error in identifying control file, check alert log for more info

RMAN> restore controlfile from '/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684025021_4y409ydg_.bkp';

Starting restore at 12-APR-09
using channel ORA_DISK_1

channel ORA_DISK_1: restoring control file
channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
output filename=/oracle_fs/ora10204/product/10.2.0.4/dbs/cntrlORT24FS.dbf
Finished restore at 12-APR-09

RMAN> alter database mount;

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of alter db command at 04/12/2009 23:10:06
ORA-01103: database name 'ORT24FS' in control file is not 'DUMMY'

RMAN> shutdown

Oracle instance shut down

RMAN> startup mount;

connected to target database (not started)
Oracle instance started
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of startup command at 04/12/2009 23:11:06
ORA-00205: error in identifying control file, check alert log for more info

RMAN> startup nomount;

database is already started

RMAN> restore controlfile from '/oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684025021_4y409ydg_.bkp';

Starting restore at 12-APR-09
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=156 devtype=DISK

channel ORA_DISK_1: restoring control file
channel ORA_DISK_1: restore complete, elapsed time: 00:00:04
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 12-APR-09

RMAN> alter database mount;

database mounted
released channel: ORA_DISK_1

RMAN> restore database;

Starting restore at 12-APR-09
Starting implicit crosscheck backup at 12-APR-09
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=156 devtype=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: sid=155 devtype=DISK
Crosschecked 35 objects
Crosschecked 18 objects
Finished implicit crosscheck backup at 12-APR-09

Starting implicit crosscheck copy at 12-APR-09
using channel ORA_DISK_1
using channel ORA_DISK_2
Finished implicit crosscheck copy at 12-APR-09

searching for all files in the recovery area
cataloging files...
cataloging done

List of Cataloged Files
=======================
File Name: /oracle_fs/FRAs/ORT24FS/ORT24FS/autobackup/2009_04_12/o1_mf_s_684025021_4y409ydg_.bkp

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 00005 to /oracle_fs/Databases/ORT24FS/example01.dbf
restoring datafile 00006 to /oracle_fs/Databases/ORT24FS/undotbs.dbf
restoring datafile 00007 to /oracle_fs/Databases/ORT24FS/assm01.dbf
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_nnndf_TAG20090412T225324_4y4037dl_.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 00008 to /oracle_fs/Databases/ORT24FS/mssm01.dbf
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_nnndf_TAG20090412T225324_4y4038mp_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_nnndf_TAG20090412T225324_4y4037dl_.bkp tag=TAG20090412T225324
channel ORA_DISK_1: restore complete, elapsed time: 00:01:36
channel ORA_DISK_2: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_nnndf_TAG20090412T225324_4y4038mp_.bkp tag=TAG20090412T225324
channel ORA_DISK_2: restore complete, elapsed time: 00:01:51
Finished restore at 12-APR-09

RMAN> recover database;

Starting recover at 12-APR-09
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=9
channel ORA_DISK_1: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_annnn_TAG20090412T225657_4y409vqv_.bkp
channel ORA_DISK_2: restoring archive log
archive log thread=1 sequence=8
channel ORA_DISK_2: reading from backup piece /oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_annnn_TAG20090412T225657_4y409vod_.bkp
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_annnn_TAG20090412T225657_4y409vqv_.bkp tag=TAG20090412T225657
channel ORA_DISK_1: restore complete, elapsed time: 00:00:02
channel ORA_DISK_2: restored backup piece 1
piece handle=/oracle_fs/FRAs/ORT24FS/ORT24FS/backupset/2009_04_12/o1_mf_annnn_TAG20090412T225657_4y409vod_.bkp tag=TAG20090412T225657
channel ORA_DISK_2: restore complete, elapsed time: 00:00:05
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_8_682469351.dbf thread=1 sequence=8
archive log filename=/oracle_fs/ArchiveLogs/ORT24FS/1_9_682469351.dbf thread=1 sequence=9
unable to find archive log
archive log thread=1 sequence=10
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 04/12/2009 23:16:51
RMAN-06054: media recovery requesting unknown log: thread 1 seq 10 lowscn 108150439

RMAN> alter database open resetlogs;

database opened

RMAN> exit


Recovery Manager complete.
ora10204>cd $ORACLE_HOME/dbs
ora10204>ls -l spfileORT24FS.ora
-rw-r----- 1 ora10204 dba 3584 Apr 12 23:13 spfileORT24FS.ora
ora10204>strings -a spfileORT24FS.ora
ORT24FS.__db_cache_size=708837376
ORT24FS.__java_pool_size=4194304
ORT24FS.__large_pool_size=4194304
ORT24FS.__shared_pool_size=113246208
ORT24FS.__streams_pool_size=0
*.audit_file_dest='/oracle_fs/ora10204/admin/ORT24FS/adump'
*.background_dump_dest='/oracle_fs/ora10204/admin/ORT24FS/bdump'
*.compatible='10.2.0.3.0'
*.control_files='/oracle_fs/Databases/ORT24FS/control01.ctl','/oracle_fs/Databases/ORT24FS/control02.ctl','/oracle_fs/Databases/ORT24FS/control03.ctl'#Restore Controlfile
*.core_dump_dest='/oracle_fs/ora10204/admin/ORT24FS/cdump'
*.db_block_size=8192
*.db_domain=''
*.db_name='ORT24FS'
*.db_recovery_file_dest='/oracle_fs/FRAs/ORT24FS'
*.db_recovery_file_dest_size=21474836480
*.dbwr_io_slaves=0
*.dispatchers='(PROTOCOL=TCP) (SERVICE=ORT24FSXDB)'
*.filesystemio_options='NONE'
*.job_queue_processes=10
*.log_archive_dest_1='LOCATION=/oracle_fs/ArchiveLogs/ORT24FS'
*.log_archive_format='%t_%s_%r.dbf'
*.open_cursors=300
*.parallel_max_servers=4
*.pga_aggregate_target=179306496
*.processes=150
*.recovery_parallelism=4
*.remote_login_passwordfile='EXCLUSIVE'
*.sga_max_size=880803840
*.sga_target=838860800
*.shared_pool_size=104857600
*.undo_management='AUTO'
*.undo_tablespace='UNDOTBS'
*.user_dump_dest='/oracle_fs/ora10204/admin/ORT24FS/udump'
ora10204>

I also demonstrate above how I did NOT have to use the "_allow_resetlogs_corruption" parameter.

What about the possible situation where my controlfile is older than ArchiveLog backups created subsequent to it ? Then, the RECOVER command would not have known about those Backupsets as they would be missing from the controlfile !
I would then
a. Restore those BackupSets from tape to disk (if not available on disk)
b. Use the RMAN "CATALOG" command to catalog the backupsets so that they are now "known" to the controlfile
and/or
b. Use the RMAN "CATALOG" command to catalog the backupsets and then use the RMAN "RESTORE ARCHIVELOG ..." command to restore archivelogs
c. Continued the Recovery either through RMAN or with SQLPLUS "RECOVER DATABASE USING BACKUP CONTROLFILE UNTIL CANCEL"

.
.
.

11 April, 2009

Incorrect Cardinality Estimate of 1 : Bug 5483301

Oracle Bug# 5483301 is about the optimizer computing an incorrect Cardinality of 1 for an equality predicate not present in a FREQUENCY Histogram.

This test is in 10.2.0.1
In the first half of this test, I create a FREQUENCY Histogram on a column with 99 distinct values ("low_card_column") between 1 and 99. For queries for the values 110, 120 and 2000, all three of which are *not* present in the Histogram, Oracle computes an estimated cardinality of 1.
Note : It wouldn't matter if the value I queried for were within the min and max values either -- as long as it does not exist in the FREQUENCY Histogram, Oracle estimates a cardinality of 1 only.

In the second half of the test, I do NOT create a Histogram on the colum. This time, for the predicate values 110, 120 and 2000, Oracle does come up with more reasonable cardinalities.

Thus, the bug being present in 10.2.0.1 to 10.2.0.3, means that if you create a FREQUENCY Histogram (either deliberately or inadvertently through Oracle's SIZE AUTO behaviour) and later query for a predicate not present in the Histogram (e.g. if the value was inserted after the Statistics were gathered), the cardinality estimate can be very wrong. This results in serious under-costing of queries for such values.
If you happen to have a very large number of rows for such a value, you are seriously out of luck.
You must either rebuild the FREQUENCY Histogram statistics OR drop the Histogram.



SQL>
SQL> REM Bug 5483301 : "QUERY WITH PREDICATE VALUE NON-EXISTENT IN FREQUENCY HISTOGRAM RUNS SLOW"
SQL>
SQL> REM The Bug causes Oracle to estimate a very poor Cardinality of 1 if a frequency histogram exists
SQL> REM on the column but the specific column value does not exist in the table
SQL>
SQL> drop table test_bug_5483301 purge;
Table dropped.

SQL> create table test_bug_5483301
2 (
3 low_card_column number not null,
4 text_column varchar2(20) not null,
5 number_column number not null,
6 date_column date not null
7 )
8 /
Table created.

SQL> alter table test_bug_5483301 nologging;
Table altered.

SQL> -- populate the table with 100 different low_card_column values
SQL> insert /*+ APPEND */ into test_bug_5483301
2 select trunc(dbms_random.value(1,100)),
3 dbms_random.string('X',10),
4 trunc(dbms_random.value(100,80000)),
5 sysdate-365+trunc(dbms_random.value(1,360))
6 from object_ids_table
7 /
2417712 rows created.

SQL> create index test_bug_5483301_lcc_ndx on test_bug_5483301(low_card_column) nologging;
Index created.

SQL> -- Create a FREQUENCY Histogram
SQL> exec dbms_stats.gather_table_stats(user,'TEST_BUG_5483301',estimate_percent=>100,method_opt=>'FOR COLUMNS LOW_CARD_COLUMN SIZE 250',cascade=>TRUE);
PL/SQL procedure successfully completed.

SQL>
SQL> REM Confirm the number and range of low_card_column values
SQL> select count(distinct(low_card_column)) from test_bug_5483301
2 /

COUNT(DISTINCT(LOW_CARD_COLUMN))
--------------------------------
99

SQL>
SQL> select min_low_card_column, max_low_card_column
2 from
3 (select min(low_card_column) min_low_card_column from test_bug_5483301),
4 (select max(low_card_column) max_low_card_column from test_bug_5483301)
5 /

MIN_LOW_CARD_COLUMN MAX_LOW_CARD_COLUMN
------------------- -------------------
1 99

SQL>
SQL> -- insert 8000 rows with low_card_column values that are not in the histogram
SQL> insert /*+ APPEND */ into test_bug_5483301
2 select 110,
3 'ABCDEFGH',
4 82000,
5 sysdate-2
6 from dba_objects
7 where rownum < 8001
8 /
8000 rows created.

SQL> commit;

Commit complete.

SQL>
SQL> REM ######################################################################################
SQL> REM Let's check the Card estimates -- when using Literals
SQL>
SQL> -- for a value in the known list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=10;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2790200580

--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 24671 | 626K| 1941 (4)| 00:00:24 |
|* 1 | TABLE ACCESS FULL| TEST_BUG_5483301 | 24671 | 626K| 1941 (4)| 00:00:24 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("LOW_CARD_COLUMN"=10)

13 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=10;

COUNT(*)
----------
24671

SQL>
SQL> -- for another value in the possible list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=75;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2790200580

--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 24594 | 624K| 1941 (4)| 00:00:24 |
|* 1 | TABLE ACCESS FULL| TEST_BUG_5483301 | 24594 | 624K| 1941 (4)| 00:00:24 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("LOW_CARD_COLUMN"=75)

13 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=75;

COUNT(*)
----------
24594

SQL>
SQL> -- for a value present in the table but not in the histogram
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=110;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1793180512

--------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 26 | 4 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| TEST_BUG_5483301 | 1 | 26 | 4 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | TEST_BUG_5483301_LCC_NDX | 1 | | 3 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

2 - access("LOW_CARD_COLUMN"=110)

14 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=110;

COUNT(*)
----------
8000

SQL>
SQL> -- for a value outside the known list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=120;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1793180512

--------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 26 | 4 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| TEST_BUG_5483301 | 1 | 26 | 4 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | TEST_BUG_5483301_LCC_NDX | 1 | | 3 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

2 - access("LOW_CARD_COLUMN"=120)

14 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=120;

COUNT(*)
----------
0

SQL>
SQL> -- for a value *far* outside the known list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=2000;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1793180512

--------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 26 | 4 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| TEST_BUG_5483301 | 1 | 26 | 4 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | TEST_BUG_5483301_LCC_NDX | 1 | | 3 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

2 - access("LOW_CARD_COLUMN"=2000)

14 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=2000;

COUNT(*)
----------
0

SQL>
SQL> REM REM REM REM REM REM ####################################################################
SQL> REM REM REM REM REM REM ####################################################################
SQL>
SQL> drop table test_bug_5483301 purge;

Table dropped.

SQL> create table test_bug_5483301
2 (
3 low_card_column number not null,
4 text_column varchar2(20) not null,
5 number_column number not null,
6 date_column date not null
7 )
8 /

Table created.

SQL>
SQL> alter table test_bug_5483301 nologging;

Table altered.

SQL>
SQL> -- populate the table with 100 different low_card_column values
SQL> insert /*+ APPEND */ into test_bug_5483301
2 select trunc(dbms_random.value(1,100)),
3 dbms_random.string('X',10),
4 dbms_random.value(100,80000),
5 sysdate-365+dbms_random.value(1,360)
6 from object_ids_table
7 /

2417712 rows created.

SQL>
SQL> create index test_bug_5483301_lcc_ndx on test_bug_5483301(low_card_column) nologging;

Index created.

SQL>
SQL> -- Create NO Histogram
SQL> exec dbms_stats.gather_table_stats(user,'TEST_BUG_5483301',estimate_percent=>100,method_opt=>'FOR COLUMNS LOW_CARD_COLUMN SIZE 1',cascade=>TRUE);

PL/SQL procedure successfully completed.

SQL>
SQL> REM Confirm the number and range of low_card_column values
SQL> select count(distinct(low_card_column)) from test_bug_5483301
2 /

COUNT(DISTINCT(LOW_CARD_COLUMN))
--------------------------------
99

SQL>
SQL> select min_low_card_column, max_low_card_column
2 from
3 (select min(low_card_column) min_low_card_column from test_bug_5483301),
4 (select max(low_card_column) max_low_card_column from test_bug_5483301)
5 /

MIN_LOW_CARD_COLUMN MAX_LOW_CARD_COLUMN
------------------- -------------------
1 99

SQL>
SQL>
SQL> -- insert 8000 rows with low_card_column values that are not in the histogram
SQL> insert /*+ APPEND */ into test_bug_5483301
2 select 110,
3 'ABCDEFGH',
4 82000,
5 sysdate-2
6 from dba_objects
7 where rownum < 8001
8 /

8000 rows created.

SQL> commit;

Commit complete.

SQL>
SQL>
SQL>
SQL>
SQL> REM ######################################################################################
SQL> REM Let's check the Card estimates -- when using Literals
SQL>
SQL> -- for a value in the known list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=10;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2790200580

--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 24421 | 667K| 2950 (3)| 00:00:36 |
|* 1 | TABLE ACCESS FULL| TEST_BUG_5483301 | 24421 | 667K| 2950 (3)| 00:00:36 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("LOW_CARD_COLUMN"=10)

13 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=10;

COUNT(*)
----------
24252

SQL>
SQL> -- for another value in the possible list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=75;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2790200580

--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 24421 | 667K| 2950 (3)| 00:00:36 |
|* 1 | TABLE ACCESS FULL| TEST_BUG_5483301 | 24421 | 667K| 2950 (3)| 00:00:36 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("LOW_CARD_COLUMN"=75)

13 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=75;

COUNT(*)
----------
24472

SQL>
SQL> -- for a value present in the table but not in the histogram
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=110;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2790200580

--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 21680 | 592K| 2950 (3)| 00:00:36 |
|* 1 | TABLE ACCESS FULL| TEST_BUG_5483301 | 21680 | 592K| 2950 (3)| 00:00:36 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("LOW_CARD_COLUMN"=110)

13 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=110;

COUNT(*)
----------
8000

SQL>
SQL> -- for a value outside the known list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=120;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 2790200580

--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 19188 | 524K| 2950 (3)| 00:00:36 |
|* 1 | TABLE ACCESS FULL| TEST_BUG_5483301 | 19188 | 524K| 2950 (3)| 00:00:36 |
--------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter("LOW_CARD_COLUMN"=120)

13 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=120;

COUNT(*)
----------
0

SQL>
SQL> -- for a value *far* outside the known list of values (by frequency histogram)
SQL> explain plan for select text_column, number_column from test_bug_5483301 where low_card_column=2000;

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1793180512

--------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 28 | 4 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| TEST_BUG_5483301 | 1 | 28 | 4 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | TEST_BUG_5483301_LCC_NDX | 1 | | 3 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

2 - access("LOW_CARD_COLUMN"=2000)

14 rows selected.

SQL> select count(*) from test_bug_5483301 where low_card_column=2000;

COUNT(*)
----------
0

SQL>



More Notes : The Patch for 5483301 can introduce bug 6082745.
The 5483301 fix is to estimate a cardinality of 0.5 times the least popular value -- which can still be very wrong if you have a new value, not present in the Histogram, but with a very large number of rows !

Aggregated by orafaq.com

Aggregated by orafaq.com
This blog is being aggregated by orafaq.com