标签归档:LogMiner

基于LogMiner数据恢复

事情是这样的,十一放完长假上班第一天,业务人员来找说是一张表的数据少了很多,根据描述,这张表在9月25号查询时数据都还在,大概有23000多条记录,结果十一放完假上班第一天需要用这个表时,发现这个表的数据明显少了很多,只有900多条,问是怎么回事,能否把被删除的数据恢复回来,最好还能找出数据被莫名其妙删除的原因,是被人为误删还是应用程序出问题删除的。

作为一名时常打酱油的运维人员,简单看了下数据库情况分析了下(其实是懒),直接和业务人员说没有什么简单的没办法找回被删除的数据,除非用数据库备份整库恢复到被删除的时间之前(比如9月25号),然后open resetlog,再把这个表导出,然后再导入到生产数据库,但是这个数据库数据量有12T,整库恢复一次代价太大(需要准备一套测试环境),所以建议他们从应用入手找之前的操作记录补录(因为根据业务人员反馈,这张表数据是手工录入的,大概有一年的数据),后来这事也就没放在心上,过完周末上班第一天,业务人员直接投诉到科技处老总那,结果不用说了,业务,应用,开发,运维有关系的人都叫去谈话,领导要求想办法找回数据,后来业务人员通过一个对比程序日志确定了这张表数据被删除的时间点:2014年9月30日20点-2014年9月30日22点,于是才有了这篇文章。

先介绍一下本次恢复15天前被删除数据的方法及思路,然后再简要说下操作过程:
方法1 使用数据库备份,整库恢复到9月25号前,open resetlog打开数据库,导出表中数据,再导入生产数据库中。
优点:操作简单,只需执行简单的RMAN和导入导出命令操作 ;
缺点:需要准备测试环境,整个过程耗时,且无法查明数据被删除的原因 。
方法2 使用数据库备份,恢复出9月25号前system表空间数据文件,被删除数据表所在的数据文件,使用类似于ODU工具直接从数据文件中抽取出这个表的数据,然后使用sqlldr导入生产数据库中。
优点:只需要恢复出很小数据量的数据文件,该过程与方法1)相比,节省了大量时间,并且不需要额外的硬件资源搭建测试环境 ;
缺点:类似于ODU恢复工具一般均收费,并且费用昂贵,其次不能保证找回所有数据记录,当然也无法查明数据被删除的原因
方法3 使用logminer挖掘30号20点到22点所有归档日志 。
有点:可能找到数据被删除的原因,是由于应用程序错误删除还是人为误操作导致(v$logmnr_contents视图中session_info);
缺点:不能保证找回所有被删除数据(即这个表中的数据不是因为delete导致丢失的,或是数据库未开启最小补充日志)

从上面三个思路出发,最终选择了方法2和3同时进行,这里先说下这个case最后处理的结果:最终使用方法三logminer分析了30号晚上20点到22点两个小时的归档日志,最终将被删除的数据全部找回,但是并未能确定数据丢失是因为应用程序错误还是人为误操作导致的,但是可以确定该表在30号晚上20点16分30秒时被一次批量删除多条记录(从目前分析来看,基本可以判定很可能是人为执行了delete from table_name的操作导致),目前该问题已经上升到掉监控录像。

下面说下处理过程及遇到的问题,对于方法2这里不会介绍如何使用ODU这个工具,有兴趣可以自己去看这个软件使用方法,但是这里还是要说下,方法2中使用ODU抽取表数据并没有成功,因为我这里平台是HP-PA,可能是因为ODU这个工具对HP平台支持不好,所以我没有实验成功,但是不要怀疑我的操作,因为我在Linux和Windowns平台上都是实验成功了,最后也不要问我哪里来的ODU工具,我是不会说的!甚至我还实验了与ODU类似的数据抽取工具MDATA,但是很遗憾也没成功,最后还联系了软件作者debug,最后无奈放弃了第二种方法。

