掉電引起的ORA-1172錯(cuò)誤解決過程（一）

同事告訴我一臺(tái)數(shù)據(jù)庫(kù)無法打開，只能啟動(dòng)到MOUNT狀態(tài)，于是連接數(shù)據(jù)庫(kù)嘗試打開，報(bào)錯(cuò)如下：

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

看來數(shù)據(jù)文件已經(jīng)出現(xiàn)了壞塊，估計(jì)需要通過備份來恢復(fù)了。檢查了一下數(shù)據(jù)庫(kù)的基本情況，發(fā)現(xiàn)雖然數(shù)據(jù)庫(kù)處于歸檔模式下，但是卻沒有做過備份。這也難怪，畢竟這個(gè)數(shù)據(jù)庫(kù)只是一個(gè)本地的測(cè)試環(huán)境。

根據(jù)錯(cuò)誤提示，可以到了對(duì)數(shù)據(jù)庫(kù)進(jìn)行一下恢復(fù)。不過為了穩(wěn)妥起見，還是先將整個(gè)數(shù)據(jù)庫(kù)環(huán)境進(jìn)行一下備份。這樣即使恢復(fù)過程出現(xiàn)了問題，至少可以將數(shù)據(jù)庫(kù)恢復(fù)到最終的狀態(tài)，不至于將問題變得更加糟糕，而且最重要的是，有了這個(gè)可恢復(fù)的現(xiàn)場(chǎng)，可以對(duì)恢復(fù)進(jìn)行多次嘗試。

備份完成后，仔細(xì)檢查了一下數(shù)據(jù)庫(kù)的alert文件，發(fā)現(xiàn)問題還真是不少：

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表空間時(shí)，覺得問題還不算太嚴(yán)重，因?yàn)槿绻?SPAN lang=EN-US>UNDO表空間的話，畢竟可以通過隱含參數(shù)嘗試強(qiáng)行RESETLOG打開數(shù)據(jù)庫(kù)，雖然會(huì)丟失一些數(shù)據(jù)，并導(dǎo)致數(shù)據(jù)庫(kù)出現(xiàn)不一致的狀態(tài)，但是數(shù)據(jù)庫(kù)是可以打開的，由于是測(cè)試數(shù)據(jù)庫(kù)，丟失部分?jǐn)?shù)據(jù)和數(shù)據(jù)庫(kù)狀態(tài)不一致都是可以接受的。

但是從alert文件看，SYSTEM表空間的數(shù)據(jù)文件居然也出現(xiàn)了壞塊，看來問題不是那么簡(jiǎn)單了。

下面只能碰碰運(yùn)氣了：

SQL> recover database;
Media recovery complete.

這一步倒是比較順利，下面看看能不能直接打開。不過很懷疑能否這么輕易的解決這個(gè)問題：

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

果然不出所料，問題沒有那么輕易的解決，數(shù)據(jù)庫(kù)打開過程中出現(xiàn)了ORA-3113錯(cuò)誤，看看alert文件中到底出現(xiàn)了什么問題：

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...

打開的過程中出現(xiàn)了ORA-600 [2662]的錯(cuò)誤，看到這個(gè)錯(cuò)誤后放了一半的心，因?yàn)榍耙魂囂幚磉^一個(gè)類似的錯(cuò)誤，由于現(xiàn)在的SCN比數(shù)據(jù)庫(kù)中的SCN要小，可以通過甚至EVENTS的方式來增大當(dāng)前SCN，關(guān)于更多的描述可以參考：ORA-600(2662)錯(cuò)誤的重現(xiàn)和解決（一）：http://yangtingkun.itpub.net/post/468/464682和ORA-600(2662)錯(cuò)誤的重現(xiàn)和解決（二）：http://yangtingkun.itpub.net/post/468/464701