本文简单记录一下最近一次数据恢复的过程。
事情的起因是,一个应用升级后,某一个操作导致一个表的几个列全部被更新为同一值(忍不住又要唠叨测试的重要性)。这样的错误居然出现在应用代码中,显然是重大的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表空间还是有好处,至少我已经有数次用闪回查询来恢复数据。
在应用程序中对于update/detel语句采用动态拼接的方式来生成sql是要非常小心的,加上1=1的条件,是方便了代码开发,但是留下了地雷。我们现在都要求不能加1=1这样的条件
[回复]
老熊 回复:
9月 29th, 2009 at 2:20 下午
@NinGoo, 这的确是比较危险。我也是第一次遇上应用代码的问题导致了数据被错误更新。以前经常遇到的是人为错误。
[回复]
一个比较大的表,通常段头后面的那个块,也就是存储那个表的数据的第1个块,通常是很少更新的,
如果这个表是顺序insert,基本没有update的情况下应该是这样的吧…
或者可以看看ora_rowscn
[回复]
老熊 回复:
9月 29th, 2009 at 8:36 下午
@dhhb, update一般也是UPDATE最近的数据。比如几年积累起来的数据,几年前的肯定是很少更新的。
[回复]
写应用程序的哥们有没有请你吃饭啊?
[回复]
老熊 回复:
9月 30th, 2009 at 12:26 下午
@半瓶, 那哥们儿远在千里之外呢,呵呵。
[回复]
“一个比较大的表,通常段头后面的那个块,也就是存储那个表的数据的第1个块,通常是很少更新的,至少当时恢复的那个表是这样一种情况。我们可以通过数据块中ITL上的事务SCN来满足我们的要求”,这个是问题解决最关键的步骤!
[回复]
“一个比较大的表,通常段头后面的那个块,也就是存储那个表的数据的第1个块,通常是很少更新的,至少当时恢复的那个表是这样一种情况。”
—-这个“方法”的确有点“经典”啊!
通常我会直接来一个 version query。
[回复]
老熊 回复:
10月 9th, 2009 at 10:48 下午
@Rain@DNA, 因为开始的时候维护人员给出了错误的时间信息,并且他们在做那个时间点的flashback query是失败的。所以开始也排除了version query这种做法。
[回复]
发现一个笔误。
alter system dump datafile 16 block 25481;
应该是block 25482吧
[回复]
老熊 回复:
10月 9th, 2009 at 10:56 下午
@jlttt, 谢谢你的指正。
[回复]
这个block格式的知识, 活学活用啊! 不错.
[回复]
老熊 回复:
10月 11th, 2009 at 3:43 下午
@dbatools, 过奖,学到block格式知识,的确有很多用处啊,呵呵
[回复]
10号晚上, 去你们happy的地方了, 不过你在唱歌, 就没打扰你了.
[回复]
老熊 回复:
10月 12th, 2009 at 9:47 上午
@dbatools, 我就说frank咋就不见了。我不唱歌,只在那里喝酒,跟同事聊天而已。
[回复]
“系统的维护人员称是星期五出的错,发现出错是在星期天,也就是我恢复数据的日期,与声称的出错时间已经隔了将近2天”
开发公司有误导之嫌疑。
[回复]