但是这里还是得再提一下我在方法2中使用ODU抽取表中数据之前,恢复system表空间数据文件和被删除数据表所在的数据文件时遇到的一个问题:由于该数据库备份离9月30号最近的一次level 0的备份是在9月27号发起的,因此我需要从9月27号的备份集中恢复出system表空间数据文件和被删除数据表所在的数据文件,我们知道恢复一个数据文件时我们会执行restore datafile file# from xxxx命令,这里xxxx有autobackup, double-quoted-string, single-quoted-string, tag四种方式,但是当控制文件中记录有多次备份产生的备份集时,当我们需要指定从较早某一个备份集恢复出数据文件时,如果此时我们使用了备份集的名字,则会报错,示例如下:

RMAN> list backup; 


List of Backup Sets
=================== 

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
8       Full    599.57M    DISK        00:01:08     03-AUG-14      
        BP Key: 8   Status: AVAILABLE  Compressed: NO  Tag: TAG20140803T105610
        Piece Name: /oracle/product/10.2.0/db_1/dbs/16pf0via_1_1
  List of Datafiles in backup set 8
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  1       Full 469228     03-AUG-14 /oracle/oradata/10g/system01.dbf
  2       Full 469228     03-AUG-14 /oracle/oradata/10g/undotbs01.dbf
  3       Full 469228     03-AUG-14 /oracle/oradata/10g/sysaux01.dbf
  4       Full 469228     03-AUG-14 /oracle/oradata/10g/users01.dbf
  5       Full 469228     03-AUG-14 /oracle/oradata/10g/example01.dbf
  6       Full 469228     03-AUG-14 /oracle/oradata/10g/test01.dbf 

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
9       Full    6.80M      DISK        00:00:02     03-AUG-14      
        BP Key: 9   Status: AVAILABLE  Compressed: NO  Tag: TAG20140803T105610
        Piece Name: /oracle/product/10.2.0/db_1/dbs/17pf0vkl_1_1
  Control File Included: Ckp SCN: 469265       Ckp time: 03-AUG-14
  SPFILE Included: Modification time: 03-AUG-14 

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
10      Full    370.88M    DISK        00:00:25     05-AUG-14      
        BP Key: 10   Status: AVAILABLE  Compressed: NO  Tag: TAG20140805T184517
        Piece Name: /oracle/product/10.2.0/db_1/dbs/18pf73pt_1_1
  List of Datafiles in backup set 10
  File LV Type Ckp SCN    Ckp Time  Name
  ---- -- ---- ---------- --------- ----
  1       Full 660328     05-AUG-14 /oracle/oradata/10g/system01.dbf 

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
11      Full    6.80M      DISK        00:00:02     05-AUG-14      
        BP Key: 11   Status: AVAILABLE  Compressed: NO  Tag: TAG20140805T184517
        Piece Name: /oracle/product/10.2.0/db_1/dbs/19pf73qm_1_1
  Control File Included: Ckp SCN: 660337       Ckp time: 05-AUG-14
  SPFILE Included: Modification time: 05-AUG-14 

RMAN> run {
2> set newname  for datafile 1 to '/home/oracle/system.dbf';
3> restore datafile 1 from '/oracle/product/10.2.0/db_1/dbs/16pf0via_1_1';
4> } 

executing command: SET NEWNAME 

Starting restore at 06-AUG-14
using channel ORA_DISK_1 

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of restore command at 08/06/2014 02:16:39
RMAN-06509: only SPFILE or control file can be restored from autobackup 

RMAN> 

这里我指定从8月3号备份集/oracle/product/10.2.0/db_1/dbs/16pf0via_1_1中恢复system表空间数据文件时报错,原因上面报错已经很清楚了,当然使用备份集的TAG来恢复是没有问题的,我们还是从8月3号的备份集中恢复system表空间数据文件,但这次用TAG来恢复:

RMAN> run {
2> set newname for datafile 1 to '/home/oracle/system.dbf';
3> restore datafile 1 from TAG 'TAG20140803T105610';
4> } 

executing command: SET NEWNAME
using target database control file instead of recovery catalog 

Starting restore at 06-AUG-14
allocated channel: ORA_DISK_1
channel ORA_DISK_1: sid=158 devtype=DISK 

channel ORA_DISK_1: starting datafile backupset restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
restoring datafile 00001 to /home/oracle/system.dbf
channel ORA_DISK_1: reading from backup piece /oracle/product/10.2.0/db_1/dbs/16pf0via_1_1
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle/product/10.2.0/db_1/dbs/16pf0via_1_1 tag=TAG20140803T105610
channel ORA_DISK_1: restore complete, elapsed time: 00:00:35
Finished restore at 06-AUG-14 

