老熊的三分地-Oracle及数据恢复

在以前的一篇文章中，我提到千万不能将Oracle数据库的global_name更新为空。这不，事儿来了。我的一个同事，提到了一个解决办法，不过那个办法实际上是一种不完全恢复的办法，如果没有备份，就行不通。如果没有备份，可以使用BBED来修改块来解决这个问题，不过使用bbed仍然比较麻烦。

下面是我一时心血来潮进行的一次测试。测试环境，10.2.0.4 for Linux AS 5.5。注意，不要在生产库上模仿。

首先UPDATE GLOBAL_NAME为空，COMMIT后以abort方式关闭数据库，以abort方式只是为了增加点难度。之后再启动数据库。

SQL> update global_name set global_name='';

1 row updated.

SQL> commit;

Commit complete.

SQL> shutdown abort
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area  209715200 bytes
Fixed Size                  1266632 bytes
Variable Size              75500600 bytes
Database Buffers          130023424 bytes
Redo Buffers                2924544 bytes
Database mounted.
ORA-01092: ORACLE instance terminated. Disconnection forced

启动失败，不出意料出现ORA-600 [18062]错误：

Mon Sep  6 15:43:31 2010
Errors in file /oracle/app/oracle/admin/xty/udump/xty_ora_3149.trc:
ORA-00600: internal error code, arguments: [18062], [], [], [], [], [], [], []
QMNC started with pid=16, OS id=3151
Mon Sep  6 15:43:33 2010
Errors in file /oracle/app/oracle/admin/xty/udump/xty_ora_3149.trc:
ORA-00600: internal error code, arguments: [18062], [], [], [], [], [], [], []
Mon Sep  6 15:43:33 2010
Errors in file /oracle/app/oracle/admin/xty/udump/xty_ora_3149.trc:
ORA-00600: internal error code, arguments: [18062], [], [], [], [], [], [], []

下面来解决这个问题。

第1步，重启数据库到MOUNT状态：

[oracle@xty ~]$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.4.0 - Production on Mon Sep 6 15:43:47 2010

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.

Connected to an idle instance.

SQL> startup mount
ORACLE instance started.

Total System Global Area  209715200 bytes
Fixed Size                  1266632 bytes
Variable Size              75500600 bytes
Database Buffers          130023424 bytes
Redo Buffers                2924544 bytes
Database mounted.

第2步，在另一个窗口中，使用gdb

[oracle@xty ~]$ ps -ef | grep LOCAL
oracle    3186  3156  0 15:43 ?        00:00:00 oraclexty (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))
oracle    3188  2978  0 15:44 pts/3    00:00:00 grep LOCAL
[oracle@xty ~]$ gdb $ORACLE_HOME/bin/oracle 3186
GNU gdb (GDB) Red Hat Enterprise Linux (7.0.1-23.el5)
...（省略）...
Reading symbols from /oracle/app/oracle/product/10.2.0/bin/oracle...(no debugging symbols found)...done.
Attaching to program: /oracle/app/oracle/product/10.2.0/bin/oracle, process 3186
Reading symbols from /etc/libcwait.so...(no debugging symbols found)...done.
Loaded symbols for /etc/libcwait.so
Reading symbols from /oracle/app/oracle/product/10.2.0/lib/libskgxp10.so...(no debugging symbols found)...done.
Loaded symbols for /oracle/app/oracle/product/10.2.0/lib/libskgxp10.so
Reading symbols from /oracle/app/oracle/product/10.2.0/lib/libhasgen10.so...(no debugging symbols found)...done.
...（省略）...
Reading symbols from /oracle/app/oracle/product/10.2.0/lib/libnnz10.so...(no debugging symbols found)...done.
Loaded symbols for /oracle/app/oracle/product/10.2.0/lib/libnnz10.so
Reading symbols from /usr/lib/libaio.so.1...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libaio.so.1
Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libnsl.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libnss_files.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libnss_files.so.2
0x0025d402 in __kernel_vsyscall ()
(gdb)  break kokiasg
Breakpoint 1 at 0xa3d404d
(gdb) continue
Continuing.

