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

某些Oracle错误，并不是总是伴随着产生trace文件，这些错误，对Oracle来说并不是严重的错误，比如像ORA-01555这样的错误。

我们可以设置一个事件，在发生错误时，产生一个Trace文件，事件通常使用下面的命令格式：

    alter system set events '<error_number> trace name errorstack level <level>';
    alter session set events '<error_number> trace name errorstack level <level>';

然而，使用alter system命令设置事件后，只会对新连接的会话有效。比如下面的测试：

会话一：
[oracle@xty scripts]$ sqlplus test/test

SQL*Plus: Release 10.2.0.4.0 - Production on Sat Jul 25 23:25:51 2009

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> drop table t1;

Table dropped.

SQL>          
SQL> create table t1 ( a number primary key);

Table created.

SQL> insert into t1 values (1);

1 row created.

SQL> commit;

Commit complete.

会话二：

alter system set events '1 trace name errorstack level 1';

会话一：
SQL> insert into t1 values (1);
insert into t1 values (1)
*
ERROR at line 1:
ORA-00001: unique constraint (TEST.SYS_C005801) violated

此时检查user_dump_dest目录，没有相应的trace文件产生，如果我们再执行下面的动作：

SQL> conn test/test
Connected.
SQL> insert into t1 values (1);
insert into t1 values (1)
*
ERROR at line 1:
ORA-00001: unique constraint (TEST.SYS_C005801) violated

就可以在user_dump_dest发现产生的trace文件。

那么发生错误的会话已经连接到数据库一段时间了，怎么得到这个会话在的信息？比如某个数据库，数据库中频繁地报下面的错误：

