Oracle資料庫恢復：歸檔日誌損壞案例一則

最近在緊急故障處理時，幫助使用者恢復資料庫遇到了一則罕見的歸檔日誌損壞案例，在這裡和大家分享一下，看看是否有人遇到過類似的問題。

在進行歸檔recover時，資料庫報錯，提示歸檔日誌損壞：

***
Corrupt block seq: 37288 blocknum=1.
Bad header found during deleting archived log
Data in bad block - seq:810559520. bno:170473264. time:707406346
beg:21280 cks:21061
calculated check value: 9226
Reread of seq=37288, blocknum=1, file=/ARCH/arch_1_37288_632509987.dbf, found same corrupt data
Reread of seq=37288, blocknum=1, file=/ARCH/arch_1_37288_632509987.dbf, found same corrupt data
Reread of seq=37288, blocknum=1, file=/ARCH/arch_1_37288_632509987.dbf, found same corrupt data
Reread of seq=37288, blocknum=1, file=/ARCH/arch_1_37288_632509987.dbf, found same corrupt data
Reread of seq=37288, blocknum=1, file=/ARCH/arch_1_37288_632509987.dbf, found same corrupt data
***

資訊比較詳細，說37288號歸檔日誌Header損壞，無法讀取資料。

提一個小問題：如果你遇到了這樣的錯誤？會怎樣思考？

如果這個歸檔日誌損壞了，其實我們仍然有辦法跳過去，繼續嘗試恢復其他日誌，但是客戶資料重要，不能容忍不一致性，這時候就只能放棄部分資料，由前臺重新提交資料了。這在業務上可以實現，也就不是大問題了。

好了，問題是為什麼日誌會損壞？是如何損壞的？

我首先要做的就是，看看日誌檔案的內容，透過最簡單的命令將日誌檔案中的內容輸出出來：
strings arch_1_37288_632509987.dbf > log.txt

然後檢查生成的這個日誌檔案，我們就發現了問題。
在這個歸檔日誌檔案中，被寫入了大量的跟蹤檔案內容，其中開頭部分就是一個跟蹤檔案的全部資訊。

這是一種我從來沒有遇到過的現象，也就是說，當作業系統在寫出跟蹤檔案時，錯誤的覆蓋掉了已經存在的歸檔檔案，最後導致歸檔日誌損壞，非常奇妙，從所未見。

最後我的判斷是，這個故障應當是作業系統在寫出時出現了問題，存在檔案的空間仍然被認為是可寫的，這樣就導致了寫衝突，出現這類問題，應當立即檢查硬體，看看是否是硬體問題導致瞭如此嚴重的異常。

Dump file /ADMIN/bdump/erp_p007_19216.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /DBMS/erp/erpdb/10g
Linux
eygle.com
2.6.9-34.ELhugemem
#1 SMP Fri Feb 24 17:04:34 EST 2006
i686
Instance name: erp
Redo thread mounted by this instance: 1
Oracle process number: 22
Unix process pid: 19216, image: oracle@eygle.com (P007)
*** SERVICE NAME:() 2010-11-10 10:37:26.247
*** SESSION ID:(2184.1) 2010-11-10 10:37:26.247
*** 2010-11-10 10:37:26.247
KCRP: blocks claimed = 61, eliminated = 0
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 61/61 = 1.0
Max compares per lookup = 0
Avg compares per lookup = 0/61 = 0.0
----------------------------------------------
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 61/61 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 1426/1426 = 1.0
----------------------------------------------
GPAYMENTdxn
AP_CHECKS
Q(xn
.1=N
Gxn
.1=N
^0e
^0e!
^0e"
^0e#
^0e$
^0e%
^0e&
^0e'
eygle.com!/
^0e(
^0e)
^0e*
^0e+
^0e+
^0e&
^ij1
R0:b
Q(xn
PaymentsN
a'VND
Userxn
AP_INVOICE_PAYMENTS
105273
5406105305-20101020-003
3001CASH CLEARING
CREATED
Dump file /ADMIN/bdump/erp_p002_19206.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /DBMS/erp/erpdb/10g
Linux
eygle.com
2.6.9-34.ELhugemem
#1 SMP Fri Feb 24 17:04:34 EST 2006
i686
Instance name: erp
Redo thread mounted by this instance: 1
Oracle process number: 17
Unix process pid: 19206, image: oracle@eygle.com (P002)
*** SERVICE NAME:() 2010-11-10 10:37:26.263
*** SESSION ID:(2187.1) 2010-11-10 10:37:26.263
*** 2010-11-10 10:37:26.263
KCRP: blocks claimed = 84, eliminated = 0
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 84/84 = 1.0
Max compares per lookup = 0
Avg compares per lookup = 0/84 = 0.0
----------------------------------------------
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 84/84 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 880/880 = 1.0
----------------------------------------------
^A&A
^1b#
^1b!
^1b"
^0e'
^Mj8
^;&3
2010PS_Legal Entity
^6&L
Eoi_VND
Quick Payment: ID=47708
Cn/a
UNSENT
^9&1
HPAYMENT
CREATEDNAP_CHECKS
^0e)
Hxn
Dump file /ADMIN/bdump/erp_p001_19204.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /DBMS/erp/erpdb/10g
Linux
eygle.com
2.6.9-34.ELhugemem
#1 SMP Fri Feb 24 17:04:34 EST 2006
i686
Instance name: erp
Redo thread mounted by this instance: 1
Oracle process number: 16
Unix process pid: 19204, image: oracle@eygle.com (P001)
*** SERVICE NAME:() 2010-11-10 10:37:26.372
*** SESSION ID:(2189.1) 2010-11-10 10:37:26.372
*** 2010-11-10 10:37:26.372
KCRP: blocks claimed = 132, eliminated = 0
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 132/132 = 1.0
Max compares per lookup = 0
Avg compares per lookup = 0/132 = 0.0
----------------------------------------------
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 132/132 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 3219/3219 = 1.0
----------------------------------------------
^ij!
^ij$
^ij!
@e>df
>df^>df
Userxn
Chen Restaurant
300190143
CASH CLEARING
AP_CHECKS
CREATED
ACCOUNTED
^ij!
CHECK
en/a
Quick Payment: ID=47708
n/a^n/a
CHECK
Chen Restaurant
210301
5&1`
54^`
^1b$
^1b&
^1b6
^1b,
^1b-
^1b4
^1b5
^1b0
^1b2
Dump file /ADMIN/bdump/erp_p000_19202.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /DBMS/erp/erpdb/10g
Linux
eygle.com
2.6.9-34.ELhugemem
#1 SMP Fri Feb 24 17:04:34 EST 2006
i686
Instance name: erp
Redo thread mounted by this instance: 1
Oracle process number: 15
Unix process pid: 19202, image: oracle@eygle.com (P000)
*** SERVICE NAME:() 2010-11-10 10:37:26.386
*** SESSION ID:(2190.1) 2010-11-10 10:37:26.386
*** 2010-11-10 10:37:26.386
KCRP: blocks claimed = 181, eliminated = 0
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 181/181 = 1.0
Max compares per lookup = 0
Avg compares per lookup = 0/181 = 0.0
----------------------------------------------
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 1
Average hash chain = 181/181 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 8629/8629 = 1.0
----------------------------------------------
^ij0
AGENT_STATUS_MARKER
^AGENTS_MARKED
R0:b
^E!
^1b
^1b
^1b!
^1b!
^1b"
^1b"
^1b#

如此少見的案例，在此與大家分享。

原文：

[@more@]