Oracle 9i遭遇ORA-00600 [OSDEP_INTERNAL]的恢复案例

前几天同事反馈说某客户的一套数据库出现异常,负载极高,服务器几乎无法操作,只能强行关闭服务器电源来重启数据库;悲剧的是重启服务器之后,数据库无法启动了。

首先我们来看看启动数据库报什么错误:

从上述的错误来看,mount之后,open数据库时报错ORA-00601,而且这是SMON进程抛出的错误;可见这是smon进程在进行事务恢复时抛出的错误,最后的结果就是smon强行终止了实例。这就是为什么同事反馈,只要执行alter database open命令,sqlplus 窗口就报错ORA-03113. 如下是对于trace文件的call stack信息:

我们继续看后面的几个ORA-错误,我们都知道,对于这种一连串的错误,需要从下往上看,即ORA-00601错误是关键,是起因,然后再导致了ORA-27303,ORA-27302 等等错误。

从错误的基本解释来看,基本上判断是存在锁冲突,数据库都没有open,怎么会有锁呢?所以我们不难看出,这应该是操作系统数据库实例的内存没有清理干净。

果然,我ipcs -a查看看到有几个之前启动过的实例还分配着内存呢,同时也还有一些ora-进程存在。通过ps -ef|grep ora|grep -v grep|awk ‘{print $2}’|xargs kill-9 杀掉进程之后,再ipcrm -m 清除即可。

接着尝试启动数据库,手工进行recover database发现又报其他的错误:

这个错误还是比较少见的。最后的这个ORA-00600 [kcoapl_blkchk] 我也是第一次遇到,不过结合前后日志来看,很明显这是数据库在通过redo进行数据块应用时出现了异常,而有异常的数据块则是file 1 block 164301;也就是我们的system 文件。

其次我们也可以看出,该数据块所涉及的对象是data object# 3,也就是我们常说的bootstrap 核心对象,但是这是一个Index。

如果我们再看的仔细一点,可以发现这个块的问题是出在了事务层,因为有ora-10561错误产生。

既然如此,那么我们首先来dbv 检查一下数据库的system文件,看看是否有物理损坏:

通过dbv的结果来看,system 文件本身是没有物理损坏的。如果不是物理损坏,那么结合前面的错误信息来看,我们可以判断这个文件的这个块应该是逻辑损坏。这里我们应该可以通过rman 进一步进行检查确认。

为了尽快启动数据库,这里我们先通过如下的方式来尝试进行恢复:

很顺利的打开了数据库,这也说明目前数据库的问题并不是很严重,只是有问题的数据块并不多,否则上述的命令是不会起到什么作用的。

这里我简单补充一点,对于allow  n corruption的操作,在Oracle 9i 和10g 版本中,仅仅支持1个corrupt block;而在11gR2版本开始,则可以支持多个,最多可达10个 corrupt block。

打开数据库之后,我检查了数据库alert log发现,有一些其他的错误,如下所示:

单纯的看到上述错误,我开始以为是不是因为我们前面执行了allow 1 corruption的恢复,所以导致sql执行报错。

针对该错误,我查询了一下Oracle metalink,其中的文档ORA-600 [25012] “Relative to Absolute File Number Conversion Error” (文档 ID 100073.1) 提到该错误则表示可能是存在物理损坏。其中[0] 表现表空间编号,[852]表示相对文件号。

但是根据实际的情况来看,这似乎不对,因为这个数据库目前仅有200多个数据文件,不太可能出现文件号大于800的情况。其次dbv 检查system文件确实是没有物理损坏。

这里我们姑且不管mos文档是不是对的,就只看这个错误来看,是调用的监控脚本运行出错,监控脚本的本意是通过查询数据库dba_segments试图来获取数据库的大小。

那么我们进一步看看dba_segments的访问是否会涉及到我们前面提到的data object# 3呢? 通过vi trace文件,搜索Plan_table关键字即可看到报错SQL语句的执行计划,我发现并没有涉及到data object# 3的对象。

由此可见,这个数据库除了我们前面提到的data object# 3,还有其他的对象可能也存在逻辑不一致的错误;因此建议进行全库级别的一致性检查,如有必要,建议重建一下数据库。

对于这个问题产生的根本原因,我一直在思考,到底是什么原因呢?最开始我怀疑可能有如下几种可能性原因:

1、强制重启主机,导致主机cache 丢失,最终导致Oracle redo或datafile 存在write lost;

2、数据库的system文件之前就存在不一致的情况

3、Oracle bug

由于客户这套Oracle 9208数据库使用的是裸设备,因此Oracle 对于文件的读写按理说是不会应该操作系统cache的,因此不存在第一种情况的说法。所以我认为要么是数据库之前可能就有一定问题要么就是命中了Oracle的某个bug(具体是什么bug,没有去深入排查)。

这里我也提醒一下,对于Oracle 9i这种老库,尤其是非归档的情况,不建议强制重启,可能出现一些异常。

 

DataBase can’t be open after shutdown immediate

五一放假期间,某客户的数据库出现故障,据说对方找了一些工程师折腾了一天,都无法将数据库open,其中参考了网络上的很多文章,也使用了一系列隐含参数,均无法将数据库打开。这里我简单的与大家分享一下这个case。

首先我介绍一下整个case的背景,客户在4月30号凌晨通过shutdown immediate停库维护后,启动数据库无法报错,此时发现数据库无法open,期间尝试了各种数据库手段,均失败告终。我们先来看看相关日志,如下是数据库停库的日志:

我们可以看出,这个数据库确实是以shutdown immediate的方式停止的。客户第一次尝试启动时,发现报错ORA-00600 [2663],如下:

这是一个非常常见的错误,这个错误通常是是更数据块有关系。我们知道,根据经验,一般来讲,如果current scn (这里是scn base)与dependent scn(scn base)非常接近(且scn wrap都一致或者为0)的情况下,说明scn的差异非常小,通过多次重启数据库的手段,基本上可以绕过这个错误。果然,通过看客户提供的alert log发现多次重启后,alert log的报错日志变了ORA-00600 [4194]错误,如下:

这是一个看似非常简单的错误,大致意思是说Oracle 在进行事务恢复时发现redo和undo的信息有所出入,因此抛出这个错误。这里我仍然贴出Oracle MOS的标准解释供大家参考:Basic Steps to be Followed While Solving ORA-00600 [4194]/[4193] Errors Without Using Unsupported parameter (文档 ID 281429.1)

上述文档中提到,这个错误其实就是指恢复时发现undo block对应的record 编号与redo block 对应的undo record 编号不一致。通常情况下来讲,都是由于回滚段损坏导致的问题。 这里我们先不去进行alert log的详细分析展开了,以自己的实际操作过程来进行展开分析说明。如下是我的简单恢复过程。

首先我尝试进行正常恢复,并打开数据库:

我们可以看到操作报错,并没有打开数据库。此时查看数据库alert 告警日志,发现正是前面提到的ORA-00600 [4194]错误:

这个ora-00600 错误与前面提到的完全一致。根据我们常规处理这个错误的套路,基本上就是使用undo_management=’manual’ 来尝试绕过,经过测试发现不好使。进一步查看对应的trace 文件,发现oracle提示说某个块存在异常:

上述的错误其实也很容易解释,简单的讲就是redo应用时出现了异常,而且oracle 明确提升file 1 block 131 这个undo block有问题. 上述的内容是redo block的dump;那么我们来看看对应的undo block 中的前镜像是什么:

我们可以看到完全不匹配,同时我们通过脚本将上述内容进行转换,可以发现是其实是回滚段名称:

其次结合我们前面解释ora-00600  [4194]错误来看,这里undo block 对应的record number是0x20,而redo block中记录的record number是0x2. 这确实是不匹配的。

那么怎么解决这个问题呢? 能不能通过屏蔽回滚段的方式来解决呢?我尝试在open之前设置10046 trace,来观察了一下得到了如下结果:

可以看到oracle在执行update undo$时报错,其中更新的是_SYSSMU1_3724004606$ 这个回滚段。而且我们也可以看到,wait# 中记录的正好是前面报错的file# 1 block 131. 那么通过_corrupted_rollback_segments=(_SYSSMU1_3724004606$)这种方式是否可以解决这个问题呢?很遗憾,这里我测试也不行。甚至通过bbed 修改undo$的kdbr记录,将_SYSSMU1 的状态修改为offline,也无法绕过这个ora-00600 4194错误。
简直堪称最顽固的ORA-00600 [4194]。我又检查了一下前面的trace文件,发现所针对这个回滚段头的dump记录,可以确认其中并没有什么活动事务。
然后再仔细看我们所遇到的这个ora-00600 [4194]错误,我感觉有点怪异。为什么说怪异呢?如果说根据Oracle mos的解释文档来看,这里是是没有[a],[b] 值的,因为均为0.最后我们想到通过修改system 回滚段头来绕过这个错误,如下是操作过程:

 

