某局点高端防火墙OSPF邻居震荡问题排查

不涉及

不涉及

防火墙对接友商设备某一个业务接口OSPF以及OSPFv3邻居不定时震荡，日志如下：

【07:37:10:756】%Jan  6 04:31:35:216 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from FULL to INIT.
【07:37:10:756】%Jan  6 04:31:35:225 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from LOADING to FULL.
【07:37:10:756】%Jan  6 04:38:22:018 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from FULL to INIT.
【07:37:10:756】%Jan  6 04:38:46:664 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from LOADING to FULL.
【07:37:10:756】%Jan  6 04:54:18:250 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from FULL to INIT.
【07:37:10:756】%Jan  6 04:54:25:756 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from LOADING to FULL.
【07:37:10:756】%Jan  6 05:01:55:351 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from FULL to INIT.
【07:37:10:756】%Jan  6 05:02:00:673 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from LOADING to FULL.
【07:37:10:756】%Jan  6 05:04:08:777 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGIN: ITCuser logged in from 10.136.128.23.
【07:37:10:756】%Jan  6 05:04:09:992 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/4/SHELL_CMD_MATCHFAIL: -User=ITCuser-IPAddr=10.136.128.23; Command echo $LANG in view shell failed to be matched.
【07:37:10:756】%Jan  6 05:09:42:835 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGOUT: ITCuser logged out from 10.136.128.23.
【07:37:10:756】%Jan  6 05:12:28:235 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPFV3/5/OSPFv3_NBR_CHG: OSPFv3 100 Neighbor 10.139.0.2(Route-Aggregation2) received 1-Way and its state from FULL to INIT.
【07:37:10:756】%Jan  6 05:13:07:218 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPFV3/5/OSPFv3_NBR_CHG: OSPFv3 100 Neighbor 10.139.0.2(Route-Aggregation2) received LoadingDone and its state from LOADING to FULL.
【07:37:10:756】%Jan  6 05:15:22:826 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGIN: ITCuser logged in from 10.136.128.23.
【07:37:10:756】%Jan  6 05:15:24:037 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/4/SHELL_CMD_MATCHFAIL: -User=ITCuser-IPAddr=10.136.128.23; Command echo $LANG in view shell failed to be matched.
【07:37:10:756】%Jan  6 05:23:21:837 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGOUT: ITCuser logged out from 10.136.128.23.
【07:37:10:756】%Jan  6 05:30:28:215 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPFV3/5/OSPFv3_NBR_CHG: OSPFv3 100 Neighbor 10.139.0.2(Route-Aggregation2) received 1-Way and its state from FULL to INIT.
【07:37:10:756】%Jan  6 05:30:37:218 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPFV3/5/OSPFv3_NBR_CHG: OSPFv3 100 Neighbor 10.139.0.2(Route-Aggregation2) received LoadingDone and its state from LOADING to FULL.
【07:37:10:756】%Jan  6 05:41:14:135 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGIN: ITCuser logged in from 10.136.128.23.
【07:37:10:756】%Jan  6 05:41:15:351 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/4/SHELL_CMD_MATCHFAIL: -User=ITCuser-IPAddr=10.136.128.23; Command echo $LANG in view shell failed to be matched.
【07:37:10:756】%Jan  6 05:42:26:304 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/4/SHELL_CMD_MATCHFAIL: -User=ITCuser-IPAddr=10.136.128.23; Command dis ospf event-log  in view shell failed to be matched.
【07:37:10:756】%Jan  6 05:42:43:884 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from FULL to INIT.
【07:37:10:756】%Jan  6 05:43:00:673 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from LOADING to FULL.
【07:37:10:756】%Jan  6 05:51:34:984 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/4/SHELL_CMD_MATCHFAIL: -User=ITCuser-IPAddr=10.136.128.23; Command dis interface  HundredGigE 0/0/26 in view shell failed to be matched.
【07:37:10:756】%Jan  6 05:58:11:204 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGOUT: ITCuser logged out from 10.136.128.23.
【07:37:10:756】%Jan  6 05:58:12:936 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from FULL to INIT.
【07:37:10:756】%Jan  6 05:58:30:672 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPF/5/OSPF_NBR_CHG: OSPF 10 Neighbor 10.139.1.121(Route-Aggregation2) changed from LOADING to FULL.
【07:37:10:756】%Jan  6 06:00:13:308 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGIN: ITCuser logged in from 10.121.4.149.
【07:37:10:756】%Jan  6 06:00:14:568 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGOUT: ITCuser logged out from 10.121.4.149.
【07:37:10:756】%Jan  6 06:01:00:262 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGIN: ITCuser logged in from 10.136.128.23.
【07:37:10:756】%Jan  6 06:01:01:476 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/4/SHELL_CMD_MATCHFAIL: -User=ITCuser-IPAddr=10.136.128.23; Command echo $LANG in view shell failed to be matched.
【07:37:10:756】%Jan  6 06:13:18:165 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPFV3/5/OSPFv3_NBR_CHG: OSPFv3 100 Neighbor 10.139.0.2(Route-Aggregation2) received 1-Way and its state from FULL to INIT.
【07:37:10:756】%Jan  6 06:13:35:352 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 SHELL/5/SHELL_LOGOUT: ITCuser logged out from 10.136.128.23.
【07:37:10:756】%Jan  6 06:13:47:217 2024 JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11 OSPFV3/5/OSPFv3_NBR_CHG: OSPFv3 100 Neighbor 10.139.0.2(Route-Aggregation2) received LoadingDone and its state from LOADING to FULL.

