ORA-00600 kclchkblk_4 错误恢复案例一则

最近客户在恢复数据库时遇到了ORA-600 kclchkblk_4错误,这个错误在MOS上有官方的解释和解决方案。

在以下错误提示下:

Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_smon_7493.trc:
ORA-600: internal error code, arguments: [kclchkblk_4], [1904],[18446744073431179384], [1904],18446744073403569507], [], [], []

Starting background process QMNC
QMNC started with pid=24, OS id=8329

Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_smon_7493.trc:
ORA-600: internal error code, arguments: [2662], [1904], [3988985522],[1904], [4016595064], [8388610], [], []

Errors in file /u01/app/oracle/admin/orcl/bdump/orcl_smon_7493.trc:
ORA-600: internal error code, arguments: [2662], [1904], [3988985525],[1904], [4016595064], [8388610], [], []
SMON: terminating instance due to error 474
Instance terminated by SMON, pid = 7493

其问题,可能是由于临时表空间的SCN问题导致的,可以尝试删除所有的临时文件,启动数据库,通常可能正常启动。
可能的采取步骤是,在Mount状态下确定并删除临时文件:

    SQL>select file_name, file_id from dba_temp_files;
SQL>alter database tempfile_name drop;
SQL>alter tablespace add tempfile size N;

如果数据库能够成功启动,可以重建临时文件。

顺便引用一下ITPUB上一个朋友的帖子供参考: http://www.itpub.net/thread-1404451-1-1.html

问题描述:
服务器突然故障死机,导致数据库无法驱动,redo的CURRENT组的损坏。oracle 10g rac环境,asm磁盘组,redhat linux系统。每个组一个成员这个是组被破坏无法修复的关键。
没有归档,没有备份。使用ASM无法将数据文件冷备份出来。

ORA-00368: checksum error in redo log block
ORA-00353: log corruption near block 254606 change 12131176305969 time 03/08/2011 01:03:00
ORA-00312: online log 2 thread 1: ‘+DG1/police/onlinelog/group_2.258.657430669’

查看日志组文件信息,报错的日志组为CURRENT模式。

SQL> select group#,sequence#,archived,status from v$log;

GROUP#  SEQUENCE# ARC STATUS
———- ———- — —————-
1      17495 NO  INACTIVE
2      17496 NO  CURRENT
3      17365 NO  INACTIVE
4      17366 NO  CURRENT

组成员只有一个。

SQL>

Group   Instance             Member             STATUS             Size(MB)
———- ———- —————————— —————- ———-
1          1 +DG1/police/onlinelog/group_1. INACTIVE                500
257.657430665

2          1 +DG1/police/onlinelog/group_2. CURRENT                 500
258.657430669

3          2 +DG1/police/onlinelog/group_3. INACTIVE                500
265.657431819

4          2 +DG1/police/onlinelog/group_4. CURRENT                 500
266.657431825

无法使用clear命令清楚redo的信息

SQL> alter database clear unarchived logfile group 2
2  ;
alter database clear unarchived logfile group 2
*
ERROR at line 1:
ORA-01624: log 2 needed for crash recovery of instance police1 (thread 1)
ORA-00312: online log 2 thread 1: ‘+DG1/police/onlinelog/group_2.258.657430669’

SQL> alter database clear logfile group 2;
alter database clear logfile group 2
*
ERROR at line 1:
ORA-01624: log 2 needed for crash recovery of instance police1 (thread 1)
ORA-00312: online log 2 thread 1: ‘+DG1/police/onlinelog/group_2.258.657430669’

处理步骤

把数据库down掉

   SQL>shutdown immediate

5、在init<sid>.ora中加入如下参数

_allow_resetlogs_corruption=TRUE

6、重新启动数据库,利用until cancel恢复

SQL>recover database until cancel;
Cancel

如果出错,不再理会,发出

SQL>alter database open resetlogs;

如果运气好的话可以正常启动数据库,就可以导出数据了。但是这里有点意外不知道是点背还是rac环境的恢复比较特殊。在alert.log中有如下报错:

Errors in file /u01/app/oracle/admin/police/bdump/police2_j003_17720.trc:
ORA-00600: internal error code, arguments: [4194], [9], [8], [], [], [], [], []
Wed Mar  9 18:08:06 2011
Errors in file /u01/app/oracle/admin/police/bdump/police2_j004_17722.trc:
ORA-00600: internal error code, arguments: [4193], [55749], [55753], [], [], [], [], []
Wed Mar  9 18:08:08 2011
Errors in file /u01/app/oracle/admin/police/bdump/police2_mmon_11328.trc:
ORA-00600: internal error code, arguments: [4194], [12], [17], [], [], [], [], []
Wed Mar  9 18:08:08 2011
Errors in file /u01/app/oracle/admin/police/bdump/police2_j002_17718.trc:
ORA-00600: internal error code, arguments: [kcbz_check_objd_typ_3], [0], [0], [1], [], [], [], []

能后我就重复启动数据库这个错误就过去了,网上有一篇文档是这么说的,真的可以过去,不过我是将两个节点都同时启动的时候过去的,但是在开始出现如下错误:
ORA-600[KCLCHKBLK_4]【2824】,但是没有出现ORA-600[2662]的报错,不知道为什么,有人说是temp文件不一致造成,但是别人都有2662的报错我这里没有,不管了先将temp删了在说。

能后速度将temp删除,能后发现问题依旧。当时我就很失望了,情绪低落。这个报错在网上的解决办法只有这一个。也没有什么人有更好的建议。
ORA-00600: internal error code, arguments: [kclchkblk_4], [2824], [18446744071603238605], [2824], [18446744071593491338], [], [], []
Wed Mar  9 14:29:55 2011
Errors in file /u01/app/oracle/admin/police/udump/police1_ora_27660.trc:
ORA-00600: internal error code, arguments: [kclchkblk_4], [2824], [18446744071603238605], [2824], [18446744071593491338], [], [], []
Wed Mar  9 14:29:55 2011
Error 600 happened during db open, shutting down database
USER: terminating instance due to error 600

但是仔细观察后我发现18446744071593491338这个数据有问题,它在我每次重新启动数据库的时候会和前面的数值有所改变18446744071593491338,我的目标就是将
这个数值尽量的缩小和18446744071603238605的值,重复几遍后发现使用srvctl start database -d sid数据库会自动重启多次,我就不停地启动关闭。有希望了两个者还是相差太大,
这一步我们在这里卡了很久。这里有一个scn的问题,我这里碰到的是后面的比前面的低,所以adjust_scn没有效果。
无赖我将_allow_resetlogs_corruption=TRUE增加到spfile中让数据库同时启动。结果发现错误改变了,后来想想估计是要将参数添加到spfile中同时启动数据库才有效果,因为我单独启动数据库的时候效果不大。

Errors in file /u01/app/oracle/admin/police/bdump/police2_smon_11322.trc:
ORA-00600: internal error code, arguments: [4137], [], [], [], [], [], [], []
Wed Mar  9 18:08:35 2011
ORACLE Instance police2 (pid = 16) – Error 600 encountered while recovering transaction (9, 46).
Wed Mar  9 18:08:35 2011
Errors in file /u01/app/oracle/admin/police/bdump/police2_smon_11322.trc:
ORA-00600: internal error code, arguments: [4137], [], [], [], [], [], [], []
Wed Mar  9 18:08:35 2011
Trace dumping is performing id=[cdmp_20110309180835]
Wed Mar  9 18:08:37 2011
Errors in file /u01/app/oracle/admin/police/bdump/police2_smon_11322.trc:
ORA-00600: internal error code, arguments: [4137], [], [], [], [], [], [], []
Errors in file /u01/app/oracle/admin/police/bdump/police2_p007_19333.trc:
ORA-00600: internal error code, arguments: [4198], [9], [], [], [], [], [], []

出现了这些报错,现在好了,4137,4138 ,4139不都是undo的报错吧,
新建立两个undo,修改spfile使用新的undo启动,删除旧的undo。
添加spfile参数

_allow_resetlogs_corruption”=true ”
_allow_terminal_recovery_corruption”=true
_corrupted_rollback_segments =’_SYSSMU1$’,’_SYSSMU2$’,’_SYSSMU3$’

如果不能确定多少个,但是我在删除UNDO的时候提示_SYSSMU2无法删除,我还是坚持加到了20个,后来我查了一下一共有400多个还好没有每个都坏掉。
修改undo_management 这个参数
把参数文件中的undo_management 改为MANUAL

SQL> create undo tablespace undotbs3 datafile ‘/opt/oracle/oradata/conner/undotbs3.dbf’ size 10M;
Tablespace created.
SQL> alter system set undo_tablespace=undotbs1 scope=spfile sid=’sid’;
System altered.
SQL> drop tablespace undotbs2;
Tablespace dropped.

将两个节点的undo都替换后发现数据库可以起来了,但还是有报错,

Errors in file /u01/app/oracle/admin/police/bdump/police2_j000_7977.trc:
ORA-00600: internal error code, arguments: [kcbz_check_objd_typ_3], [0], [0], [1], [], [], [], []
Wed Mar  9 23:56:10 2011