注意,这里我们仅仅需要修改ktuxcnfb和ktuxcfbp[1] 即可。其中将ktuxcnfb修改为0,ktuxcfbp[1]中的uba修改为0.
然后再尝试打开数据库,发现顺利打开了数据库,如下:

接着检查了数据库alert log,也没有发现任何的ora-错误。
看到最后,或许大家会觉得很奇怪,为什么会出现这样的故障呢 ? 这里我也跟大家一样困惑。为什么说困惑呢?
因为这库是通过shutdown immediate方式正常停止的。我们都知道,这种方式停库之后,整个Oracle数据库的
文件都是处于一致的状态,重新启动数据库实例后按理说是不需要再进行实例恢复的。
那么为什么这里又出现了这种情况呢?
针对这个问题,我认为有2种可能性:
1、shutdown immediate之后,数据库写入到操作系统cache,还未完全写入到disk上时,此时数据库主机被强行重启;
由于操作系统cache丢失,导致数据库出现了不一致的情况(本文环境是Linux文件系统)。
2、其他程序或软件破坏了Oracle数据库文件的一致性(实际上,经过了解该环境部署了Rose HA软件;而且
客户在操作时,据说并没有停止rose ha软件)。
由于客户操作的时间点是凌晨2点,几乎是0业务场景,因此我认为第一种可能性几乎为0;第2种可能性更大。

Oracle open遭遇ora-01555错误

前几天我们的一位准客户的其中一套较为重要的数据库出现了故障。我们这里先姑且不去分析原因,来将数据库打开提供业务恢复再说。首先我们来看下一线工程师现场发回的报道:

从上述的错误来看。数据库在open时,其中一个递归SQL语句执行失败,该递归SQL执行失败的原因是出现了ora-01555错误,即大家所熟知的快照过旧;同时日志中也明确提到了需要访问的回滚段编号,即第37号回滚段。

根据我们一般的处理思路,需要进行10046 trace跟踪,确认这里的递归SQL是不是访问了一些存在活动事务的Block

 

10046 跟踪来看,报错的SQL 语句访问了2block;分别是file 1 block 337file 157 block 164013. 很明显第一个数据块应该是数据字典的block,而157号文件的这个block应该是undo block,因为这里的obj#=0.

接着我们来看看file 1 block 337 blockdump情况:

 

block dump来看,这是一个Index Block。从ITL的信息来看,这个Index Block没有任何活动事务。同时,根据前面的10046 trace来看,报错的递归SQL访问的obj#=20,换成为16进制为c1 15,然而这个Index block 中并没有这个键值;同时我们dump了下一个index block 找到了对应的键值。

我们可以看出,这个index是一个复合索引,其中col 0的c1 15就是表示20. 该行数据对应的数据块地址是004000f100,转换为10进制是:4194545。

我们回到前面的这个问题,为什么递归SQL访问file block 337 然后接着需要去访问undo block呢? 而且从10046 trace来看fetch r=0,表明并没有获取到数据。说明问题仍然出在这个block的访问上。

这里我们进一步该block的dump来看,发现其scn如下:

当通过dump控制文件的scn来看,明显要小的多,如下:

我们将上述的database checkpoint进行转换:

很明显数据库的checkpoint 明显要比这个Index Block的scn小的多,也就势必导致数据库在启动的时候需要去访问Undo Block。所以这里经过单次的修改undo$  将对应的37号回滚段标记为offline都无法解决这个问题。这里我们首先尝试清除了file 1 block 377的ITL信息之后,启动数据库发现错误发生了改变,如下:

这个错误就非常明白了,就是block scn的问题。而报错的数据块地址为:4194545,这就是我们前面提到的4000f1这个数块,即file 1 block 241 这个数据块。

看起来这个错误本质上来说,可以直接推进scn解决问题。这里我们通过设置*._minimum_giga_scn参数来解决问题。通过设置了该参数之后,成功打开了数据库。

虽然数据库alert log后续还有一些ora-00600 [4097],ora-08102等错误,但是处理都相对简单了。通过重建undo、重建Index即可解决。