这里结果已经很明显是成功的了,因为在恢复datafile 1时读取的备份片是/oracle/product/10.2.0/db_1/dbs/16pf0via_1_1,而这个备份片对应的时间正是8月3号,但是试想一种情况,如果控制文件中记录的所有备份集的TAG都完全是一样的,那要怎么样才能从指定的备份集中恢复需要的数据文件呢?比如我上面list backup中所有的备份集的TAG都是完全一样,不要觉得这不可能,我这次方法2恢复system表空间数据文件及被删除数据表所在的数据文件时就遇到这样的问题,发现控制文件中记录的所有备份集的TAG都是完全一样HOT_BACKUP_LEVEL0,去查备份脚本才发现是因为在备份脚本中写死了TAG,先说下这个备份脚本肯定不是我写的。那如何从8月3号的备份集中恢复出system表空进数据文件datafile 1呢?那么上面这种使用TAG恢复datafile 1肯定是不行了,因为控制文件中所记录的所有备份集TAG都一样,RMAN肯定会从离当前最近的备份集中恢复datafile 1,那恢复出来的datafile 1就是8月5号的,这明显不是我们想要的。如果真遇到我了上面说的,控制文件中记录的所有备份集的TAG都相同时,该如何从8月3号的备份集中恢复出datafile 1呢?方法其实很简单,只需要在run块中加set until time限定即可,示例如下:

RMAN> run {
2> set newname for datafile 1 to '/home/oracle/system.dbf';
3> sql 'alter session set nls_date_format="YYYY-MM-DD HH24:MI:SS"';
4> set until time '2014-08-04 00:00:00';
5> restore datafile 1;
6> } 

executing command: SET NEWNAME 

sql statement: alter session set nls_date_format="YYYY-MM-DD HH24:MI:SS" 

executing command: SET until clause 

Starting restore at 06-AUG-14
using channel ORA_DISK_1 

channel ORA_DISK_1: starting datafile backupset restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
restoring datafile 00001 to /home/oracle/system.dbf
channel ORA_DISK_1: reading from backup piece /oracle/product/10.2.0/db_1/dbs/16pf0via_1_1
channel ORA_DISK_1: restored backup piece 1
piece handle=/oracle/product/10.2.0/db_1/dbs/16pf0via_1_1 tag=TAG20140803T105610
channel ORA_DISK_1: restore complete, elapsed time: 00:00:25
Finished restore at 06-AUG-14 

从上面输出可以看出,当我使用set until time限制时间为2014-08-04 00:00:00后,直接执行restore datafile 1时,RMAN会从8月4号之前最近的备份集中恢复我们想要恢复的数据文件,从上面可以看出是从备分片/oracle/product/10.2.0/db_1/dbs/16pf0via_1_1中恢复出的1号数据文件即8月3号。

下面简要介绍下方法3过程,关于logminer参考LogMiner百度百科,上面已经写的很全了,使用logminer分析日志,步骤很简单这里先列一下操作过程,后面再说重点关注的地方:
1)安装LOGMNR包,需要本步骤没什么可多说的,只是需要注意在连接数据库的时候默认最好使用本地验证方式
$ sqlplus / as sysdba
SQL> @$ORACLE_HOME/rdbms/admin/dbmslm.sql
SQL> @$ORACLE_HOME/rdbms/admin/dbmslmd.sql
SQL> @$ORACLE_HOME/rdbms/admin/dbmslms.sql
2)创建数据字典
SQL> show parameter utl_file_dir
SQL> alter system set utl_file_dir=’/home/oracle’ scope=spfile;
SQL> EXECUTE dbms_logmnr_d.build(‘dictionary.ora’,’/home/oracle’);
3)添加日志文件
SQL> EXECUTE dbms_logmnr.add_logfile(LogFileName=>’/u01/app/archive/1_108_691175178.dbf’,Options=>dbms_logmnr.new);
SQL> EXECUTE dbms_logmnr.add_logfile(LogFileName=>’/u01/app/archive/1_108_691175177.dbf’,Options=>dbms_logmnr.addfile);
备注:这里分析的日志可以是在线日志,也可以使归档日志,如果有多组日志需要分析,那么添加第一条日志时Options=>dbms_logmnr.new,添加其余日志时Options=>dbms_logmnr.new
4)查看将要分析的日志文件
SQL> select filename from v$logmnr_logs;
5)使用字典分析日志文件
SQL> execute dbms_logmnr.start_logmnr(dictfilename=>’/home/oracle/dictionary.ora’);
6)查询结果
SQL> select * from v$logmnr_contents where … and … ;
7)退出logmnr
SQL> execute dbms_logmnr.end_logmnr;