第3步，OPEN数据库：

SQL> alter database open;

约等一会儿，在alert日志里面可以看到：

Mon Sep  6 15:44:41 2010
SMON: enabling cache recovery
SMON: enabling tx recovery
Mon Sep  6 15:44:41 2010
Database Characterset is ZHS16GBK

在gdb的输出可以看到：

Breakpoint 1, 0x0a3d404d in kokiasg ()

第4步，在gdb那里中止OPEN：

(gdb) kill
Kill the program being debugged? (y or n) y     
(gdb) quit

sqlplus会提示：

alter database open
*
ERROR at line 1:
ORA-03113: end-of-file on communication channel

这一次，Instance并没有terminated。只是Server process被KILL了。

第5步，还原GLOBAL_NAME：

[oracle@xty ~]$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.4.0 - Production on Mon Sep 6 15:45:09 2010

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> select status from v$instance;

STATUS
------------
OPEN

SQL> update global_name set global_name='XTY';

1 row updated.

SQL> commit
  2  ;
commit
*
ERROR at line 1:
ORA-01109: database not open

虽然可以执行UPDATE，但是不能COMMIT。再试试能不能做DDL：

SQL> create table t1 ( a int);

Table created.

成功了。

在另会一个会话中查看GLOBAL_NAME：

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
XTY

GLOBAL_NAME回来了。

这里通过DDL的隐式提交特性来UPDATE GLOBAL_NAME。其实还有更简单的办法：OCI主动断开连接时的自动提交。如果UPDATE之后，直接退出sqlplus，UPDATE GLOBAL_NAME的事务实际也提交了。看起来ORACLE这时只是不能执行显式的COMMIT语句。

第6步，重启数据库：

SQL> shutdown immediate
ORA-00604: error occurred at recursive SQL level 1
ORA-01109: database not open


SQL> shutdown abort
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area  209715200 bytes
Fixed Size                  1266632 bytes
Variable Size              75500600 bytes
Database Buffers          130023424 bytes
Redo Buffers                2924544 bytes
Database mounted.
Database opened.

看起来只能以abort方式关闭数据库：
成功了，数据库起来了。没有数据丢失，没有使用备份。不需要基于时间点的恢复，不需要BBED，不需要Resetlog。

internal, recovery

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

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

flashback, recovery

在Oracle的备份恢复过程中，需要注意数据文件的unrecoverable，不适当的操作很容易造成恢复后有大量的坏块。在视图v$datafile中，UNRECOVERABLE_CHANGE#和UNRECOVERABLE_TIME分别表示数据文件最后一个unrecoverable操作的change#和时间。unrecoverable通常就是指不记录日志的操作（nologging），这样当用一个旧的数据文件还原后，用日志进行恢复时，由于日志文件没有记录unrecoverable的操作时的日志，导致那些操作的数据块为逻辑坏块（实际上在日志文件中为这样的操作产生了一些重做日志项，在恢复时，根据这些重做日志项，直接将相应的数据块标记为坏块）。常见的以下几种情况：
1. 非归档模式下的create table as 操作和直接路径插入（如加了append hint的insert语句和直接路径装载）
2. 归档模式下的create table xxx nologging（即创建表时为表指定了nologging）和nologging表的直接路径插入。
在数据库（或表空间）为force logging时，任何操作都会记录日志。不会有unrecoverable操作。

下面先做个实验（数据库版本为9.2.0.1）来看看这两列：

数据库当前处于非归档模式;

SQL> select name,checkpoint_time,unrecoverable_time from v$datafile where file#=10;

NAME CHECKPOINT_TIME UNRECOVERABLE_TIME
---------------------------------------- ------------------- -------------------
D:\ORACLE\ORADATA\XJ\TEST01.DBF 2008-09-23 09:28:22

SQL> create table t tablespace test nologging as select * from dba_objects where rownum< =10; 表已创建。 SQL> select name,checkpoint_time,unrecoverable_time from v$datafile where file#=10;

NAME CHECKPOINT_TIME UNRECOVERABLE_TIME
---------------------------------------- ------------------- -------------------
D:\ORACLE\ORADATA\XJ\TEST01.DBF 2008-09-23 09:28:22