现场要求分析邻居异常中断原因。

收集display ospf event-log peer信息如下：

【08:49:14:308】Date       Time     Local Address   Remote Address  Router ID       Reason
【08:49:14:308】2024-01-06 08:34:49 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:325】2024-01-06 08:19:38 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:325】2024-01-06 07:52:50 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:325】2024-01-06 07:36:47 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:341】2024-01-06 06:28:23 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:341】2024-01-06 06:23:50 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:341】2024-01-06 05:58:12 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:341】2024-01-06 05:42:43 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:361】2024-01-06 05:01:55 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:361】2024-01-06 04:54:18 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
【08:49:14:378】2024-01-06 04:38:22 10.139.1.122    10.139.1.121    10.139.0.2      1-Way
 
【08:49:14:378】2024-01-06 04:31:35 10.139.1.122    10.139.1.121    10.139.0.2      1-Way

可以发现邻居震荡是因为收到对端的1-Way报文导致本端邻居震荡。需要对端分析为何发送1-Way报文。

本端周期发送报文，如下：

【08:48:15:708】
【08:48:15:708】         OSPF Process 10 with Router ID 10.139.0.3
【08:48:15:708】                 Hello Log
【08:48:15:724】
【08:48:15:724】
【08:48:15:724】Interface RAGG2
【08:48:15:724】Neighbor address: 10.139.1.121, NbrID: 10.139.0.2
【08:48:15:724】First 4 hello packets sent:
【08:48:15:724】  2023-09-06 02:00:21:577, succeeded
【08:48:15:724】  2023-09-06 02:00:35:239, succeeded
【08:48:15:724】  2023-09-06 02:00:45:239, succeeded
【08:48:15:755】  2023-09-06 02:00:55:239, succeeded
【08:48:15:758】Last 4 hello packets sent before Full->Init at 2024-01-06 08:34:49:504
【08:48:15:758】  2024-01-06 08:34:10:664, succeeded
【08:48:15:758】  2024-01-06 08:34:20:664, succeeded
【08:48:15:758】  2024-01-06 08:34:30:664, succeeded
【08:48:15:758】  2024-01-06 08:34:40:664, succeeded
 
【08:48:04:670】RBM_P<JNSC-P-PUB-CMNET-H3C-M9016V-1-ITC11>dis ospf event-log hello received
【08:48:04:701】
【08:48:04:733】         OSPF Process 10 with Router ID 10.139.0.3
【08:48:04:733】                 Hello Log
【08:48:04:733】
【08:48:04:733】
【08:48:04:733】Interface RAGG2
【08:48:04:733】Neighbor address: 10.139.1.121, NbrID: 10.139.0.2
【08:48:04:733】First 4 hello packets received:
【08:48:04:733】  2023-09-07 14:41:52:642
【08:48:04:733】  2023-09-07 14:41:52:674
【08:48:04:749】  2023-09-07 14:42:00:142
【08:48:04:749】  2023-09-07 14:42:10:142
【08:48:04:749】Last 4 hello packets received before Full->Init at 2024-01-06 08:34:49:504
【08:48:04:749】  2024-01-06 08:34:26:203
【08:48:04:749】  2024-01-06 08:34:36:202
【08:48:04:749】  2024-01-06 08:34:43:702
【08:48:04:765】  2024-01-06 08:34:49:504

将以上分析同步现场后，协调对端一起查看，对端显示Reason:DeadTimerExpire。

于是建议现场两边同步抓包对比，本端抓包如下：

可以看出10:28:10之前，防火墙hello报文都是10s周期发包，对端10.139.1.121设备给我们发了个DB报文重新主从选举。

分析到现在，问题很明显和对端有关系。但是对端坚持说他们自己的hello报文也是规律发送，未收到华三发送的hello报文。

如果双方均显示正常的话，一般会在中间串一个交换机镜像抓包做仲裁，看到底是谁的问题。可惜客户不同意。

本人不信邪，查看了下对端的日志。疑点有两处：

1. 对端的hello包发送的并不规律，并非10 S一次。

2. 本端发送的Hello报文很有规律，10S一次。

对端答复他们机制就是这样，把我整的很无语。

对端做了接口替换发现接口卡存在故障，更换故障接口卡之后解决。