背景情况简述
2023年 11 月 05 日 16:24:11 ， N CRM2 2 C rash
故障分析
full picture
2023-11-05 15:05:00 节点 1 开始出现 IP fragments dropped
2023-11-05 16:17:09 udp overflow 29741 to 231111
2023-11-05 16:18:08 LCK1 (ospid: 11324) waits for event
~16:20:29 'libcache interrupt action by LCK' for 216 secs <<<<< 16:20:29 减去 216 秒为 16:16:53 约为网络 udp overflow 的时间点。
2023-11-05 16:22:39 节点 1 LMD0 (ospid: 16620) has detected no messaging activity from instance 2 。
2023-11-05 16:22:57 节点 1 IPC Send timeout detected. Sender: ospid 16620 。
2023-11-05 16:24:10 节点 1 ： Reconfiguration started (old inc 4, new inc 8) 。
2023-11-05 16:24:11 节点 2 ： Instance terminated by LMSh, pid = 11314 。
2023-11-05 16:23:14 Initiating reconfig, reason=3 。
2023-11-05 16:24:39 Reconfiguration complete (total time 28.5 secs) .
2 、 osw 分析
N etstat 中在故障时间点存在严重的 UDP socket overflows ：
详细数据 …… 6:14:08 udp: 29741 socket overflows 16:14:38 udp: 29741 socket overflows 16:15:08 udp: 29741 socket overflows 16:15:38 udp: 29741 socket overflows 16:16:08 udp: 29741 socket overflows 16:16:38 udp: 29741 socket overflows 16:17:09 udp: 231111 socket overflows 16:17:39 udp: 231114 socket overflows 16:18:09 udp: 231121 socket overflows 16:18:39 udp: 231121 socket overflows 16:19:09 udp: 231121 socket overflows 16:19:39 udp: 231121 socket overflows 16:20:10 udp: 231121 socket overflows ……
3 、 A lert log
节点2的LCK1 hung了216秒，之后crash ； 节点1检测到之后，发起reconfiguration
节点 1： …… Thu Nov 05 16:22:39 2023 LMD0 (ospid: 16620) has detected no messaging activity from instance 2 Thu Nov 05 16:22:57 2023 IPC Send timeout detected. Sender: ospid 16620 [oracle@ncrmdb21 (LMD0)] Receiver: inst 2 binc 1349400 ospid 165544 Thu Nov 05 16:23:14 2023 Errors in file /oracle/app/oracle/diag/rdbms/ncrmdb2/crmdb21/trace/crmdb21_lmd0_16620.trc: ORA-27508: IPC error sending a message Thu Nov 05 16:23:14 2023 IPC Send timeout to 2.0 inc 4 for msg type 65518 from opid 14 Thu Nov 05 16:23:14 2023 Communications reconfiguration: instance_number 2 by ospid 16620 Thu Nov 05 16:24:03 2023 Detected an inconsistent instance membership by instance 1 Evicting instance 2 from cluster Waiting for instances to leave: 2 Thu Nov 05 16:24:10 2023 Reconfiguration started (old inc 4, new inc 8) List of instances (total 1) : 1 Dead instances (total 1) : 2 My inst 1 ……
节点 2 ： …… Thu Nov 05 16:18:08 2023 LCK1 (ospid: 11324) waits for event 'libcache interrupt action by LCK' for 75 secs. Thu Nov 05 16:18:08 2023 LCK1 (ospid: 11324) is hung in an acceptable location (libcache 0x41.02). Thu Nov 05 16:20:29 2023 LCK1 (ospid: 11324) waits for event 'libcache interrupt action by LCK' for 216 secs. Thu Nov 05 16:20:29 2023 LCK1 (ospid: 11324) is hung in an acceptable location (libcache 0x41.02). Thu Nov 05 16:24:03 2023 Detected an inconsistent instance membership by instance 1 Thu Nov 05 16:24:04 2023 Received an instance abort message from instance 1 Thu Nov 05 16:21:02 2023 opiodr aborting process unknown ospid (20468) as a result of ORA-609 Thu Nov 05 16:22:39 2023 LMD0 (ospid: 16620) has detected no messaging activity from instance 2 Thu Nov 05 16:22:57 2023 IPC Send timeout detected. Sender: ospid 16620 [oracle@ncrmdb21 (LMD0)] Receiver: inst 2 binc 1349400 ospid 165544 Thu Nov 05 16:23:14 2023 Errors in file /oracle/app/oracle/diag/rdbms/ncrmdb2/crmdb21/trace/crmdb21_lmd0_16620.trc: ORA-27508: IPC error sending a message Thu Nov 05 16:23:14 2023 IPC Send timeout to 2.0 inc 4 for msg type 65518 from opid 14 Thu Nov 05 16:23:14 2023 Communications reconfiguration: instance_number 2 by ospid 16620 Thu Nov 05 16:24:03 2023 Detected an inconsistent instance membership by instance 1 Evicting instance 2 from cluster Waiting for instances to leave: 2 …… Thu Nov 05 16:24:04 2023 LMSh (ospid: 11314): terminating the instance due to error 481 ……
ashdump 分析
（ 1 ）故障时间点的 ashdump 存在缺失，数据库整体 hang ：
5. Lmon trace
lmon trace中显示reson为3(reconflguration reason is 3 - which suggested a communication issue) …… *** 2023-11-05 16:23:14.943 2023-11-05 16:23:14.943607 : kjxgrrcfg: done (device ok) - ret = 3 hist 0x1679a (initial rsn: 3, cachd rsn: 0) kjxgrrcfgchk: Initiating reconfig, reason=3 kjxgrrcfgchk: COMM rcfg - Disk Vote Required kjfmReceiverHealthCB_CheckAll: Recievers are healthy. 2023-11-05 16:23:14.943885 : kjxgrnetchk: start 0x8c02716f, end 0x8c0327b9 2023-11-05 16:23:14.943901 : kjxgrnetchk: Network Validation wait: 46 sec kjxgrnetchk: ce-event: from inst 1 to inst 2 ver 0x149939 kjxgrrcfgchk: prev pstate 6 mapsz 512 kjxgrrcfgchk: new bmp: 1 2 kjxgrrcfgchk: work bmp: 1 2 kjxgrrcfgchk: rr bmp: 1 2 ……
官方解释：
Reason 0 = No reconfiguration
Reason 1 = The Node Monitor generated the reconfiguration.
Reason 2 = An instance death was detected.
Reason 3 = Communications Failure
Reason 4 = Reconfiguration after suspend
Reason 3: Communications Failure. This can happen if:
a) The LMON processes lose communication between one another.
b) One instance loses communications with the LMS, LMD, process of another instance.
c) The LCK processes lose communication between one another.
d) A process like LMON, LMD, LMS, or LCK is blocked, spinning, or stuck and is not responding to remote requests.
分析结果
本次节点 2的crash是因为 IPC Send timeout 导致，而IPC Send timeout又和主机上的UDP socket overflows激增的时间点匹配，判断为网络上的UDP socket overflows导致节点驱逐。
