Tuesday, 28 April 2009

Database crashed in manual hotbackup mode...

Introduction:

One of our test database crashed, while it was in manual hotbackup mode. And when we tried to open the database, it didnt comeup as expected, becuase all the datafiles were in backup mode, and needed recovery. We were doing the manual hotbackup becuase of some limitations of the environment, where we were not able to use RMAN.

Troubleshooting and Resolution:

Before doing a blind recovery, we checked the alert log of the database, and searched theh v$backup view, to see which files were in backup mode. And then we initiated the recovery.

1- We checked the alert log file and found the following entries.

Thu Mar 16 04:02:57 2009
ARC0: Evaluating archive log 3 thread 1 sequence 52
ARC0: Beginning to archive log 3 thread 1 sequence 52
Creating archive destination LOG_ARCHIVE_DEST_1: '/u02/oracle/admin/TEST/arch/TEST_s52.arc'
ARC0: Completed archiving log 3 thread 1 sequence 52
Thu Mar 16 04:03:46 2009
Shutting down instance (abort)
License high water mark = 4
Instance terminated by USER, pid = 17937
Thu Mar 16 04:04:04 2009

2- When database was started again, it gave the following messages.

Completed: ALTER DATABASE MOUNT
Thu Mar 16 04:04:49 2009
alter database open
Thu Mar 16 04:04:49 2009
ORA-1113 signalled during: alter database open...
Thu Apr 16 04:05:24 2009


3- When we checked the v$backup view, 7 files were in backup mode, so we had to recover these 7 datafiles.

SQL> l
1 select * from v$backup
2* where status != 'NOT ACTIVE'
SQL>
SQL> /

FILE# STATUS CHANGE# TIME
---------- ------------------ ---------- ---------
18 ACTIVE 7.2622E+12 15-MAR-09
19 ACTIVE 7.2622E+12 15-MAR-09
37 ACTIVE 7.2622E+12 15-MAR-09
49 ACTIVE 7.2622E+12 15-MAR-09
51 ACTIVE 7.2622E+12 15-MAR-09
60 ACTIVE 7.2622E+12 15-MAR-09
75 ACTIVE 7.2622E+12 15-MAR-09

7 rows selected.


4- Then we started database recovery, having put database in autorecovery mode. Following is the log what we did, we recovered all the datafiles, which was in backup mode, and we got that information from v$backup view.

ALTER DATABASE RECOVER datafile 18
Thu Mar 16 04:05:24 2009
Media Recovery Datafile: 16
Media Recovery Start
Starting datafile 16 recovery in thread 1 sequence 45
Datafile 16: '/u02/oradata/TEST/test_idx_01.dbf'
Media Recovery Log
ORA-279 signalled during: ALTER DATABASE RECOVER datafile 16 ...
Thu Mar 16 04:05:24 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Media Recovery Log /u02/oracle/admin/TEST/arch/TEST_s45.arc
ORA-279 signalled during: ALTER DATABASE RECOVER CONTINUE DEFAULT ...
Thu Mar 16 04:05:24 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Media Recovery Log /u02/oracle/admin/TEST/arch/TEST_s46.arc
ORA-279 signalled during: ALTER DATABASE RECOVER CONTINUE DEFAULT ...
Thu Mar 16 04:05:24 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Media Recovery Log /u02/oracle/admin/TEST/arch/TEST_s47.arc
ORA-279 signalled during: ALTER DATABASE RECOVER CONTINUE DEFAULT ...
Thu Mar 16 04:05:24 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Media Recovery Log /u02/oracle/admin/TEST/arch/TEST_s48.arc
ORA-279 signalled during: ALTER DATABASE RECOVER CONTINUE DEFAULT ...
Thu Mar 16 04:05:24 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Media Recovery Log /u02/oracle/admin/TEST/arch/TEST_s49.arc
ORA-279 signalled during: ALTER DATABASE RECOVER CONTINUE DEFAULT ...
Thu Mar 16 04:05:24 2009
ALTER DATABASE RECOVER CONTINUE DEFAULT
Media Recovery Log /u02/oracle/admin/TEST/arch/TEST_s50.arc
Recovery of Online Redo Log: Thread 1 Group 2 Seq 51 Reading mem 0
Mem# 0 errs 0: /u02/oradata/TEST/redo02.log
Recovery of Online Redo Log: Thread 1 Group 3 Seq 52 Reading mem 0
Mem# 0 errs 0: /u02/oradata/TEST/redo03.log
Recovery of Online Redo Log: Thread 1 Group 1 Seq 53 Reading mem 0
Mem# 0 errs 0: /u02/oradata/TEST/redo01.log
Media Recovery Complete
Completed: ALTER DATABASE RECOVER CONTINUE DEFAULT
Thu Mar 16 04:05:49 2009
alter database open
Thu Mar 16 04:05:49 2009
Beginning crash recovery of 1 threads
Thu Mar 16 04:05:49 2009
Started first pass scan
Thu Mar 16 04:05:49 2009
Completed first pass scan
136 redo blocks read, 20 data blocks need recovery
Thu Mar 16 04:05:49 2009
Started recovery at
Thread 1: logseq 53, block 2, scn 1690.3567247729
Recovery of Online Redo Log: Thread 1 Group 1 Seq 53 Reading mem 0
Mem# 0 errs 0: /u02/oradata/TEST/redo01.log
Thu Mar 16 04:05:49 2009
Ended recovery at
Thread 1: logseq 53, block 138, scn 1690.3567267893
20 data blocks read, 20 data blocks written, 136 redo blocks read
Crash recovery completed successfully
Thu Mar 16 04:05:49 2009
LGWR: Primary database is in CLUSTER CONSISTENT mode
Thread 1 advanced to log sequence 54
Thread 1 opened at log sequence 54
Current log# 2 seq# 54 mem# 0: /u02/oradata/TEST/redo02.log
Successful open of redo thread 1.
Thu Mar 16 04:05:49 2009
ARC0: Evaluating archive log 1 thread 1 sequence 53
ARC0: Beginning to archive log 1 thread 1 sequence 53
Creating archive destination LOG_ARCHIVE_DEST_1: '/u02/oracle/admin/TEST/arch/TEST_s53.arc'
Thu Mar 16 04:05:49 2009
SMON: enabling cache recovery
Thu Mar 16 04:05:49 2009
ARC0: Completed archiving log 1 thread 1 sequence 53
Thu Mar 16 04:05:50 2009
Undo Segment 1 Onlined
Undo Segment 2 Onlined
Undo Segment 3 Onlined
Undo Segment 4 Onlined
Undo Segment 5 Onlined
Undo Segment 6 Onlined
Undo Segment 7 Onlined
Undo Segment 8 Onlined
Undo Segment 9 Onlined
Undo Segment 10 Onlined
Successfully onlined Undo Tablespace 1.
Thu Mar 16 04:05:50 2009
SMON: enabling tx recovery
Thu Mar 16 04:05:50 2009
Database Characterset is UTF8
replication_dependency_tracking turned off (no async multimaster replication found)
Completed: alter database open


No comments: