Oracle 9i遭遇ORA-00600 OSDEP_INTERNAL
本站文章除注明转载外,均为本站原创: 转载自love wife love life —Roger的Oracle/MySQL/PostgreSQL数据恢复博客
前几天同事反馈说某客户的一套数据库出现异常,负载极高,服务器几乎无法操作,只能强行关闭服务器电源来重启数据库;悲剧的是重启服务器之后,数据库无法启动了。
首先我们来看看启动数据库报什么错误:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 |
Mon Apr 24 16:28:11 2017 This instance was first to mount LCK0 started with pid=18, OS id=667902 Mon Apr 24 16:28:15 2017 Successful mount of redo thread 1, with mount id 2877742299 Mon Apr 24 16:28:15 2017 Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE). Completed: ALTER DATABASE MOUNT Mon Apr 24 16:31:14 2017 Errors in file /oracle/app/oracle/admin/jchs07/bdump/jchs07a_smon_516226.trc: ORA-00601: cleanup lock conflict Mon Apr 24 16:31:19 2017 SMON: terminating instance due to error 601 Instance terminated by SMON, pid = 516226 Mon Apr 24 16:31:19 2017 Errors in file /oracle/app/oracle/admin/jchs07/bdump/jchs07a_smon_516226.trc: ORA-00600: internal error code, arguments: [OSDEP_INTERNAL], [], [], [], [], [], [], [] ORA-27302: failure occurred at: skgpwreset1 ORA-27303: additional information: invalid shared ctx ORA-00601: cleanup lock conflict Mon Apr 24 16:31:19 2017 Errors in file /oracle/app/oracle/admin/jchs07/bdump/jchs07a_smon_516226.trc: ORA-07445: exception encountered: core dump [] [] [] [] [] [] ORA-00600: internal error code, arguments: [OSDEP_INTERNAL], [], [], [], [], [], [], [] ORA-27302: failure occurred at: skgpwreset1 ORA-27303: additional information: invalid shared ctx ORA-00601: cleanup lock conflict |
从上述的错误来看,mount之后,open数据库时报错ORA-00601,而且这是SMON进程抛出的错误;可见这是smon进程在进行事务恢复时抛出的错误,最后的结果就是smon强行终止了实例。这就是为什么同事反馈,只要执行alter database open命令,sqlplus 窗口就报错ORA-03113. 如下是对于trace文件的call stack信息:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 |
ORA-00600: internal error code, arguments: [OSDEP_INTERNAL], [], [], [], [], [], [], [] ORA-27302: failure occurred at: skgpwreset1 ORA-27303: additional information: invalid shared ctx ORA-00601: cleanup lock conflict ----- Call Stack Trace ----- calling call entry argument values in hex location type point (? means dubious value) -------------------- -------- -------------------- ---------------------------- ksedmp+0148 bl ksedst 1029762F4 ? ksfdmp+0018 bl 01FD5C3C kgerinv+00e8 bl _ptrgl kgerin+003c bl kgerinv BADC0FFEE0DDF00D ? BADC0FFEE0DDF00D ? BADC0FFEE0DDF00D ? BADC0FFEE0DDF00D ? FFFFFFFFFFFE830 ? kgerecoserr+0144 bl kgerin 110005BA8 ? 110396408 ? 1029745C4 ? 000000000 ? 102974480 ? 000000000 ? 000000000 ? 000000000 ? ksugprst+0068 bl kgerecoserr 000000000 ? 102978294 ? FFFFFFFFFFFDA48 ? ksuitm+0790 bl ksugprst ksbrdp+0580 bl ksuitm 000000000 ? 25900000259 ? opirip+02a8 bl ksbrdp opidrv+0300 bl opirip 9001000A0269318 ? 0101FA7E0 ? 000000000 ? sou2o+0028 bl opidrv 32E0DDF00D ? 0A0059810 ? 000000000 ? main+01a4 bl 01FD5650 __start+0090 bl main 000000000 ? 000000000 ? |
我们继续看后面的几个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发现又报其他的错误:
1 2 3 4 5 6 7 8 9 |
SQL> recover database; ORA-00283: recovery session canceled due to errors ORA-10562: Error occurred while applying redo to data block (file# 1, block# 164301) ORA-10564: tablespace SYSTEM ORA-01110: data file 1: '/dev/rlv07_2g_sys' ORA-10561: block type 'TRANSACTION MANAGED INDEX BLOCK', data object# 3 ORA-00607: Internal error occurred while making a change to a data block ORA-00600: internal error code, arguments: [kcoapl_blkchk], [1], [164301], [6401], [], [], [], [] |
这个错误还是比较少见的。最后的这个ORA-00600 [kcoapl_blkchk] 我也是第一次遇到,不过结合前后日志来看,很明显这是数据库在通过redo进行数据块应用时出现了异常,而有异常的数据块则是file 1 block 164301;也就是我们的system 文件。
其次我们也可以看出,该数据块所涉及的对象是data object# 3,也就是我们常说的bootstrap 核心对象,但是这是一个Index。
如果我们再看的仔细一点,可以发现这个块的问题是出在了事务层,因为有ora-10561错误产生。
既然如此,那么我们首先来dbv 检查一下数据库的system文件,看看是否有物理损坏:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 |
jchsdb1:/oracle>dbv file=/dev/rlv07_2g_sys blocksize=8192 DBVERIFY: Release 9.2.0.8.0 - Production on Mon Apr 24 18:13:21 2017 Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved. DBVERIFY - Verification starting : FILE = /dev/rlv07_2g_sys DBVERIFY - Verification complete Total Pages Examined : 261120 Total Pages Processed (Data) : 90663 Total Pages Failing (Data) : 0 Total Pages Processed (Index): 58458 Total Pages Failing (Index): 0 Total Pages Processed (Other): 2011 Total Pages Processed (Seg) : 0 Total Pages Failing (Seg) : 0 Total Pages Empty : 109988 Total Pages Marked Corrupt : 0 Total Pages Influx : 0 Highest block SCN : 14868719377535 (3461.3837566079) |
通过dbv的结果来看,system 文件本身是没有物理损坏的。如果不是物理损坏,那么结合前面的错误信息来看,我们可以判断这个文件的这个块应该是逻辑损坏。这里我们应该可以通过rman 进一步进行检查确认。
为了尽快启动数据库,这里我们先通过如下的方式来尝试进行恢复:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 |
jchsdb1:/oracle>sqlplus "/as sysdba" SQL*Plus: Release 9.2.0.8.0 - Production on Mon Apr 24 19:22:19 2017 Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved. Connected to an idle instance. SQL> startup mount ORACLE instance started. Total System Global Area 2568456648 bytes Fixed Size 743880 bytes Variable Size 1493172224 bytes Database Buffers 1073741824 bytes Redo Buffers 798720 bytes Database mounted. SQL> RECOVER DATABASE ALLOW 1 CORRUPTION; Media recovery complete. SQL> show parameter job NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ job_queue_processes integer 10 SQL> alter system set job_queue_processes=0; System altered. SQL> alter database open; Database altered. |
很顺利的打开了数据库,这也说明目前数据库的问题并不是很严重,只是有问题的数据块并不多,否则上述的命令是不会起到什么作用的。
这里我简单补充一点,对于allow n corruption的操作,在Oracle 9i 和10g 版本中,仅仅支持1个corrupt block;而在11gR2版本开始,则可以支持多个,最多可达10个 corrupt block。
打开数据库之后,我检查了数据库alert log发现,有一些其他的错误,如下所示:
1 2 3 4 5 6 7 8 |
ORA-00600: internal error code, arguments: [25012], [0], [852], [], [], [], [], [] Current SQL statement for this session: INSERT INTO LOG_DB_SIZE_CHANGE SELECT SYSDATE,ROUND(SUM(BYTES)/1024/1024/1024,2) FROM DBA_SEGMENTS GROUP BY SYSDATE ----- PL/SQL Call Stack ----- object line object handle number name 700000064ab51c0 3 procedure SYSTEM.LOG_TOTAL_DB_SIZE_PRO 700000064ac73a8 1 anonymous block |
单纯的看到上述错误,我开始以为是不是因为我们前面执行了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这种老库,尤其是非归档的情况,不建议强制重启,可能出现一些异常。
Leave a Reply
You must be logged in to post a comment.