但还好可以exp数据了。

导出数据后,删除数据库,删除asm,
关闭第二台的asm实例,
登入第一台asm

SQL> select name from v$asm_diskgroup;
NAME
——————————
DG1
SQL> drop diskgroup DG1 including contents;       –>删除磁盘组
SQL>SHUTDOWN IMMEDIATE

最后
crs_unregister ora.node1.ASM1.asm
crs_unregister ora.node1.ASM1.asm(后来极度后悔,应该在unregister前备份一下就好了)
在dbs和admin下删除asm相关文档
修改/etc/oratab文件将asm的注释。
dbca重新建立asm磁盘发现asm实例无法启动晕倒。好像是出现prks-1011,和ora-0210的报错
使用srvctl add asm -n node1 -i +ASM1 -o $ORACLE_HOME -p init+ASM1.ora
提示ora.node1.ASM1.asm服务已经存在了,但是crs_stat -t查看又没有ora.node1.ASM1.asm服务。
于是我使用crs_register ora.node1.ASM1.asm的时候提示找不到 ora.node1.ASM1.asm.cap的文件(这里折腾了一段时间)
没法我从别的rac上使用crs_stat -p ora.node1.ASM1.asm > ora.node1.ASM1.asm.cap导出了一份拷贝到提示的目录下,并且修改了文件中的主机信息等。
在使用crs_register ora.node1.ASM1.asm就注册成功了。其实 ora.node1.ASM1.asm.cap这个文件的东西和 ora.node1.lsnr的文件内容一样。就是有些东西自己动手修改一下就可以替代了。
重新建库导入文件
艰苦的数据恢复终于完成了。

某客户的一套5TB Oracle RAC 数据库恢复案例

某客户的核心数据库存储问题导致数据库重启后无法正常启动,根据客户反馈最开始在启动数据库时
报错控制文件IO错误,如下:

上述的问题本质上都跟控制文件有关系,替换掉损坏的控制文件就行。当替换掉控制文件之后,在open数据库时发现报如下错误:

该错误本质上是因为redo的问题,即有redo log损坏。通过在RMAN进行recover,发现报如下类似错误:

上述过程大致是客户之前的处理过程。我在18点左右介入之后,进行了相关的操作。我最开始尝试在利用RMAN 进行恢复,发现报错:

从上面的错误来看,初步可以判断redo04a.log文件已经损坏,而且是block 1788672的问题。为了验证该block是否损坏,我通过类似如下的dump 命令进行dump,发现报错:

由此判断,该block损坏无疑。 由于客户的需求是尽可能快的将数据库拉起来,因此对应redo损坏的情况之下。
通常只能进程不完全恢复并强制打开,这里我使用了如下的参数:

在open resetlogs之前,我已经将redo备份,resetlogs打开时,发现数据库报错如下:

从日志来看,大致判断可能是_SYSSMU25$ 回滚段的问题,因此尝试先通过如下隐含参数屏蔽回滚段:

屏蔽回滚段之后,尝试打开数据库,发现错误依旧,通过10046 trace跟踪,发现递归SQL在如下的block上执行失败:

通过dump file 1 block 91,发现该block上第2个ITL确认存在一个活跃事务。原本计划直接bbed提交该事务,但是当我编译好bbed之后,查看发现该block为一个cluster block.

对于cluster block的事务修改,相对复杂一些,我的博客有文章描述,大家可以参考,这里不多说。考虑到生产库使用bbed有一定的风险,我并没有使用bbed。

接着使用undo_management参数启动数据库,然后强制open数据库,发现错误变成如下:

从错误来看,我们就可以知道,这应该是SCN的问题。如果要手工推进SCN,那么level应该待遇3297*4才行,由于这里的238091117/1024/1024/1024小于1,因此推进scn时,level=3297*4+2 就差不多了。 这里我再次进行了10046 trace,发现了如下信息:

bscn: 0xce1.e379b05 将该scn进行转换,我们可以发现:0xce1 为3297,e379b05为238525189. 与上述报错信息一致。同时我发现这里使用了第2号回滚段,如下:

因此,尝试继续使用隐含参数屏蔽这第2号回滚段,并尝试打开数据库,但是错误依旧。看来还是需要调整SCN才行,如下:

首先我尝试了在会话级别设置:

发现alter database open失败,尝试使用*._minimum_giga_scn参数,但是在启动的时候,提示说该参数不支持。从此判断,该环境可能是安装了比较新的PSU,Oracle将该参数废弃掉了,这么说前面的10015 event根本就没起作用。 无奈只能通过oradebug手工修改SCN来启动数据库了,如下:

修改SCN之后,顺利打开了数据库,但是数据库很快就crash掉,如下是日志信息:

从上述日志信息来看,主要出现了如下几个错误:

ORA-00600 [6006],ORA-00600 [4137],ORA-00600 [kdsgrp1]

对于前面2个错误,很明显是Oracle SMON进程在进行利用回滚段进行事务rollback时失败导致,如下:
ORACLE Instance xxxx2 (pid = 22) – Error 600 encountered while recovering transaction (44, 26) on object 47098.
ORACLE Instance xxxx2 (pid = 22) – Error 600 encountered while recovering transaction (48, 25).

因此,不难看出,数据库中还有部分的回滚段存在活跃事务。

对于ORA-00600 [kdsgrp1]错误,通常是出现在Index上,即Index数据和表的数据不一致,一般来说可以通过重建解决。

其次,对于后面的ORA-08102: index key not found, obj# 239, file 1, block 1674 (2) 错误,主要是job调用出现,因此
我们可以暂时屏蔽job的调度。

对于ORA-08102错误,我的博客几年前也写过相关的文章,本质上也是Index block中的相关键值不存在导致。

与其如此,最后我感觉将数据库的所有回滚段都屏蔽掉,并重建数据库undo 表空间,如下是获取回滚段的命令:

strings system01.dbf | grep _SYSSMU | cut -d $ -f 1 | sort -u

经过整理,发现该库存在大约2600个回滚段,我了个去,先不管这么多,重启实例后,重建undo表空间:

最后重启数据库实例,让客户将关键核心的配置表导出,先进行业务恢复,如果需要数据,直接从库中抽取。
这里要补充一点,该库约为5TB多一点,虽然有备份,但是恢复时间太长,如果有个dataguard是多么的重要啊!

某客户RAC由于掉电导致系统崩溃的恢复案例

这里简单记录一下,此次国庆加班恢复的某客户的2套Oracle RAC数据库,整个恢复过程中,2套rac差不多,因此这里以其中一套数据库的恢复过程为例进行简单分析说明。数据库由于为非归档,由于掉电导致重启之后系统无法正常open。

在正常open的过程中,报错如下错误:

对于该错误,网上的解决方法也很多,可惜都不管用。这种情况之下,往往都是需要强制打开数据库的,首先需要做一个不完全恢复,如下:

在进行相关操作之后,我备份了一下当前的控制文件信息,便于后面如果有问题,方便处理。强制open的过程中,发现报如下错误:

这个错误已经处理过多次了。同样,百度一下,会发现很多人都写过相关的文章,包括Oracle mos的文章解释也是说这是临时块的scn过大导致,通过drop  tempfile即可绕过该问题。实际上,这种情况之下,根本不会起作用。

但是不管如何,这个问题很明显都是跟block的scn有关系。既然是跟scn有关系,那么处理就不难了,通过推进scn即可。

通过推进scn 之后,再次open resetlogs成功打开数据库,可惜的是alert log报了一堆错误,如下所示:

这部分错误处理其实都不难。对于第一个ora-00600 [4137] 错误,很明显这是跟undo有关系的,其中(23,85)中的23表现第23号回滚段;通过屏蔽第23号回滚段可以很容易解决该错误,当然,这会儿导致事务的不一致性,这是没办法的,已经undo异常,Oracle 已经没有办法进行正常的事务恢复了。

其次,对于第2个ora-00600  [qertbFetchByRowID] 错误,处理也很简单,其大致意思是通过rowid访问获取数据有异常,很明显这是跟index有关系,通过重建index 可以解决该问题,其次最后一个[kdsgrp1] 错误就更常见了,通常也是Index的问题,重建即可。

看上去一切的恢复过程都很简单,很顺利,然而这里真正的难题,真正的问题才开始。
也就是最后一个看似很简单的错误ora-00600 [kdsgrp1]错误,对我们产生了极大的困难。首先我们来看下产生该错误时涉及到那些对象:

我们可以发现,除开其他的非核心对象之后,这里还涉及到一个obj#=18,也就是obj$ 这个核心的数据字典表。而该数据字典表上的几个Index,
i_obj1,i_obj2,i_obj3 都是object_id 小于57的核心对象,这部分对象是属于bootstrap$ 的核心数据字典对象。即是Index也无法通过
rebuild,38003 event或在upgrade模式下进行重建。
当然,这里也不是说完全无法去重建上述数据字典表,我后面有一篇文章会相信讲解如何去重建。
在分析过程中,我发现其中的前面2个Index都有问题,如下:

不过这里我们也要注意的时,虽然前面2个index都有问题,然而上述错误产生时涉及到的index并不是2个都用到了,其实只是用到了第一个index就
报错ora-00600错误了。由于客户想通过expdp schema的方式去导出数据,然而发现执行时报错ora-00600 [kdsgrp1],包括exp执行时也报该
错误,不过exp tables的方式,不会报错;由于对象太多,将近50万个对象(包括表,index以及其他)。很明显,只能通过用户级别的导出。
那么也就在意味着我们必须修复这个错误才。
通过dump 相关的block,我们发现错误是很奇怪的,如下:

对于上述这个index 的错误,我是第一次遇见,跟老熊讨论了一下,他认为可能是index split情况之下出现的。在远程时,我也用过bbed对前后将近10个index block进行了分析,通过比较index 的链表,发现确实不匹配。
对于这种情况之下,想通过bbed去修复 index,难度可想而知,因此果断放弃这种方式。最后无奈之下,只能通过处理数据字典表
的方式来处理掉i_obj1,i_obj2 这2个index。最后再让客户进行exp 用户级别的导出,只不过这个导出的时间比较漫长了。

 

一个55TB的Oracle RAC (ASM)恢复案例

前几天某客户的一个数据库出现故障,需要我们紧急救援支持。了解了一下环境,着实也吓了一跳,数据量55TB左右。首先我们来看看故障的信息:

从前面的日志可以看出,该数据库节点从25号22:57开始报错,开始可能是出现了部分session hung的情况,接着出现了写失败的操作。而其中写失败的是第35个磁盘。

当然,这里仅仅是一个warning,因此我们还不能判断是磁盘是否有问题。

后面我们跟客户了解,当时的现象应该是存储链路出现了异常,导致数据库IO出现异常。这也符合之前的现象描述。

那么我们进一步分析后面客户的操作,看看之前他们都进行了哪些相关的操作?

我们可以看到,客户进行了正常的alter database open,但是Oracle提示有部分文件需要recover。那么进行recover database操作呢,则提示有部分文件可能来自fuzzy backup.

这是什么意思呢? 这其实是说这几个文件的检查点比较旧,需要很早之前的日志来进行recover。

由于这是一个非归档的数据库,因此很可能有问题的这几个文件需要日志已经被覆盖。

通过比较scn,我们可以判断这几个文件需要的redo信息已经被覆盖了。这里我要提醒大家的是,不要仅仅只看alert log就轻易下判断。

仅仅看alert log我们可能认为只有几个文件问题。后续我想,如果是仅仅有几个文件有问题,那么我跳过这部分文件进行recover 不就行了吗? 因为这样可以实现数据的最大程度恢复。

于是我执行了下面的命令:

上面这个命令,其实是比较致命的,因为Oracle 会将这里skip的表空间里面的文件全部进行offline drop。

所以这里其实上述的做法是有些欠妥的。

我进一步根据文件的scn和v$log的scn 信息进行比较,发现其实有605个文件可能都需要进行recover;因为全库已经有2000个左右的数据文件。

这里我根据scn进行大致判断然后产生2个脚本进行文件级别的recover,大致获取脚本如下:

通过将其他能够进行正常recover的文件进行恢复之后,尝试打开数据库。居然能够正常open数据库。有些人可能已经到此结束了吧,其实并不然。

大家想一下?虽然数据库打开了,我们不能正常recover的605个数据文件中可能还有部分数据文件状态是recover,也就是还不是online的状态。

这种情况之下,业务是无法访问的。实际上我这里查了一下,大概有540个文件状态仍然是recover。因此我们现在还需要想办法怎么去讲这部分文件online。

处理方法其实并不难,比如通过bbed简单修改下数据文件头的checkpoint信息,就可以完成了。但是有540个文件,而且都是ASM环境。

这个修改的工作量可想而已。后面再产生一个脚本,将数据库启动到mount状态,然后将之前状态为recover的文件全部online。

然后进行recover database using backup controlfile操作。接着直接进行alter database open resetlogs。

遗憾的是没有能够直接打开数据库,报了一个如下的错误,该错误很常见,mos有问题也提到,可能跟temp有关系。

 

 

 

 

这里我这里直接将tempfile 进行drop,然后再重建控制文件,进行recover后,居然直接打开数据库了。

检查alert log,我发现还存在一个如下的错误:

很明显,上述错误是指smon进程在进行事务恢复时,发现有2个事务无法进行恢复。

看到上述的错误,或许有人会说可能是undo出现损坏,导致无法进行事务恢复。实际上这里并不是,我通过dbv检查发现undo文件都是完好的。

无论怎讲,这里要解决这个问题,相对简单,定位到是什么对象,重建就好。