DBA手记:Grid Control监控-进程累积导致的宕机

« Oracle Linux 6 使用 Ext4的性能体验 | Blog首页 | DBA手记:DBA诊断利器 - Event 10046和 10053 »

某用户Oracle Database 10g 10.2.0.4数据库，运行在HP 平台上，数据库出现大量系统累积进程，最后导致数据库挂起，影响了业务使用，造成了严重故障。

在数据库的进程记录信息中，我们发现大量的crs_stat.bin -t进程，这些进程部分是Grid Control调度的监控，另外一部分来自用户自定制的监控脚本，这些脚本中最早未能完成的脚本时间为03:32:48。也就是说，从这一时间起，数据库出现异常导致大量crs_stat进程累积，最后耗尽资源，导致系统挂起。

oracle 7085 7084 0 03:52:49 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 9016 9015 0 03:57:48 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 1194 1193 0 03:37:49 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 7237 7231 0 16:31:00 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 5119 5118 0 03:47:48 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 6325 6319 0 03:51:00 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 25629 25619 0 04:41:00 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 28872 28871 0 03:32:48 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 2328 2322 0 03:41:00 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 11040 11039 0 04:02:49 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 10294 10288 0 04:01:00 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

oracle 29596 29590 0 04:51:00 ? 0:00 /u01/app/oracle/product/10.2.0/crs/bin/crs_stat.bin -t

那么是否这些进程就是罪魁祸首呢？

除了这些进程，系统中还累积了大量的racgmain check进程，这些进程自Mar 14日已经开始累积，最终数量达到了400个左右：

oracle 21315 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 16268 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 27453 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 12214 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 6824 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 8249 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 1884 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 12224 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 8232 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 11227 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 26275 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 16272 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 6829 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

oracle 1889 1 0 Mar 14 ? 0:00 /u01/app/oracle/product/10.2.0/db_1/bin/racgmain check

正常情况下，在每次检测之后racgmain进程应当退出，但是在故障出现时，这些进程没有退出，而且这种情况持续了多天。这说明racgmain的大量异常累积以及之后的crs_stat检测异常是导致最终故障的来龙去脉，而racgmain的异常是主要起因。Oracle的Bug 6196746说明了这个问题。可以通过如下步骤修复这个问题：

1. Make a copy of racgwrap located under $ORACLE_HOME/bin and $CRS_HOME/bin on ALL Nodes

2. Edit the file racgwrap and modify the last 3 lines from:

~~~

$ORACLE_HOME/bin/racgmain "$@"

status=$?

exit $status

to:

# Line added to fix for Bug 6196746

exec $ORACLE_HOME/bin/racgmain "$@"

~~~

3. Kill all the orphan racgmain processes running.

$ ps -ef|grep "racgmain check"

oracle 18701 1 0 Aug 1 ? 0:00 /oracle/product/10.2.0/database/bin/racgmain check

oracle 14653 1 0 Aug 1 ? 0:00 /oracle/product/10.2.0/database/bin/racgmain check

oracle 24517 1 0 Aug 1 ? 0:00 /oracle/product/10.2.0/database/bin/racgmain check

$ kill -9 <PID of racgmain>

注意，数据库在运行过程中，会调用该系统$ORACLE_HOME/bin 和 $CRS_HOME/bin下的racgwrap脚本，进而执行racgmain检测，这两个脚本应该同时修正，而在客户系统中我们发现这两个目录下的脚本并不一致，这可能是因为之前客户修正的疏忽遗漏：

db1::/u01/app/oracle/product/10.2.0/crs/bin>diff racgwrap $ORACLE_HOME/bin/racgwrap

3c3

---

9c9

< ORACLE_HOME=/u01/app/oracle/product/10.2.0/crs

---

> ORACLE_HOME=/u01/app/oracle/product/10.2.0/db_1

12c12

< ORACLE_BASE=/u01/app/oracle/product/10.2.0/crs

---

> ORACLE_BASE=/u01/app/oracle/product/10.2.0/db_1

62c62,64

< exec $ORACLE_HOME/bin/racgmain "$@"

---

> $ORACLE_HOME/bin/racgmain "$@"

> status=$?

> exit $status

在检查crsd.log日志文件中，我们可以发现大量如下错误提示：

2010-03-14 17:31:21.682: [ CRSEVT][67763] CAAMonitorHandler :: 0:Action Script /u01/app/oracle/product/10.2.0/crs/bin/racgwrap(check) timed out for ora.xgp4.db! (timeout=600)

2010-03-14 17:31:21.683: [ CRSAPP][67763] CheckResource error for ora.xgp4.db error code = -2

2010-03-14 17:37:32.382: [ CRSEVT][67784] CAAMonitorHandler :: 0:Could not join /u01/app/oracle/product/10.2.0/db_1/bin/racgwrap(check)

category: 1234, operation: scls_process_join, loc: childcrash, OS error: 0, other: Abnormal termination of the child

2010-03-14 17:37:32.382: [ CRSEVT][67784] CAAMonitorHandler :: 0:Action Script /u01/app/oracle/product/10.2.0/db_1/bin/racgwrap(check) timed out for ora.xgp4.cmp.cs! (timeout=600)

2010-03-14 17:37:32.382: [ CRSAPP][67784] CheckResource error for ora.xgp4.cmp.cs error code = -2

2010-03-14 17:47:32.093: [ CRSEVT][67819] CAAMonitorHandler :: 0:Could not join /u01/app/oracle/product/10.2.0/db_1/bin/racgwrap(check)

category: 1234, operation: scls_process_join, loc: childcrash, OS error: 0, other: Abnormal termination of the child

值得注意的是，在以上提示中，Oracle数据库会调用$ORACLE_HOME/bin/racgwrap 和$CRS_HOME/bin/racgwrap两个脚本来执行检查，来自$ORACLE_HOME/bin/racgwrap的脚本未修正，会导致进程的异常挂起。

这个Bug在CRS的PSU中被修正，根据环境检查，在Patch应用中可能出现问题，导致脚本错误，当数据库调用$ORACLE_HOME/bin/racgwrap进程时，就可能出现问题。

下图是CRS 10.2.0.4中相关的Bug修正列表：

而为何累计了大量racgmain进程，crs_stat操作无法返回结果，这和HP-UX Itanium平台的Bug有关，根据Metalink的883801.1文档记录应当应用操作系统PHKL_40208 补丁集。并且应当检查以下补丁或替代补丁已经被应用：PHKL_38715、PHCO_38837、PHKL_38623、PHKL_38733, PHKL_38715, PHKL_38762。