select sysdate create_time from dual
ORA-01555 caused by SQL statement below (Query Duration=0 sec, SCN: 0x09e5.0c3c77b1):
Wed Jul 22 11:17:51 2009
select g.*,m.*  from Tb_Model m right outer join (select t.*,v.table_name from.....

这个ORA-01555错误是非常怪异的，首先是查询DUAL表都会报错，其次，每次报错都是“Query Duration=0 sec, SCN: 0x09e5.0c3c77b1”，这里除了BUG,实在想不到其他的理由 。不过为了查明到底是哪个会话和哪个应用，是不是同一个会话引起，我们需要得到这个引起错误的会话的信息。

这里，我们可以用触发器。以SYS用户执行下面的代码：

Read the rest of this entry

一套运行在AIX 5.3，HACMP 5.4上的双节点RAC数据库,CRS和数据库的版本均为10.2.0.3；CRSD.BIN自动重启，并产生很多的CORE DUMP。
进入$ORA_CRS_HOME/log/<nodename>/crsd目录下，查看crsd日志文件，可以看到CRSD在重启时的日志如下：

2009-03-13 13:59:49.692: [ OCRRAW][11400]proprdc: backend_ctx->prop_sctx=[0x1017ed10]
2009-03-13 13:59:49.692: [ OCRRAW][11400]proprdc: backend_ctx->prop_sltsmx=[0x0]
2009-03-13 13:59:49.692: [ OCRRAW][11400]proprdc: backend_ctx->prop_sclsctx=[0x10365848]
2009-03-13 13:59:49.692: [ OCRRAW][11400]proprdc: backend_ctx->prop_ctx_ocrctx=[0x10362940]
2009-03-13 13:59:49.692: [ OCRSRV][11400]th_snap:8:failed to take backup prop_retval=26
2009-03-13 13:59:51.480: [ CRSOCR][11240]32OCR api procr_open_key failed for key CRS.CUR.ora!wydb3!ons. OCR error code = 3 OCR error msg:
2009-03-13 13:59:51.480: [ CRSOCR][11240][PANIC]32Failed to open key: CRS.CUR.ora!wydb3!ons(File: caaocr.cpp, line: 319)

2009-03-13 14:00:06.282: [ default][1][ENTER]32
Oracle Database 10g CRS Release 10.2.0.3.0 Production Copyright 1996, 2004, Oracle. All rights reserved
2009-03-13 14:00:06.282: [ default][1]32CRS Daemon Starting
2009-03-13 14:00:06.282: [ CRSMAIN][1]32Checking the OCR device
2009-03-13 14:00:06.285: [ CRSMAIN][1]32Connecting to the CSS Daemon
2009-03-13 14:00:06.705: [ CRSD][1]32Daemon Version: 10.2.0.3.0 Active Version: 10.2.0.3.0
2009-03-13 14:00:06.705: [ CRSD][1]32Active Version and Software Version are same
2009-03-13 14:00:06.705: [ CRSMAIN][1]32Initializing OCR
2009-03-13 14:00:06.713: [ OCRRAW][1]proprioo: for disk 0 (/dev/rwbsdb_ocr1_128m), id match (1), my id set (550012785,1028247821) total id sets (1), 1st set (550012785,1028247821), 2nd set (0,0) my votes (2), total votes (2)
2009-03-13 14:00:06.809: [ CRSD][1]32ENV Logging level for Module: allcomp 0

列出目录中的所有文件可以看到，最近几天都有core dump文件。仔细查看可以发现，每个core dump文件的间隔周期为固定的8.5小时。这是一个周期性的现象。

仔细查看上面的日志，”红色字体“的部分，引起了我的注意。这个错误，表明是在做某个东西的备份的时候报了错。应该是在备份OCR。core dump产生的周期和crsd自动重启的周期，都是固定的，这跟CRS会自动周期性地备份OCR比较吻合。

在METALINK上一番搜索，找到了BUG 5893629与这个故障现象比较符合。METALINK对这个BUG的描述称，CRS在备份OCR时，会在$ORA_CRS_HOME/cdata/<cluster_name>目录下生成一个temp.ocr，如果这个文件之前已经存在，会试图删除这个文件，而如果这个文件由于不是root用户所有，则就会导致crsd crash。这个BUG要在10.2.0.4才会修复。

根据对这个BUG的描述，进入到$ORA_CRS_HOME/cdata目录，这个目录下面有两个目录，一个是“crs”，另一个是"localhost“，一般来说，crs就是CRS集群的名称。进入这个目录，没有发现任何文件，看权限，root用户也可以建立文件。

问题在哪里呢？换一个角度思考，既然BUG描述中称不能删除旧的temp.ocr文件会导致crsd crash，那要是没有$ORA_CRS_HOME/cdata/<cluster_name>这个目录会怎么样，一样不能建立temp.ocr这个文件，那这种情况也会不会crash？这里$ORA_CRS_HOME/cdata目录下只有crs和localhost目录，如果按这种推理，如果cluster_name不是通常的”crs“呢？

不过当时有其他事情，离开了现场，不能得到CRS集群名字。不过幸运的是，我在日志文件中，在上面贴出的那段信息的前面，经过了一大段一大段的无用的信息之后，找到了下面的日志：

2009-03-13 13:59:49.391: [ OCRRAW][11400]rbkp:1: could not create the temp backup file [/oracle/crs/cdata/wydb_crs/temp.ocr]
2009-03-13 13:59:49.391: [ OCRRAW][11400]proprseterror: Error in accessing physical storage [26] Marking context invalid.

这里的日志就更明显了，就是不能创建”/oracle/crs/cdata/wydb_crs/temp.oc“这个文件。而前面的推断却不幸言中，CRS集群名字真的不是默认的"crs”，/oracle/crs/cdata这个目录下也的确没有wydb_crs这个目录。

让数据库维护人员在/oracle/crs/cdata目录中新建一个目录wydb_crs，经过一段时间的观察，故障不再出现，问题解决。

从这个故障中，我们得到一个教训，CRS有时真的很傻，为什么在备份时像这种不能创建文件的错误，不是写个日志忽略过去而是直接将进程crash了，并且还产生了core dump？为什么在安装CRS时，安装软件不自动建好这个目录，而只是按默认的"crs"名字建立目录？看来安装ORACLE软件的时候，CRS集群名字取默认值就行了。严重怀疑那个BUG是不是真的会解决这个问题（根据METALINK的描述，在备份时会随机生成一个文件名，而不再是固定的temp.ocr，但如果像这个案例中的故障，仍然会得不到解决。）

环境：HP-UX 11.31
Oracle 9.2.0.8

数据库异常崩溃，询问维护人员之前有大量数据操作。查看alert日志：

Thu Oct 9 02:20:18 2008
Errors in file /oracle/OraHome1/rdbms/log/acct_ora_11361.trc:
ORA-00600: internal error code, arguments: [ktprhtnew6], [], [], [], [], [], [], []
Thu Oct 9 02:20:19 2008
Fatal internal error happened while SMON was doing active transaction recovery.
Thu Oct 9 02:20:19 2008
Errors in file /oracle/OraHome1/rdbms/log/acct_ora_11361.trc:
ORA-00600: internal error code, arguments: [ktprhtnew6], [], [], [], [], [], [], []
SMON: terminating instance due to error 600
Instance terminated by SMON, pid = 11361

检查trace文件，没有发现有用的信息。

重启数据库，数据库能打开，但不到一分钟实例就crash。在alert日志中的错误信息均如上所示。
在网上及在metalink中以ktprhtnew6为关键字搜索，没有找到相似的BUG和案例。同时当时手边是用的163拨号上网，速度非常慢，只有通过分析来解决问题。

仔细分析alert日志可以发现是在做事务恢复时SMON出错，导致实际中止：

Fatal internal error happened while SMON was doing active transaction recovery.

我们知道ORA-600错误后面参数，如果像ktprhtnew6这样的均表示出错的函数。这里可以看出是在做并行恢复：

[K]enerl [T]ransaction [P]arallel [R]ecovery

设置fast_start_parallel_rollback参数为false，关闭数据库的并行恢复功能，重启数据库，数据库正常，故障消失。
看起来这应该又是一个BUG。

先说说这个数据库的环境：
Oracle 9.2.0.4 RAC，只不过这个RAC只运行了一个节点，另一节点没有开启。
AIX 5.3 TL04
主机为p550，4CPU，16G内存
应用为部署在Weblogic下的WEB应用。

故障现象：
首先是客户端的操作没有响应，从weblogic上看连接数非常高，其日志里面不停报超出连接池的最大连接数。在主机上用sqlplus "/ as sysdba"，在显示sqlplus的banner后，停止响应。

从故障现象来看，是数据库hang住了。

由于sqlplus不能操作，那么这个时候没办法通过oracle来dump system state。先看看操作系统里面，用topas命令观察，发现一个oracle进程占用了26%左右的CPU资源，IO等待几乎为0，可用的物理内存还比较多。根据那个占用CPU的进程号用ps命令查看，是一个普通的Server Process。

看来起这个进程陷入死循环了，26%的CPU资源正好是1个CPU（因为系统共4个CPU）。如果一个oracle进程拿到比较重要的资源，比如shared pool latch、library cache latch等，然后陷入了死循环（SPIN）后，其他进程没法解析SQL等，也就只有挂起了。

用kill命令杀掉那个进程，系统恢复正常，看来前面对故障的推断是正确的，不过没过几分钟，又出现了此故障现象。

只有找到oracle当时正在干什么，才能进行处理。用dbx来dump system state：

# dbx -a 446910
Waiting to attach to process 446910 ...
Successfully attached to oracle.
Type 'help' for help.
reading symbolic information ...
stopped in iosl.select at 0x9000000000c94d8 ($t2)
0x9000000000c94d8 (select+0xfffffffffff06318) e8410028 ld r2,0x28(r1)
(dbx) print ksudss(10)

Segmentation fault in slrac at 0x100083aa0 ($t2)
0x100083aa0 (slrac+0xe4) 88030000 lbz r0,0x0(r3)
(dbx) detach

Read the rest of this entry

某客户的一个表在进行分析和建索引一段时间时，均报ORA-8103错误。

让我们先看看ORA-8103错误是个什么样的错误？

[oracle@xty ~]$ oerr ora 8103
08103, 00000, "object no longer exists"
// *Cause: The object has been deleted by another user since the operation
// began, or a prior incomplete recovery restored the database to
// a point in time during the deletion of the object.
// *Action: Delete the object if this is the result of an incomplete
// recovery.

从上面的信息来看，引起这个错误的并不是由于什么对象被删除或者不完全恢复引起的。看来剩下的可能就是BUG或者是坏块了。

select /*+ parallel(a 6) no_index(a) */
count(lrrq) from hz2004.HJXX_RYZPXXB a

由于表很大，100g左右，因此等了好长一段时间，就报了ORA-8103错误。由于不同的SQL语句（建索引、分析表和查询表数据）都报了这个错误，基本可以确定是坏块引起的问题。

由于表中有long raw类型，因此不能通过从主键取得ROWID再根据ROWID读到值以后插入新表，由于查询表有问题，导出也不会成功。因此决定想办法来修复这个问题：

首先要确定是哪个块出现问题：

SQL> alter session set max_dump_file_size=unlimited;
SQL> alter session set db_file_multiblock_read_count=1;
SQL> alter session set events ‘immediate trace name trace_buffer_on level 1048576′;
SQL> alter session set events ‘10200 trace name context forever, level 1′;
SQL> select /*+ no_index(a */ count(*) from hz2004.hjxx_ryzpxxb a;

（注：经测试，在10g中，需要去掉trace_buffer_on那一个语句才会有trace，否则没有trace文件）
再次报错时，检查trace文件，发现如下的信息：

Consistent read started for block 11 : 09c63a9e
env: (scn: 0×0886.245ea878 xid: 0×0000.000.00000000
uba: 0×00000000.0000.00 statement num=0 parent xid:
xid: 0×0000.000.00000000
scn: 0×0000.00000000 0sch: scn: 0×0000.00000000)

从trace文件中可以发现在读文件号39块号408222时报错。

执行：

select * from hz2004.hjxx_ryzpxxb
where rowid=dbms_rowid.rowid_create(1,7415,39,408222,0);

报ORA-08103错误，可以确认是39号文件408222块坏。

然而用dbv命令检查39号文件，没有发现坏块。

通过dd取出39号文件408222块，发现该块居然是一个未格式化的块，但是该块在表的High water mark以下。单从该块来说是一个好的块，所以dbv检查并不会报坏块。

既然如此，我就故意做成一个坏块，然后让oracle跳过这个坏块。关闭库之后，用dd把坏块复制出来保存在一个文件，然后修改该块，使之成为一个坏块（很多的方法，这里我的方法就是修改其checksum值）。然后用dd复制回去。重启库之后，用 dbms_repair.skip_corrupt_blocks过程设置表在读取数据时，跳过坏块。

再次读取该表的所有数据，不再报错。

客户进行建索引和分析时也不再报错，顺利进行。

当然后续的工作，还是需要将数据导出来再导入，这样更稳妥。

前一天遇到一例database link问题，仅供大家参考：

数据库是运行在Windows 2003上的Oracle 9i

先来看看故障现象，维护人员发现数据库上的job不能正常执行。用TOAD手工调用job的存储过程，TOAD一直阻塞。

经过这个故障的过程如下：

1.      在TOAD中手工执行存储过程，TOAD挂起。
2． 用sqlplus连接到数据库，检查v$session_wait，发现执行存储过程的会话正在等待library cache pin。
3． 通过x$kglob与v$session_wait，发现等待library cache pin的SQL语句为：
         select flag from account@zw.world ....
4． 手工执行此SQL，客户端挂起。怀疑是数据链路问题，执行select * from dual@zw.world，客户端也挂起。
5． 在sqlplus下，新建数据库zw_link，执行select * from dual@zw_link，执行此SQL仍然会导致客户端挂起。
6． 怀疑数据库服务器不能正常接连到ZW库。在数据库服务器上用sqlplus连接ZW库：
       sqlplus xxx/xxx@zw
    这时数据库服务器（windows系统）弹出一对话框，windows木马防火墙提示是否允许sqlplus程序访问zw的IP地址的信息。看来是由于木马防火墙引起的问题。
7． 查看系统中运行的进程，发现windows木马防火墙软件是通过线程注入到其他进程的方式，对进程的网络访问进行控制。在进程要访问网络时，弹出对话框选择是否允许访问网络，但ORACLE进程是以服务方式运行的，没有设置为与桌面交互，所以弹 出的对话框不能显示，所以一直处于等待状态。
8． 去掉windows木马防火墙的自动启动，重启服务器，删除windows木马防火墙，检查数据库链接已经正常。
9． 手工执行存储过程,存储过程正常执行。检查存储过程运行产生的日志，也显示正常。至此问题解决。

看来现在的防病毒，防木马的工具也是越来越“厉害”了。

一客户重启主机，启动数据库之后，客户端连接报ORA-12541：没有监听器的错误

环境：ORACLE 10.2.0.1 RAC AIX 5.3

进行测试，发现结点1不正常。客户端通过PUBLIC IP可以连接，但通过VIP不能进行连接，报ORA-12541错误

检查结点1的VIP，正常。在客户端PING VIP，正常。TNSPING VIP，不通。

检查监听配置，正常。

重启监听，故障依旧。

在客户端（WINDOWS系统），用arp -a命令检查发现，结点1的PUBLIC IP和VIP的MAC地址不一致。怀疑是其他机器占用了此IP。

在客户端用nbtstat -A VIP地址，发现是一WINDOWS系统机器占用了此IP，并得到机器名。

客户维护人员解决IP地址冲突，故障排除。

故障解决很快，但此故障引发的问题值得紧记：在管理数据库的同时，别忘网络的管理。特记之。