Thursday, September 4, 2014

Recovering when the database is asking for a log that hasn't been created yet

I was asked to create a duplicate of a database on the same host as the source, so started the process to run an RMAN duplicate (more of that later).

As I was happily plodding along, the source database decided to crash - and I still don't know why. It was a DEV database and not PROD, which was reasonably fortunate (although I don't think the DEVs were happy), so I went to restart it.

ORA-01589: must use RESETLOGS or NORESETLOGS option for database open
Shutting down instance (abort)

Um. Er. What?

After running around in headless chicken mode for a few minutes, I still couldn't figure out what went wrong.

So, the first thing I did was start the database in mount mode and create a new copy of the control file

SQL> alter database backup controlfile to trace;

Database altered.

SQL> show parameter user

/u01/app/oracle/diag/rdbms/devdb/DEVDB/trace

SQL> exit

cd /u01/app/oracle/diag/rdbms/devdb/DEVDB/trace

and wade through the last few files to find the create SQL one.

A habit of mine is to immediately rename it to cr_ctl.sql so I don't lose it.

Next, edit out all the comments and delete everything except the "RESETLOGS" section

Shutdown the database and run cr_ctl.sql

SQL> @cr_ctl

Control file created

OK, that's the first hurdle cleared.

Now, issue the recovery command

SQL> RECOVER DATABASE USING BACKUP CONTROLFILE UNTIL CANCEL ;
ORA-00279: change 7668683382995 generated at 09/04/2014 12:21:58 needed for thread 1
ORA-00289: suggestion : +RECO
ORA-00280: change 7668683382995 for thread 1 is in sequence #2873

Hey, why isn't it suggesting an archived log?

Checking the ASM file system shows the latest archived log is Sequence #2872 - #2873 doesn't exist.

So, I used the online log (thanks Google!)

+DATA/DEVDB/ONLINELOG/group_1.1004.855927971

Which it liked, and this time it asked for an archived log:

Specify log: {=suggested | filename | AUTO | CANCEL}
+DATA/DEVDB/ONLINELOG/group_1.1004.855927971
ORA-00279: change 7668683382995 generated at 09/04/2014 12:16:54 needed for thread 2
ORA-00289: suggestion : +RECO/devdb/archivelog/2014_09_04/thread_2_seq_2714.21172.857392313
ORA-00280: change 7668683382995 for thread 2 is in sequence #2714

So I hit enter. Then

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

ORA-00279: change 7668683386102 generated at 09/04/2014 12:31:52 needed for thread 2
ORA-00289: suggestion : +RECO
ORA-00280: change 7668683386102 for thread 2 is in sequence #2715
ORA-00278: log file '+RECO/devdb/archivelog/2014_09_04/thread_2_seq_2714.21172.857392313' no longer
needed for this recovery

Great, I thought, so I typed "CANCEL"

ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01194: file 1 needs more recovery to be consistent
ORA-01110: data file 1: '+DATA/devdb/datafile/system.1002.855927973'

Dang.

Basically I had to apply all the online logs; it was a bit of trial and error, but got there in the end:

SQL> RECOVER DATABASE USING BACKUP CONTROLFILE UNTIL CANCEL ;
ORA-00279: change 7668683386102 generated at 09/04/2014 12:31:52 needed for thread 2
ORA-00289: suggestion : +RECO
ORA-00280: change 7668683386102 for thread 2 is in sequence #2715


Specify log: {=suggested | filename | AUTO | CANCEL}
+DATA/DEVDB/ONLINELOG/group_2.1003.855927973
ORA-00325: archived log for thread 2, wrong thread # 1 in header
ORA-00334: archived log: '+DATA/devdb/onlinelog/group_2.1003.855927973'

Try again

SQL> RECOVER DATABASE USING BACKUP CONTROLFILE UNTIL CANCEL ;
ORA-00279: change 7668683386102 generated at 09/04/2014 12:31:52 needed for thread 2
ORA-00289: suggestion : +RECO
ORA-00280: change 7668683386102 for thread 2 is in sequence #2715


Specify log: {=suggested | filename | AUTO | CANCEL}
+DATA/DEVDB/ONLINELOG/group_3.936.855928451
ORA-00279: change 7668683386102 generated at  needed for thread 1
ORA-00289: suggestion : +RECO


Specify log: {=suggested | filename | AUTO | CANCEL}
+DATA/DEVDB/ONLINELOG/group_1.1004.855927971
Log applied.
Media recovery complete.

Oh, that looks good.

SQL> alter database open resetlogs;

Database altered.

Phew. If you've seen this yourself, you can imagine my relief.

Next thing I did was a shutdown and restart, then a backup.

And tried the RMAN duplicate again, which went without a hitch this time so I have no idea what happened the first time.