请注意,上面的7步操作请在一个session中操作,否则不会执行成功,因为logminer需要在同一个会话中执行执行以上步骤。这里本想用一个完整的例子来演示logminer挖掘日志的过程,但是经过多次试验验证,发现logminer在数据库未打开最小补充日志时,其使用会出现很多问题,例如,我删除了一个表100条记录,然后使用logminer分析与该表delete操作相关的尽可能多的日志,但却发现v$logmnr_contents中只能找到84条此表delete数据的SQL语句,甚至还出现过找不到与此表相关的任何DML语句的情况,这里不要怀疑我的操作过程,因为当我遇到这个问题后,找了我们Team其他成员共同测试过,大家均遇到这种情况。要避免这些问题,最有效的办法就是开启数据库的最小补充日志,当对表执行DML操作后,例如插入20条数据,更新10条数据,删除30条数据,使用logminer分析与此表相关的这些DML操作归档日志,就可以从v$logmnr_contents中找出对表执行插入更新删除操作的60条SQL语句。这里注意,你在对表进行插入更新删除时,绝对没有写60条SQL语句去分别操作每一条符合条件的数据记录,但是使用logminer挖掘日志从v$logmnr_contents视图中的sql_redo得出的SQL语句却有60条,这是为什么呢?仔细看一下v$logmnr_contents这个视图中的sql_redo和sql_undo就很容易明白了,假如T1结构如下:
lynn@10G> select * from t1;

        ID NA
———- –
         1 aa
         2 bb
         3 cc
         4 dd
         5 ee

此时你对t1表执行delete from t1 where id < 4这个操作,有假设3条记录被删除了,因为sql_undo必须记录sql_redo的相反操作,所以Oracle将delete from t1 where id < 4这个操作拆分成3条语句,即将id < 4满足删除条件的三条数据记录分别写成一个delete语句(where条件中补全除了id字段的其他字段值),也就是sql_redo中记录的:
SQL> delete from t1 where id=1 and na=’aa';
SQL> delete from t1 where id=2 and na=’bb';
SQL> delete from t1 where id=3 and na=’cc';
相应的sql_undo语句为:
SQL> insert into t1 values (1,’aa’);
SQL> insert into t1 values (2,’bb’);
SQL> insert into t1 values (3,’cc’);
也就是说无论t1这个表有多少列,虽然我们在执行delete时where条件只限定了id这一个条件,但是在日志中记录时,Oracle会将所有要删除的每个数据记录都写成一个delete语句,即在where条件中补全所有的字段值,这样每个要删除的数据记录的delete语句也就是唯一的,那么对应的sql_undo也就出来了,insert和update操作也同理。

还有一点需要说明,如果数据库打开了最小补充日志,使用logminer挖掘日志,不但可以找回因DML操作导致的数据丢失或错误修改,还可以找出这些错误操作是哪个用户,在哪台机器上操作的,因为v$logmnr_contents视图中username和session_info这两个字段会记录。

最后先想强调的是,虽然文章开始提到了,我使用logminer找回了所有被误删除的数据,但是由于生产数据库最小补充日志没有开启,因此最后也无法确定该误删除操作是哪个用户在哪台机器上操作的,并且这里还是想说,虽然我用logminer将被删除的数据找回来了,只能说很幸运,如果真的出现我说的那种极端情况,logminer挖不倒任何与DML操作相关的操作,那最后可能只能像上面提到的方法1搭建新环境,将整库备份恢复到一个时间点,导出表中数据再导入生产库。所以日常操作规范真是必要的,同时不要总抱着侥幸心理,使用一些极端方法可以恢复数据就不注意规范操作,这样总有一天会出问题的,与君共勉!