可以看到，unrecoverable_time为空。想一想就可以理解，unrecoverable操作都是将数据直接写入了数据文件，没有经过SGA的缓存，非归档模式下的物理备份都是一致的冷备份，不需要日志来进行恢复，因此对于非归档模式下并不存在unrecoverable操作。unrecoverable只是针对归档模式的。下面将数据库置为归档模式后，重复上述过程，进行验证：

SQL> create table t tablespace test nologging as select * from dba_objects where rownum< =10; 表已创建。 SQL> select name,checkpoint_time,unrecoverable_time,unrecoverable_change# from v$datafile where file#=10;

NAME CHECKPOINT_TIME UNRECOVERABLE_TIME UNRECOVERABLE_CHANGE#
---------------------------------------- ------------------- ------------------- ---------------------
D:\ORACLE\ORADATA\XJ\TEST01.DBF 2008-09-23 09:45:03 2008-09-23 09:45:41 1298047

可以看到，v$datafile视图中unrecoverable_time和unrecoverable_change#已经有了值。

下面来看看unrecoverable_time是最后一次unrecoverable操作的开始时间还是结束时间？
创建一个具有延时功能的函数：

create or replace function f_cdate return date
as
begin
dbms_lock.sleep(10);
return sysdate;
end;

SQL> create table t (d date) nologging tablespace test;

表已创建。

SQL> begin
2 dbms_output.put_line('start test:'||sysdate);
3 insert /*+ append */ into t select f_cdate from dba_objects where rownum< =10; 4 dbms_output.put_line('after insert:'||sysdate); 5 dbms_lock.sleep(60); 6 commit; 7 dbms_output.put_line('end test:'||sysdate); 8 end; 9 / start test:2008-09-23 10:31:50 after insert:2008-09-23 10:33:33 end test:2008-09-23 10:34:34 PL/SQL 过程已成功完成。 SQL> select name,checkpoint_time,unrecoverable_time,unrecoverable_change# from v$datafile where file#=10;

NAME CHECKPOINT_TIME UNRECOVERABLE_TIME UNRECOVERABLE_CHANGE#
---------------------------------------- ------------------- ------------------- ---------------------
D:\ORACLE\ORADATA\XJ\TEST01.DBF 2008-09-23 09:45:03 2008-09-23 10:33:33 1299032
SQL> begin
2 dbms_output.put_line('start test:'||sysdate);
3 insert /*+ append */ into t select f_cdate from dba_objects where rownum< =10; 4 dbms_output.put_line('after insert:'||sysdate); 5 dbms_lock.sleep(60); 6 rollback; 7 dbms_output.put_line('end test:'||sysdate); 8 end; 9 / start test:2008-09-23 10:37:59 after insert:2008-09-23 10:39:42 end test:2008-09-23 10:40:43 PL/SQL 过程已成功完成。 SQL> select name,checkpoint_time,unrecoverable_time,unrecoverable_change# from v$datafile where file#=10;

NAME CHECKPOINT_TIME UNRECOVERABLE_TIME UNRECOVERABLE_CHANGE#
---------------------------------------- ------------------- ------------------- ---------------------
D:\ORACLE\ORADATA\XJ\TEST01.DBF 2008-09-23 09:45:03 2008-09-23 10:39:42 1299157

可以看到unrecoverable_time为unrecoverable操作完成的那个时间，不管事务是否提交。

对于数据库备份后的恢复，需要注意查询v$datafile视图中关于unrecoverable操作时间，如果unrecoverable操作时间在数据文件备份之后（更精确的比较是通过change#，比较文件的checkpoint_change#和unrecoverable_change#），则恢复会产生坏块。

建议重要的数据库，将数据库置为force logging（当然数据库应当是归档模式），避免无意的产生了unrecoverable操作。或者在做了unrecoverable操作之后立即进行数据文件的备份。

PS：关于不产生日志的操作，请参见metalink NOTE:269274.1 CHECK FOR LOGGING/NOLOGGING ON DB OBJECT(S)

backup, recovery