本文简单记录一下最近一次数据恢复的过程。

事情的起因是,一个应用升级后,某一个操作导致一个表的几个列全部被更新为同一值(忍不住又要唠叨测试的重要性)。这样的错误居然出现在应用代码中,显然是重大的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表空间还是有好处,至少我已经有数次用闪回查询来恢复数据。

,

其实这篇文章,说讲述的跟DBA没有太大的关系,但是我写出来,希望对DBA有所帮助。

上个月一客户的某重要业务,出现2小时故障,事情闹得很大。故障发生在一个简单的INSERT语句上面,不幸的时执行那个SQL时总是报ORA-600[kcbget_24]这样的错误,其实导致事务一直失败。不过幸运的是,那个INSERT语句所要完成的业务功能只是整个业务环节中的可选功能,开发商也有开关来控制是否启动这个可选功能。虽然这个ORA-600错误,不能很快查到原因,但是却可以通过设置那个业务功能的开关来绕过这个问题。当时是我在现场处理的这个问题,从接到问题报告到解决问题,只花了很短的时间。那为什么整个故障历时了2小时。其主要原因在于,这个客户没有有效的监控手段,来监控错误,完全靠业务人员的反映,而业务人员又不能很快地发现问题。

事后检查错误出现的原因,发现是INSERT语句时,维护一个索引出现了索引,在做索引节点块分裂时报了ORA-600[kcbget_24]错误。ORA-600错误基本上是由BUG或数据损坏引起的,但BUG引起的可能性更大。那为什么之前好好的,怎么突然就出现错误了,再进一步追查发现出现问题的索引是新建的索引,而建这个索引的,是开发商的一个开发人员,未经过流程,就直接在表上建了。结果索引一建好,就出现问题了。

这里我想说的是,做DBA工作,不能有任何侥幸心理。这次发生的事故,是ORACLE的BUG引起,但是如果之前有过充分的测试,按流程来操作,很可能就分避免了这个问题的产生。对一个复杂的系统的维护,技术或许比较重要,但是我认为,流程和测试更重要。

这件事也让我想起2年前,我还在上一家单位(相对目前的工作性质来说是甲方)时,一个非常重要的业务系统,在一个非常重要的时间,崩溃了,完全不能用。这套系统本来还有一个月就功成身退,被新的业务系统所代替,结果最后一班岗也没站好,潜伏的一个致命的BUG爆发了(不是数据库软件的BUG,是业务软件的BUG)。头一天晚上系统的配置数据做了改动,按正常的流程是需要测试的,或许业务人员认为,配置的改动是常有的事,不需要测试,结果忽略了测试,结果第二天.....

工作中的某些环节,比如测试,是枯燥的,但是实在是不可或缺的。