1. 说明

某客户生产部署Oracle RAC 19c集群，在部署之后，EM监控报ora.crf资源在此期间，异常重启数次，并且数次重启并没有任何规律。
----环境
系统版本：CentOS Linux release 7.6.1810
数据库版本：Oracle RAC 19.11.0.0.210420
----现象
ora.crf在无人为干预的情况下，异常重启，没有规律，最近一次发生的时间在2022-05-31 16:25左右。

2. 诊断过程

2.1 何为ora.crf资源

ora.crf 是 Cluster Health Monitor (CHM) 的资源，诊断 CHM 的问题通常更需要 ologgerd 和 sysmond 的log，与客户沟通，提供相关时间点的集群日志。
通过以下命令搜集相关日志。

su - root
export ORACLE_HOME= <your CRS home>
$ORACLE_HOME/tfa/bin/tfactl diagcollect -from "May/31/2022 14:00:00" -to "May/31/2022 18:00:00"
复制

2.2 分析alter.log日志

2022-04-22 18:33:15.614 [OSYSMOND(4714)]CRS-8500: Oracle Clusterware OSYSMOND process is starting with operating system process ID 4714
2022-05-31 16:25:15.621 [OSYSMOND(23503)]CRS-8500: Oracle Clusterware OSYSMOND process is starting with operating system process ID 23503
复制

最近OSYSMOND出现重启，而且最近一次时间为2022-05-31 16:25:15.621，与客户反馈时间吻合。

2.3 分析osysmond.trc日志

2022-05-31 16:25:15.013 : default:3588681472: scrfosm_fill_all_nic_info: NIC: ens2f0: not found in ioctl array
2022-05-31 16:25:15.013 : default:3588681472: scrfosm_fill_all_nic_info: NIC: virbr0-nic: not found in ioctl array
2022-05-31 16:25:15.096 : CRFMOND:3588681472: Restarting sysmond after user defined cpu time <<<<<<<<<<<<<<<<<<<<<<<

2022-05-31 16:25:15.302 : CRFMOND:3588681472: clsmond_shutdown: Received shutdown sysmond signal. Flushing both the previous and current buffers to local log, marking them as MUSTSEND.

Trace file /u01/app/grid/diag/crs/dc17glsdb2/crs/trace/osysmond.trc
Oracle Database 19c Clusterware Release 19.0.0.0.0 - Production
Version 19.13.0.0.0 Copyright 1996, 2021 Oracle. All rights reserved.
default:3197280000: 1: clskec:has:CLSU:910 4 args[clsdAdr_CLSK_err][mod=clsdadr.c][loc=(:CLSD00302:)][msg=2022-05-31 16:25:15.416 (:CLSD00302:) Trace file size and number of segments fetched from environment variable: ORA_DAEMON_TRACE_FILE_OPTIONS filesize=26214400,numsegments=10 Detected in function clsdAdrGetEnvVar_TFO at line number 6819. ]

CLSB:3197280000: [ INFO] Argument count (argc) for this daemon is 1
CLSB:3197280000: [ INFO] Argument 0 is: /u01/app/19.0.0/grid/bin/osysmond.bin
2022-05-31 16:25:15.623 : default:3197280000: clsmond_main: Successfully initilized enviornment variable
复制

注意到sysmond 在after user defined cpu time 之后发生了重启，何为user defined cpu time，再此并未找到相关解释（大概意思sysmond进程有一个内置的临界值，达到此值会重启），但不影响继续往下分析。

2.4 分析系统资源

在搜集的日志中包含osw相关信息，可供参考。

XXXXX_vmstat_22.05.31.1600.dat <<<<<<<<< 系统资源充裕

zzz ***Tue May 31 16:24:14 CST 2022
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
6 0 0 59304672 60900 59655628 0 0 2 4 0 0 1 0 99 0 0
0 0 0 59293268 60900 59655860 0 0 20 97 11760 20419 1 1 98 0 0
0 0 0 59295384 60900 59655768 0 0 6595 630 12028 24698 1 1 98 0 0
复制

由此可见并非系统资源问题导致重启。

XXXXX_ps_22.05.31.1600.dat <<<< 可观察到 osysmond 正好在进程 CPU Time 累计为 24 小时(TIME = 1-00:00:00)后重启。


zzz ***Tue May 31 16:24:14 CST 2022
USER PID PPID PRI %CPU %MEM VSZ RSS WCHAN S STARTED TIME COMMAND
root 4714 1 69 2.5 0.3 1921680 459068 hrtimer_nanosleep S Apr 22 23:59:58 /u01/app/19.0.0/grid/bin/osysmond.bin

zzz ***Tue May 31 16:24:44 CST 2022
USER PID PPID PRI %CPU %MEM VSZ RSS WCHAN S STARTED TIME COMMAND
root 4714 1 69 2.5 0.3 1921680 459068 hrtimer_nanosleep S Apr 22 23:59:59 /u01/app/19.0.0/grid/bin/osysmond.bin

zzz ***Tue May 31 16:25:14 CST 2022
USER PID PPID PRI %CPU %MEM VSZ RSS WCHAN S STARTED TIME COMMAND
root 4714 1 69 2.5 0.3 1921680 459068 hrtimer_nanosleep S Apr 22 1-00:00:00 /u01/app/19.0.0/grid/bin/osysmond.bin

zzz ***Tue May 31 16:25:44 CST 2022
USER PID PPID PRI %CPU %MEM VSZ RSS WCHAN S STARTED TIME COMMAND
root 23503 1 69 5.0 0.1 1659532 171640 hrtimer_nanosleep S 16:25:14 00:00:01 /u01/app/19.0.0/grid/bin/osysmond.bin <<<<< 重启
复制

根据osw的ps日志，可以清晰的看到， osysmond 正好在进程 CPU Time 累计为 24 小时(TIME = 1-00:00:00)后重启。

2.5 资料查证

根据以往经验，出现此类问题，如果不是系统资源本身出现问题，可以向BUG方向猜测，19C虽说比较稳定，但也要经过事实验证。
经过MOS查证，发现类似案例，证实为BUG导致

Bug 33132334 - OSYSMOND Goes Down With "restarting sysmond after user defined cpu time" Message ( Doc ID 33132334.8 )
复制

2.6 解决方案

可升级至19.14.0.0.220118，修复此BUG

2.7 附加建议

ora.crf 实际上是 Cluster Health Monitor (CHM) 资源，参考：

Cluster Health Monitor (CHM) FAQ ( Doc ID 1328466.1 )
复制

它是用来收集 OS 的一些资源状况信息的，对于已经部署了 OSWatcher 工具来收集 OS 资源信息，ora.crf 实际上并没有什么实际用处。如果短时间不能升级，忽略该问题即可，它不会影响集群运行。