本站文章除注明转载外，均为本站原创： 转载自love wife & love life —Roger 的Oracle技术博客
前几天同事反馈说某客户的一套数据库出现异常，负载极高，服务器几乎无法操作，只能强行关闭服务器电源来重启数据库；悲剧的是重启服务器之后，数据库无法启动了。
首先我们来看看启动数据库报什么错误：
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信息：
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发现又报其他的错误：
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文件，看看是否有物理损坏：
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 进一步进行检查确认。
为了尽快启动数据库，这里我们先通过如下的方式来尝试进行恢复：
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发现，有一些其他的错误，如下所示：
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这种老库，尤其是非归档的情况，不建议强制重启，可能出现一些异常。
Related posts: