ORA-07274 spdcr:access error错误一例

下午在客户office遭遇了ORA-07274错误,那是一套AIX 5.3上10.2.0.4的2节点RAC系统,乍看到7274还以为是ORA-7445的孪生兄弟,心中暗想10.2.0.4的RAC问题还真是不少:

Errors in file /s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_psp0_4272.trc:
ORA-07274: spdcr: access error, access to oracle denied.
No such file or directory

Mon Apr 18 17:05:44 2011
PSP0: terminating instance due to error 7274
Mon Apr 18 17:05:44 2011
Errors in file /s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_lms1_4285.trc:
ORA-07274: spdcr: access error, access to oracle denied.
Mon Apr 18 17:05:44 2011
Errors in file /s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_lms0_4279.trc:
ORA-07274: spdcr: access error, access to oracle denied.
Mon Apr 18 17:05:44 2011
Errors in file /s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_lmd0_4276.trc:
ORA-07274: spdcr: access error, access to oracle denied.
Mon Apr 18 17:05:44 2011
Errors in file /s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_lmon_4274.trc:
ORA-07274: spdcr: access error, access to oracle denied.
Mon Apr 18 17:05:45 2011
System state dump is made for local instance
System State dumped to trace file /s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_diag_4270.trc
Mon Apr 18 17:05:45 2011
Trace dumping is performing id=[cdmp_20110418170545]
Mon Apr 18 17:05:46 2011
Instance terminated by PSP0, pid = 4272


====/s01/oracle/product/10.2.0/db_1/rdbms/log/prod21_psp0_4272.trc======

error 7274 detected in background process
ORA-07274: spdcr: access error, access to oracle denied.
ksuitm: waiting up to [5] seconds before killing DIAG


[oracle@vrh1 ~]$ oerr ora 7274
07274, 00000, "spdcr: access error, access to oracle denied."
// *Cause:  Unable to access "oracle" program. Verify ?/bin/oracle or
//          $ORABCKPRG exist, and are executable.
// *Action: Check errno returned.

以上ORA-07274错误直接导致RAC的2号节点实例意外终止!

引起ORA-07274错误的唯一直接原因是$ORACLE_HOME/bin目录下的oracle 2进制文件在错误发生时无法正常访问,可能造成该重要文件无法访问的原因可能有:

1.文件系统被umount或者ORACLE_HOME所在磁盘出现错误
2.oracle 2进制文件的权限设置错误,其正确权限应为6751
3.oracle 2进制文件被意外删除;当然relink oracle程序需要短暂移动该文件,所以也可能造成以上问题

在发生以上ORA-07274错误后我们第一时间使用ls命令查看了oracle 2进制文件的状态:

[oracle@vrh1 bin]$ ls -l $ORACLE_HOME/bin/oracle     
-rwsr-s--x 1 oracle oinstall 96789226 Apr 18 17:03 /s01/oracle/product/10.2.0/db_1/bin/oracle

[oracle@vrh1 bin]$ stat $ORACLE_HOME/bin/oracle
  File: `/s01/oracle/product/10.2.0/db_1/bin/oracle'
  Size: 96789226        Blocks: 189248     IO Block: 4096   regular file
Device: fd00h/64768d    Inode: 4434759     Links: 1
Access: (6751/-rwsr-s--x)  Uid: (  500/  oracle)   Gid: (  500/oinstall)
Access: 2011-04-18 17:04:55.000000000 -0400
Modify: 2011-04-18 17:03:44.000000000 -0400
Change: 2011-04-18 17:25:09.000000000 -0400

[oracle@vrh1 bin]$ date
Mon Apr 18 17:25:30 EDT 2011

并发现该文件在近期内被修改过(Modify: 2011-04-18 17:03:44.000000000 -0400),首先我想到的是可能有人在实例启动的情况下重新编译了oracle 2进制程序,但虽然的调查发现$ORACLE_HOME下大部分的目录修改时间(Modify time)都变成了最近。

这个时候一副”案件现场”已经呈现在我脑海中了,很明显是有人误删除了$ORACLE_HOME下的文件,在发现是误操作后立即终止了rm命令,但这个时候Oracle instance已经因为oracle 2进制程序文件丢失而意外终止terminated了,为了让现场恢复到原样,其又试图通过将1号节点上的Oracle Software传输到2号节点上来解决问题。

为了进一步证明我的想法,我求助于OS管理人员,希望通过传说中的系统命令审计来”锁定”问题。OS管理人员打开一个文本文件同我一起开始review起来,但在我看来这个审计文件的信息似乎过于简单了,只记录操作用户名下运行过的shell命令;一开始我们浏览了root用户的审计记录,没有发现任何问题;在准备查看oracle用户的审计文件时,系统管理人员才告之我,我们在查看的审计文件其实是用户home目录下的.sh_history,天哪!这就是传说中的审计文件,真神奇!

一般来说UNIX上的shell history只保留最近1000条的命令记录,为了不让这些唯一的证据丢失,我们首先将该.sh_history复制了一份,之后review历史记录文件后发现oracle用户执行过如下命令:

..............
rm -rf *
rcp -r node:/s01/oracle/product/10.2.0/db_1/* ./

rm -rf命令的确应当成为DBA的禁忌,无论是旧历江湖的老鸟还是初出茅庐的嫩头青都可能栽在rm手上。根据抽屉原理,最坏的情况总会发生,而我们又无法真正绝对意义上杜绝对rm命令的使用(我之前的文章介绍过由hostname误操作修改了RAC中一个节点的主机名的例子,这样的情况推荐使用uname -n来获取主机名字,可以杜绝使用hostname),那么我们真的很有必要在敲下rm命令前思考那么几秒,或者请另一位头脑清醒的仁兄帮自己确认一下,当然常年在船上走没有不湿鞋的,特别是当操作者处在一种panic模式的情景中时。

这个case因为oracle用户的密码只有少数几个人拥有,所以之后很容易能定位到责任人。多年之前在我第一家服务的公司中,office中到处贴着各种IT从业人员应当知晓的守则,其中就有一条”Passwords are like bubble gum”,是的密码就像是吹泡泡糖!

沪ICP备14014813号-2

沪公网安备 31010802001379号