Troubleshooting Oracle Exadata x8 crsctl start fail with error CRS-41053

by

最近有个客户的Oracle Exadata X8 其中一个节点crash后无法启动提示 CRS-41053 其他节点运行正常，手动重启CRS依旧失败并且alert日志中无明显报错。后在聚合所有日志，在问题时间段RStrce文件发现了OS system dependent operation:connect failed with status: 111， 排查出RS和MS进程异常，原因为/var空间耗尽，下面记录这个案例

oracle exadata x8 启动失败

# crsctl start crs

CRS-41053: checking Oracle Grid Infrastructure for file permission issues
CRS-4124: Oracle High Availability Services startup failed.
CRS-4000: Command Start failed, or completed with errors.

db alert log crash前无任何报错

2026-09-02T14:58:48.368684+08:00
Thread 3 advanced to log sequence 197938 (LGWR switch), current SCN: 21264392342830
Current log# 42 seq# 197938 mem# 0: +DATAC1/ORCL/ONLINELOG/group_42.5273.1190483431
2026-09-02T14:58:50.095133+08:00
LOGMINER: End mining logfile for session 37 thread 3 sequence 197937, +DATAC1/ORCL/ONLINELOG/group_41.5272.1190483429
2026-09-02T14:58:50.168900+08:00
LOGMINER: Begin mining logfile for session 37 thread 3 sequence 197938, +DATAC1/ORCL/ONLINELOG/group_42.5273.1190483431
2026-09-02T14:58:57.462932+08:00
ARCe (PID:288874): Archived Log entry 933599 added for T-3.S-197937 ID 0x6104c5d8 LAD:1
2026-09-02T14:58:57.726655+08:00
fast_start_mttr_target 300 is set too low, using minimum achievable MTTR 7946 instead.

gi alert log 无crash和重启的日志

2026-09-02 11:27:31.407 [GIPCD(71976)]CRS-7510: The 'daemon thread' of Oracle Grid Interprocess communication (GIPC) has been non-responsive for '10490' milliseconds. Additional diagnostics: process name: 'gipcd'.
2026-09-02 11:27:31.412 [GIPCD(71976)]CRS-7510: The 'daemon thread' of Oracle Grid Interprocess communication (GIPC) has been non-responsive for '11220' milliseconds. Additional diagnostics: process name: 'crsd'.
2026-09-02 13:40:22.280 [ORAROOTAGENT(289042)]CRS-5818: Aborted command 'check' for resource 'ora.drivers.acfs'. Details at (:CRSAGF00113:) {0:11:2} in /u01/app/grid/diag/crs/anbob03/crs/trace/ohasd_orarootagent_root.trc.
2026-09-02 13:40:23.755 [ORAROOTAGENT(289042)]CRS-5014: Agent "ORAROOTAGENT" timed out starting process "/u01/app/21.0.0.0/grid/bin/acfsload" for action "check": details at "(:CLSN00009:)" in "/u01/app/grid/diag/crs/anbob03/crs/trace/ohasd_orarootagent_root.trc"
2026-09-02 13:40:23.822 [OHASD(66363)]CRS-2802: Purging events not published within 15 minutes
2026-09-02 14:18:22.279 [ORAROOTAGENT(289042)]CRS-5818: Aborted command 'check' for resource 'ora.drivers.acfs'. Details at (:CRSAGF00113:) {0:11:2} in /u01/app/grid/diag/crs/anbob03/crs/trace/ohasd_orarootagent_root.trc.
2026-09-02 14:18:22.431 [OHASD(66363)]CRS-2802: Purging events not published within 15 minutes
2026-09-02 17:29:48.293 [CLSECHO(78971)]AFD-0654: AFD is not supported on Exadata systems
2026-09-02 17:35:24.840 [CLSECHO(117034)]AFD-0654: AFD is not supported on Exadata systems
2026-09-02 17:40:03.678 [CLSECHO(148239)]AFD-0654: AFD is not supported on Exadata systems
2026-09-02 17:44:12.443 [CLSECHO(179147)]AFD-0654: AFD is not supported on Exadata systems
2026-09-02 17:50:17.869 [CLSECHO(220429)]AFD-0654: AFD is not supported on Exadata systems
2026-09-02 17:56:44.675 [CLSECHO(263038)]AFD-0654: AFD is not supported on Exadata systems
2026-09-02 19:33:01.283 [CRSCTL(106060)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /u01/app/grid/diag/crs/anbob03/crs/trace/crsctl_106060.trc.
2026-09-02 19:33:11.117 [CRSCTL(107203)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /u01/app/grid/diag/crs/anbob03/crs/trace/crsctl_107203.trc.
2026-09-02 19:33:20.460 [OCRCONFIG(108273)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /u01/app/grid/diag/crs/anbob03/crs/trace/ocrconfig_108273.trc.
2026-09-02 19:33:32.906 [OCRDUMP(111566)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /u01/app/grid/diag/crs/anbob03/crs/trace/ocrdump_111566.trc.
2026-09-02 20:13:28.265 [CRSCTL(271705)]CRS-1013: The OCR location in an ASM disk group is inaccessible. Details in /u01/app/grid/diag/crs/anbob03/crs/trace/crsctl_271705.

crsctl trace不存在

message 日志


Sep 2 14:58:06 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:58:10 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:58:23 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:58:31 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:58:42 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:58:56 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:59:01 anbob03 systemd: Started Session 1992880 of user root.
Sep 2 14:59:07 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:59:07 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 14:59:22 anbob03 systemd-logind: New session 1992881 of user zdbm.
Sep 2 14:59:22 anbob03 systemd: Started Session 1992881 of user zdbm.
Sep 2 15:11:10 anbob03 chronyd[21448]: Selected source 10.32.38.153
Sep 2 15:11:10 anbob03 chronyd[21448]: System clock wrong by 1043.230603 seconds, adjustment started
Sep 2 15:11:10 anbob03 systemd: Time has been changed
Sep 2 15:11:10 anbob03 chronyd[21448]: System clock was stepped by 1043.230603 seconds
Sep 2 15:11:10 anbob03 rsyslogd: imjournal: 1681014 messages lost due to rate-limiting
Sep 2 15:11:10 anbob03 systemd: Started Wait for chrony to synchronize system clock.
Sep 2 15:11:10 anbob03 systemd: Starting Wait for chrony synchronization completed…
Sep 2 15:11:10 anbob03 systemd: Started Wait for chrony synchronization completed.
Sep 2 15:11:10 anbob03 systemd: Reached target System Time Synchronized.
Sep 2 15:11:10 anbob03 systemd: Started Command Scheduler.
Sep 2 15:11:10 anbob03 systemd: Starting LSB: Start and Stop Oracle High Availability Service…
Sep 2 15:11:10 anbob03 systemd: Started Oracle High Availability Services.
Sep 2 15:11:10 anbob03 ohasd: Starting ohasd:
Sep 2 15:11:10 anbob03 root: Starting execution of Oracle Clusterware init.ohasd
Sep 2 15:11:10 anbob03 root: Oracle HA daemon is enabled for autostart.
Sep 2 15:11:10 anbob03 ohasd: CRS-4123: Oracle High Availability Services has been started.
Sep 2 15:11:10 anbob03 systemd: Started LSB: Start and Stop Oracle High Availability Service.
Sep 2 15:11:10 anbob03 systemd: Started RHPHelper Drain Service.
Sep 2 15:11:10 anbob03 root: exec /u01/app/21.0.0.0/grid/perl/bin/perl -I/u01/app/21.0.0.0/grid/perl/lib /u01/app/21.0.0.0/grid/bin/crswrapexece.pl /u01/app/21.0.0.0/grid/crs/install/s_crsconfig_anbob03_env.txt /u01/app/21.0.0.0/grid/bin/ohasd.bin "reboot"
Sep 2 15:11:43 anbob03 systemd: Created slice User Slice of zdbm.
Sep 2 15:11:43 anbob03 journal: Suppressed 50976 messages from /system.slice/rsyslog.service
Sep 2 15:11:43 anbob03 rsyslogd: imjournal: fopen() failed for path: '/var/lib/rsyslog/imjournal.state.tmp': No space left on device [v8.24.0-57.0.1.el7_9.1 try http://www.rsyslog.com/e/2013 ]
Sep 2 15:11:43 anbob03 systemd-logind: New session 1 of user zdbm.
Sep 2 15:11:43 anbob03 systemd: Started Session 1 of user zdbm.
Sep 2 15:21:43 anbob03 rsyslogd: imjournal: 1683798 messages lost due to rate-limiting
Sep 2 15:21:43 anbob03 su: (to oracle) root on none

rsyslog 在读取 systemd journal 时，因为日志产生速度过快触发了 rate limit，导致约 168 万条日志没有被 rsyslog 转发/写入 /var/log/messages。
注意/var 空间已耗尽。

不过用我日志聚合工具分析重启后的错误日志

2026-09-02 15:11:10.481 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004BA: mon_proc_pid oldpid: 39349
2026-09-02 15:11:10.481 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004BC: OS system dependent operation:connect failed with status: 111
2026-09-02 15:11:10.481 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004BD: OS failure message: Connection
2026-09-02 15:11:10.481 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004BE: failure occurred at: sosstcpconne
2026-09-02 15:11:10.481 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004BF: Failed to heartbeat MS (port: 5043 timeout: 60 sec)
2026-09-02 15:11:10.581 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C0: mon_proc_pid oldpid: 39349
2026-09-02 15:11:10.581 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C2: OS system dependent operation:connect failed with status: 111
2026-09-02 15:11:10.581 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C3: OS failure message: Connection
2026-09-02 15:11:10.581 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C4: failure occurred at: sosstcpconne
2026-09-02 15:11:10.581 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C5: Failed to heartbeat MS (port: 5043 timeout: 60 sec)
2026-09-02 15:11:10.681 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C6: mon_proc_pid oldpid: 39349
2026-09-02 15:11:10.682 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C8: OS system dependent operation:connect failed with status: 111
2026-09-02 15:11:10.682 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004C9: OS failure message: Connection
2026-09-02 15:11:10.682 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004CA: failure occurred at: sosstcpconne
2026-09-02 15:11:10.682 diag/asm/dbserver/anbob03/trace/rstrc_39320_mmt_2.trc :000004CB: Failed to heartbeat MS (port: 5043 timeout: 60 sec)
2026-09-02 15:11:10.718 diag/crs/anbob03/crs/trace/crsctl_44413.trc *:kgfpm.c@1144: kgfpmInitPatchIter: npatches 6
2026-09-02 15:11:10.718 diag/crs/anbob03/crs/trace/crsctl_44413.trc *:kgfpm.c@1176: kgfpmGetNextPatch: patchid[7fffab94f5e8] 33276861
2026-09-02 15:11:10.718 diag/crs/anbob03/crs/trace/crsctl_44413.trc *:kgfpm.c@1176: kgfpmGetNextPatch: patchid[7fffab94f5e8] 33516412

rstrc_39320_mmt_2.trc 文件，是 Exadata 存储节点上 RS（Restart Server，重启服务器）进程组产生的诊断追踪文件 (trace file)，rstrc：这是 RS 进程组追踪文件的固定标识，mmt：这代表 cellrsmmt 进程，是 RS 中专用来监控 MS (Management Server，管理服务器) 服务的进程。生成这类追踪文件，通常意味着 RS 检测到了问题并采取了行动。最常见的场景就是 CELLSRV 或 MS 服务发生挂起 (hang) 或无响应。例如，当监控进程无法收到定期心跳时，就会触发一系列诊断并重启服务

什么是RS MS?

在Exadata中，RS 进程组是 Exadata 存储节点上的“守护者”。它负责监控CELLSRV（核心存储服务）和MS（管理服务）的健康状况，并在它们出现故障（如崩溃、挂起、内存泄漏）时自动重启，以保障服务可用性。MS 是 Management Server（管理服务器） 的缩写。它是 Exadata 存储节点和数据库节点上的一个核心管理进程，同 CELLSRV（核心存储服务）和 RS（重启服务器）并称为存储软件的“三大核心进程”，MS 服务扮演着“管理大总管”的角色，可以把它理解为Exadata节点上各种管理任务的执行者。虽然我们通常通过CellCLI（存储节点）或DBMCLI（数据库节点）这样的命令行工具来执行管理操作，但这些命令本身只是客户端，真正执行并完成配置和管理工作的，是后台的 MS 进程。MS 是一个基于 OC4J（Oracle Containers for J2EE）的 Java 应用程序。

connect failed with status: 111，status: 111 在 Linux 上：errno 111 = ECONNREFUSED，connect() 发起 TCP 连接时，对端主动拒绝了连接。ASM/RSTRC 进程正在尝试连接 MS（Management Server）的 TCP 5043 端口进行 heartbeat，但连接被拒绝。

这里其他db server正常，说明cell没有问题。

DB Server 上重启 MS

dbmcli -e "alter dbserver shutdown services ms"
dbmcli -e "alter dbserver startup services ms"
# /opt/oracle/dbserver/dbms/bin/dbmcli -e "alter dbserver startup services ms"
Starting MS services…
DBM-01509: Restart Server (RS) not responding..
# /opt/oracle/dbserver/dbms/bin/dbmcli -e list dbserver detail
DBM-01514: Connect Error. Verify that Management Server is running on the server
msStatus: unknown
rsStatus: stopped

RS 已经 stopped，所以执行 STARTUP SERVICES MS 时，DBMCLI 无法通过 RS 正常管理/启动 MS。Oracle 对 DB Server 的 ALTER DBSERVER 明确支持 STARTUP SERVICES {RS | MS | ALL}；而 RS 的职责就是监控并重启其他服务。先启动 RS

# /opt/oracle/dbserver/dbms/bin/dbmcli -e "alter dbserver startup services rs"

然后检查：

# /opt/oracle/dbserver/dbms/bin/dbmcli -e "list dbserver detail"
正常节点是
msStatus: running
rsStatus: running

这个问题节点我们RS 启动成功，但是在启动MS时还是失败。

# /opt/oracle/dbserver/dbms/bin/dbmcli -e "alter dbserver startup services ms"

Starting MS services…
The STARTUP of MS services was not successful. Error: Start Timed out

检查进程和端口有没有占用

ps -ef | grep -Ei '[d]bmsrv|[d]brs|[m]s'

— MS进程并不存在(java)

ss -lntp | grep ':5043'

— 端口也并没有占用

MS启动要在10分钟后timeout，在启动期间检查是否有进程卡死

ps -eo pid,ppid,user,lstart,etime,args |grep -Ei '[d]bms|[m]anagement|[m]s'

先看看 /opt/oracle/dbserver/dbms 下有哪些日志

find /opt/oracle/dbserver/dbms -type f \
( -name ".log" -o -name ".trc" -o -name "*.out" ) \
-mtime -3 -ls 2>/dev/null

— 并没有trace文件

还有一个非常值得查的地方：MS 的 Unix socket / IPC

ls -la /var/run | grep -Ei 'dbms|ms|rs'
find /var/run /tmp -maxdepth 2 ( -iname 'dbms' -o -iname 'dbrs' -o -iname 'ms' ) \
-ls 2>/dev/null

查一下 MS 的运行用户和文件权限

id dbmsvc
id dbmadmin
id dbmmonitor
ls -ld /opt/oracle/dbserver/dbms
ls -ld /opt/oracle/dbserver/dbms/bin
ls -l /opt/oracle/dbserver/dbms/bin | head -50

MS日志


Running Jetty:
2026-09-03 18:46:30.325:INFO::main: Logging initialized @272ms to org.eclipse.jetty.util.log.StdErrLog
2026-09-03 18:46:30.412:INFO::main: Console stderr/stdout captured to /var/log/oracle/deploy/2026_09_03.jetty.log
/opt/oracle/dbserver/dbms/deploy/scripts/ms_server.sh: line 125: 361838 Killed LD_PRELOAD=${JAVA_HOME}/jre/lib/amd64/libjsig.so ${JETTY_HOME}/bin/jetty.sh "run"

dbmcli.lst.root.0 日志 –按时间排序

Sep 03, 2026 6:51:31 PM oracle.ossmgmt.common.util.RSCtl invokeSingleRSCmd
WARNING: The STARTUP of MS services was not successful. Error: Start Timed out
Sep 03, 2026 6:51:31 PM oracle.ossmgmt. dbms.cli.DBMCLIImpl readAndProcessLine
INF0: call path: 361773(java)-361732(dbmcli)-300121(bash)-299669(sshd)-59480( sshd)-1(systemd)

查 OS 资源

free -h
df -h
df -ih

开头我们就提到过 /var日志耗尽，但是清理过.

我们决定重启OS, 重启后RS 和MS进程恢复正常。

启动GI恢复正常。

解决方案

1， 检查文件系统是否full ，主要检查 / 和 /var ,容易触发CRS-41053，我们这个案例就是/var。
2，kill 重启的ohasd 进程


ps -ef | grep -v grep | grep ohasd

3， 重启操作系统
crsd日志中是否有关键字 Patch Levels don’t match.

$ /oracle/app/193/grid/bin/kfod op=patches
$ /oracle/app/193/grid/bin/kfod op=patchlvl

4， Re-configuring the clusterware

$GRID_HOME/crs/install/rootcrs.sh -deconfig -force

$GRID_HOME/root.sh

Leave a Comment