事情的起因是,一個應用升級後,某一個操作導致一個表的幾個列全部被更新為同一值(忍不住又要唠叨測試的重要性)。這樣的錯誤居然出現在應用代碼中,顯然是重大的BUG。那個是罪魁禍首的SQL,UPDATE語句,其WHERE條件僅僅只有一個where 1=1。
系統的維護人員稱是星期五出的錯,發現出錯是在星期天,也就是我恢復數據的日期,與聲稱的出錯時間已經隔了將近2天。開始嘗試用Flashback query恢復數據,報ORA-01555錯誤,此路不通。維護人員說,星期五之前的RMAN備份已經被刪除了(又是一個備份恢復策略不當地例子),使用基於時間點的恢復也不可能了。剩下的一條路,只有使用log miner。還好歸檔文件還在數據庫服務器上。
這套庫是一套RAC數據庫,由於沒有人能確認操作發生在哪個節點,因此需要將一個節點下所有的歸檔復制到另一個節點上(如果沒有足夠的空間,可以使用NFS)。然後需要找到我們用於數據恢復的歸檔日志:
set linesize 170 pagesize 10000 alter session set nls_date_format='yyyy-mm-dd hh24:mi:ss'; col name for a30 col first_change for a10 col next_change for a10 select max(first_time) from v$archived_log where first_time < to_date('200909251900','yyyymmddhh24mi'); --這裡的時間為錯誤發生時估計的最早時間。 select sequence#,first_time,name,to_char(first_change#,'xxxxxxxx') first_change, to_char(next_change#,'xxxxxxxx') next_change from v$archived_log where first_time >=to_date('200909251707','yyyymmddhh24mi') order by 2;--這裡的時間為前一SQL的max(first_time)結果 SEQUENCE# FIRST_TIME NAME FIRST_CHAN NEXT_CHANG ---------- ------------------- ------------------------------ ---------- ---------- 4039 2009-09-25 17:07:10 /arch/db1_1_4039.arc 88ce7eff 88d1457c 4040 2009-09-26 12:24:52 /arch/db1_1_4040.arc 88d1457c 88d1459f 4041 2009-09-26 12:25:22 /arch/db1_1_4041.arc 88d1459f 88d156a4 4688 2009-09-26 12:37:59 /arch/db1_2_4688.arc 88d1457f 88d1464a 4689 2009-09-26 12:38:27 /arch/db1_2_4689.arc 88d1464a 88d1569c 4042 2009-09-26 12:54:44 /arch/db1_1_4042.arc 88d156a4 88d157e7 4043 2009-09-26 12:54:56 /arch/db1_1_4043.arc 88d157e7 88d1ab06 4690 2009-09-26 13:07:47 /arch/db1_2_4690.arc 88d1569c 88d1570b 4691 2009-09-26 13:08:00 /arch/db1_2_4691.arc 88d1570b 88d1ab09 4044 2009-09-26 15:27:32 /arch/db1_1_4044.arc 88d1ab06 88d1ab0d 4045 2009-09-26 15:27:35 /arch/db1_1_4045.arc 88d1ab0d 88d25091 4692 2009-09-26 15:40:36 /arch/db1_2_4692.arc 88d1ab09 88d1ab77 4693 2009-09-26 15:40:39 /arch/db1_2_4693.arc 88d1ab77 88d25094 4046 2009-09-26 22:24:07 /arch/db1_1_4046.arc 88d25091 88d250db 4047 2009-09-26 22:24:19 /arch/db1_1_4047.arc 88d250db 88d2515e 4048 2009-09-26 22:24:29 /arch/db1_1_4048.arc 88d2515e 88d25167 4049 2009-09-26 22:24:41 /arch/db1_1_4049.arc 88d25167 88d25cac 4694 2009-09-26 22:37:13 /arch/db1_2_4694.arc 88d25094 88d25147 4695 2009-09-26 22:37:25 /arch/db1_2_4695.arc 88d25147 88d2515b 4696 2009-09-26 22:37:33 /arch/db1_2_4696.arc 88d2515b 88d2516a 4697 2009-09-26 22:37:47 /arch/db1_2_4697.arc 88d2516a 88d25ca9 4050 2009-09-26 22:41:57 /arch/db1_1_4050.arc 88d25cac 88d25cde 4698 2009-09-26 22:55:01 /arch/db1_2_4698.arc 88d25ca9 88d25dcf 4699 2009-09-26 22:55:19 /arch/db1_2_4699.arc 88d25dcf 88dBD27e
嘗試找到數據被錯誤更新的時間點:
exec sys.dbms_logmnr.add_logfile(logfilename=>'/arch/db1_1_4038.arc'); exec sys.dbms_logmnr.add_logfile(logfilename=>'/arch/db1_1_4039.arc'); exec sys.dbms_logmnr.start_logmnr(options=>sys.dbms_logmnr.dict_from_online_catalog); col sql_redo for a50 select scn,timestamp,username,sql_redo from v$logmnr_contents where Operation='UPDATE' and upper(sql_redo) like '%TBL_FORM_FORM%' and sql_redo like '%SGS0900021BNc10%' --這個值是UPDATE時某一列被更新後的值,用在這裡便於查找。 order by scn,timestamp; exec sys.dbms_logmnr.end_logmnr;
很不幸的是,沒有找著需要的數據。再往後找了幾個日志,也沒找著。
如果一直找下去,顯然會消耗比較長的時間,業務也已經停止了。不過可以用一種簡單的方法來查找數據被錯誤更新發生的時間:一個比較大的表,通常段頭後面的那個塊,也就是存儲那個表的數據的第1個塊,通常是很少更新的,至少當時恢復的那個表是這樣一種情況。我們可以通過數據塊中ITL上的事務SCN來滿足我們的要求。
SQL> select tablespace_name,extent_id,file_id,block_id,blocks from dba_extents where owner='XXX' and segment_name='TBL_FORM_FORM' order by extent_id; TABLESPACE_NAME EXTENT_ID FILE_ID BLOCK_ID BLOCKS ---------------- ---------- ---------- ---------- ------- XXXX 0 16 25481 128 XXXX 1 17 23433 128 XXXX 2 18 21385 128 XXXX 3 19 19977 128 XXXX 4 16 23945 128 XXXX 5 17 8585 128 XXXX 6 18 14217 128 XXXX 7 19 18825 128 SQL> alter system dump datafile 16 block 25482; System altered. Start dump data blocks tsn: 4 file#: 16 minblk 25482 maxblk 25482 buffer tsn: 4 rdba: 0x0400638a (16/25482) scn: 0x0000.88e21027 seq: 0x02 flg: 0x00 tail: 0x10270602 frmt: 0x02 chkval: 0x0000 type: 0x06=trans data Block header dump: 0x0400638a Object id on Block? Y seg/obj: 0x40d8 csc: 0x00.88e20c40 itc: 2 flg: - typ: 1 - DATA fsl: 0 fnx: 0x0 ver: 0x01 Itl Xid Uba Flag Lck Scn/Fsc 0x01 0x0010.011.0006ed74 0x03c002a0.2f48.07 C--- 0 scn 0x0000.88d7af30 0x02 0x0012.019.000027e0 0x03c00ede.05de.42 C--- 0 scn 0x0000.44e2ee39
從上面的結果可以看到,數據塊的ITL中,最新的事務其SCN為88d7af30,正處於最後一個歸檔日志的first_change#和last_change#之間,即88d25dcf和88dBD27e之間,難不成這個錯誤是今天早上才發生的?於是我挖掘最後1個歸檔日志,結果發生錯誤的確是發生在早上,也就是我開始進行恢復操作之前半個小時。
既然錯誤並沒有發生太久,同時這個系統也允許一定的數據丟失,那就使用Flashback query,得到UPDATE操作之前的數據即可。
create table tbl_form_form_new as select * from tbl_form_form as of timestamp to_date('2009-09-27 09:08:00','yyyy-mm-dd hh24:mi:ss'); --當然這裡也可以按SCN進行閃回。
幸運的是,這次閃回查詢成功了。看起來足夠大的UNDO表空間還是有好處,至少我已經有數次用閃回查詢來恢復數據。