掉电引起的ORA-1172错误解决过程（一）

由于UPS故障，导致机房连续多次掉电，问题解决后，发现一台本地测试数据库打开时报错，ORA-1172、ORA-1151错误。

同事告诉我一台数据库无法打开，只能启动到MOUNT状态，于是连接数据库尝试打开，报错如下：

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01172: recovery of thread 1 stuck at block 1669 of file 2
ORA-01151: use media recovery to recover block, restore backup if needed

看来数据文件已经出现了坏块，估计需要通过备份来恢复了。检查了一下数据库的基本情况，发现虽然数据库处于归档模式下，但是却没有做过备份。这也难怪，毕竟这个数据库只是一个本地的测试环境。

根据错误提示，可以到了对数据库进行一下恢复。不过为了稳妥起见，还是先将整个数据库环境进行一下备份。这样即使恢复过程出现了问题，至少可以将数据库恢复到最终的状态，不至于将问题变得更加糟糕，而且最重要的是，有了这个可恢复的现场，可以对恢复进行多次尝试。

备份完成后，仔细检查了一下数据库的alert文件，发现问题还真是不少：

Completed: ALTER DATABASE MOUNT
Thu Jun 5 14:05:10 2008
ALTER DATABASE OPEN
Thu Jun 5 14:05:11 2008
Beginning crash recovery of 1 threads
parallel recovery started with 7 processes
Thu Jun 5 14:05:11 2008
Started redo scan
Thu Jun 5 14:05:11 2008
Completed redo scan
23473 redo blocks read, 49 data blocks need recovery
Thu Jun 5 14:05:11 2008
Started redo application at
Thread 1: logseq 525, block 2, scn 6533560108
Thu Jun 5 14:05:11 2008
Recovery of Online Redo Log: Thread 1 Group 2 Seq 525 Reading mem 0
Mem# 0: /data/oradata/test08/redo02.log
Thu Jun 5 14:05:11 2008
RECOVERY OF THREAD 1 STUCK AT BLOCK 21 OF FILE 2
Thu Jun 5 14:05:11 2008
RECOVERY OF THREAD 1 STUCK AT BLOCK 1669 OF FILE 2
Thu Jun 5 14:05:11 2008
RECOVERY OF THREAD 1 STUCK AT BLOCK 813 OF FILE 2
Thu Jun 5 14:05:11 2008
Completed redo application
Thu Jun 5 14:05:11 2008
Hex dump of (file 3, block 21009) in trace file /opt/ora10g/admin/test08/bdump/test08_p000_4369.trc
Corrupt block relative dba: 0x00c05211 (file 3, block 21009)
Fractured block found during crash/instance recovery
Data in bad block:
type: 6 format: 2 rdba: 0x00c05211
last change scn: 0x0001.8570a63d seq: 0x2 flg: 0x06
spare1: 0x0 spare2: 0x0 spare3: 0x0
consistency value in tail: 0xe8520602
check value in block header: 0xf307
computed block checksum: 0xe6c
Reread of rdba: 0x00c05211 (file 3, block 21009) found same corrupted data
Thu Jun 5 14:05:15 2008
Errors in file /opt/ora10g/admin/test08/bdump/test08_p002_4373.trc:
ORA-01172: recovery of thread 1 stuck at block 813 of file 2
ORA-01151: use media recovery to recover block, restore backup if needed
Thu Jun 5 14:05:15 2008
Errors in file /opt/ora10g/admin/test08/bdump/test08_p001_4371.trc:
ORA-10388: parallel query server interrupt (failure)
Thu Jun 5 14:05:15 2008
Errors in file /opt/ora10g/admin/test08/bdump/test08_p004_4377.trc:
ORA-10388: parallel query server interrupt (failure)
Thu Jun 5 14:05:15 2008
Errors in file /opt/ora10g/admin/test08/bdump/test08_p005_4379.trc:
ORA-10388: parallel query server interrupt (failure)
Thu Jun 5 14:05:15 2008
Errors in file /opt/ora10g/admin/test08/bdump/test08_p005_4379.trc:
ORA-01578: ORACLE data block corrupted (file # 1, block # 1895)
ORA-01110: data file 1: '/data/oradata/test08/system01.dbf'
ORA-10564: tablespace SYSTEM
ORA-01110: data file 1: '/data/oradata/test08/system01.dbf'
ORA-10561: block type 'TRANSACTION MANAGED DATA BLOCK', data object# 482
ORA-10388: parallel query server interrupt (failure)
Thu Jun 5 14:05:15 2008
Aborting crash recovery due to slave death, attempting serial crash recovery
Thu Jun 5 14:05:15 2008
Beginning crash recovery of 1 threads
Thu Jun 5 14:05:15 2008
Started redo scan
Thu Jun 5 14:05:15 2008
Completed redo scan
23473 redo blocks read, 49 data blocks need recovery
Thu Jun 5 14:05:15 2008
Started redo application at
Thread 1: logseq 525, block 2, scn 6533560108
Thu Jun 5 14:05:15 2008
Recovery of Online Redo Log: Thread 1 Group 2 Seq 525 Reading mem 0
Mem# 0: /data/oradata/test08/redo02.log
Hex dump of (file 3, block 21009) in trace file /opt/ora10g/admin/test08/udump/test08_ora_4367.trc
Corrupt block relative dba: 0x00c05211 (file 3, block 21009)
Fractured block found during crash/instance recovery
Data in bad block:
type: 6 format: 2 rdba: 0x00c05211
last change scn: 0x0001.8570a63d seq: 0x2 flg: 0x06
spare1: 0x0 spare2: 0x0 spare3: 0x0
consistency value in tail: 0xe8520602
check value in block header: 0xf307
computed block checksum: 0xe6c
Reread of rdba: 0x00c05211 (file 3, block 21009) found same corrupted data
RECOVERY OF THREAD 1 STUCK AT BLOCK 1669 OF FILE 2
Thu Jun 5 14:05:15 2008
Aborting crash recovery due to error 1172
Thu Jun 5 14:05:15 2008
Errors in file /opt/ora10g/admin/test08/udump/test08_ora_4367.trc:
ORA-01172: recovery of thread 1 stuck at block 1669 of file 2
ORA-01151: use media recovery to recover block, restore backup if needed
ORA-1172 signalled during: ALTER DATABASE OPEN...

原本看到问题出在UNDO表空间时，觉得问题还不算太严重，因为如果是UNDO表空间的话，毕竟可以通过隐含参数尝试强行RESETLOG打开数据库，虽然会丢失一些数据，并导致数据库出现不一致的状态，但是数据库是可以打开的，由于是测试数据库，丢失部分数据和数据库状态不一致都是可以接受的。

但是从alert文件看，SYSTEM表空间的数据文件居然也出现了坏块，看来问题不是那么简单了。

下面只能碰碰运气了：

SQL> recover database;
Media recovery complete.

这一步倒是比较顺利，下面看看能不能直接打开。不过很怀疑能否这么轻易的解决这个问题：

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-03113: end-of-file on communication channel

果然不出所料，问题没有那么轻易的解决，数据库打开过程中出现了ORA-3113错误，看看alert文件中到底出现了什么问题：

ALTER DATABASE RECOVER database
Thu Jun 5 15:33:16 2008
Media Recovery Start
parallel recovery started with 7 processes
Thu Jun 5 15:33:17 2008
Recovery of Online Redo Log: Thread 1 Group 2 Seq 525 Reading mem 0
Mem# 0: /data/oradata/test08/redo02.log
Thu Jun 5 15:33:18 2008
Hex dump of (file 2, block 1095) in trace file /opt/ora10g/admin/test08/bdump/test08_p004_6330.trc
Corrupt block relative dba: 0x00800447 (file 2, block 1095)
Fractured block found during media recovery
Data in bad block:
type: 2 format: 2 rdba: 0x00800447
last change scn: 0x0001.81e8f3ea seq: 0x1 flg: 0x04
spare1: 0x0 spare2: 0x0 spare3: 0x0
consistency value in tail: 0x3f380250
check value in block header: 0x43df
computed block checksum: 0x696b
Reread of rdba: 0x00800447 (file 2, block 1095) found same corrupted data
Thu Jun 5 15:33:18 2008
Hex dump of (file 3, block 4417) in trace file /opt/ora10g/admin/test08/bdump/test08_p000_6322.trc
Corrupt block relative dba: 0x00c01141 (file 3, block 4417)
Fractured block found during media recovery
Data in bad block:
type: 6 format: 2 rdba: 0x00c01141
last change scn: 0x0001.856e4319 seq: 0x1 flg: 0x06
spare1: 0x0 spare2: 0x0 spare3: 0x0
consistency value in tail: 0x87540601
check value in block header: 0x4a80
computed block checksum: 0x3564
Reread of rdba: 0x00c01141 (file 3, block 4417) found same corrupted data
.
.
.
Hex dump of (file 3, block 36842) in trace file /opt/ora10g/admin/test08/bdump/test08_p006_6334.trc
Corrupt block relative dba: 0x00c08fea (file 3, block 36842)
Fractured block found during media recovery
Data in bad block:
type: 6 format: 2 rdba: 0x00c08fea
last change scn: 0x0001.856e421e seq: 0x1 flg: 0x06
spare1: 0x0 spare2: 0x0 spare3: 0x0
consistency value in tail: 0xef620601
check value in block header: 0x7673
computed block checksum: 0xac7e
Reread of rdba: 0x00c08fea (file 3, block 36842) found same corrupted data
Thu Jun 5 15:33:20 2008
Media Recovery Complete (test08)
Thu Jun 5 15:33:21 2008
Completed: ALTER DATABASE RECOVER database
Thu Jun 5 15:33:30 2008
alter database open
Thu Jun 5 15:33:31 2008
Beginning crash recovery of 1 threads
parallel recovery started with 7 processes
Thu Jun 5 15:33:31 2008
Started redo scan
Thu Jun 5 15:33:31 2008
Completed redo scan
23473 redo blocks read, 0 data blocks need recovery
Thu Jun 5 15:33:31 2008
Started redo application at
Thread 1: logseq 525, block 2, scn 6533560108
Thu Jun 5 15:33:31 2008
Recovery of Online Redo Log: Thread 1 Group 2 Seq 525 Reading mem 0
Mem# 0: /data/oradata/test08/redo02.log
Thu Jun 5 15:33:31 2008
Completed redo application
Thu Jun 5 15:33:31 2008
Completed crash recovery at
Thread 1: logseq 525, block 23475, scn 6533584244
0 data blocks read, 0 data blocks written, 23473 redo blocks read
Thu Jun 5 15:33:31 2008
LGWR: STARTING ARCH PROCESSES
ARC0 started with pid=23, OS id=6336
Thu Jun 5 15:33:31 2008
ARC0: Archival started
ARC1 started with pid=24, OS id=6338
Thu Jun 5 15:33:31 2008
ARC1: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
Thread 1 advanced to log sequence 526
Thread 1 opened at log sequence 526
Current log# 3 seq# 526 mem# 0: /data/oradata/test08/redo03.log
Successful open of redo thread 1
Thu Jun 5 15:33:31 2008
ARC1: Becoming the 'no FAL' ARCH
ARC1: Becoming the 'no SRL' ARCH
Thu Jun 5 15:33:31 2008
ARC0: Becoming the heartbeat ARCH
Thu Jun 5 15:33:31 2008
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Thu Jun 5 15:33:31 2008
SMON: enabling cache recovery
Thu Jun 5 15:33:33 2008
Errors in file /opt/ora10g/admin/test08/udump/test08_ora_5406.trc:
ORA-00600: internal error code, arguments: [2662], [1], [2238616959], [1], [2238756337], [8388637], [], []
Thu Jun 5 15:33:35 2008
Errors in file /opt/ora10g/admin/test08/udump/test08_ora_5406.trc:
ORA-00600: internal error code, arguments: [2662], [1], [2238616959], [1], [2238756337], [8388637], [], []
Thu Jun 5 15:33:35 2008
Error 600 happened during db open, shutting down database
USER: terminating instance due to error 600
Instance terminated by USER, pid = 5406
ORA-1092 signalled during: alter database open...

打开的过程中出现了ORA-600 [2662]的错误，看到这个错误后放了一半的心，因为前一阵处理过一个类似的错误，由于现在的SCN比数据库中的SCN要小，可以通过甚至EVENTS的方式来增大当前SCN，关于更多的描述可以参考：ORA-600(2662)错误的重现和解决（一）：http://yangtingkun.itpub.net/post/468/464682和ORA-600(2662)错误的重现和解决（二）：http://yangtingkun.itpub.net/post/468/464701