BFD fails when running over OSPF unnumbered interfaces in a non-default VRF

lynnemorrison commented 8 months ago

Describe the bug

We have run into an issue running BFD on OSPF unnumbered interfaces in a VRF. The problem that we see is that the packets aren't sent on the specific interface, but rather are routed. So, if there is an alternate path with lower cost, the packets take that path. This (understandably) confuses BFD, and in some cases we get no BFD peers ever coming up, and in other cases we get peers flapping. It's clear that for unnumbered interfaces, BFD has to send the packet on the specific interface, rather than allowing it to be routed.

If running BFD on OSPF unnumbered interfaces in default VRF traffic passes correctly on the expected interfaces and the BFD session come up.

[x ] Did you check if this is a duplicate issue?
[x ] Did you test it on the latest FRRouting/frr master branch?

To Reproduce I created a topotest scenario to setup an environment to cause the failure: https://github.com/FRRouting/frr/pull/15048

This scenario has three FRR routers in a VRF called Test. The OSPF cost between R1-R2 is 50, where the cost between R1-R3 is 20. All BFD traffic is sent over the R1-R3 link.

If you run this scenario and look for bfd peers on R1 you will see one BFD session down and one up. The BFD session that is supposed to run over r1-eth1 interface is down as it has a higher OSPF cost and the BFD packets for link r1-r2 are incorrectly sent over r1-eth2.

Running tcpdump -ni r1-eth1 you will only see OSPF packets Running tcpdump -ni r1-eth2 you will see OSPF packets and all BFD packets for both peers

When running in VRF we are learning both 2.2.2.2 and 3.3.3.3 over r1-eth2 as it has the lower OSPF cost. Obviously with these routes, BFD will be sent on the wrong interface.

r1# do show ip route vrf Test
Codes: K - kernel route, C - connected, L - local, S - static,
       R - RIP, O - OSPF, I - IS-IS, B - BGP, E - EIGRP, N - NHRP,
       T - Table, v - VNC, V - VNC-Direct, A - Babel, F - PBR,
       f - OpenFabric, t - Table-Direct,
       > - selected route, * - FIB route, q - queued, r - rejected, b - backup
       t - trapped, o - offload failure
VRF Test:
L * 1.1.1.1/32 is directly connected, r1-eth1, 00:00:43
C * 1.1.1.1/32 is directly connected, r1-eth1, 00:00:43
L * 1.1.1.1/32 is directly connected, r1-eth2, 00:00:43
C * 1.1.1.1/32 is directly connected, r1-eth2, 00:00:43
O   1.1.1.1/32 [110/0] is directly connected, Test, weight 1, 00:00:43
L * 1.1.1.1/32 is directly connected, Test, 00:00:43
C>* 1.1.1.1/32 is directly connected, Test, 00:00:43
O>* 2.2.2.2/32 [110/40] via 3.3.3.3, r1-eth2 onlink, weight 1, 00:00:21
O>* 3.3.3.3/32 [110/20] via 3.3.3.3, r1-eth2 onlink, weight 1, 00:00:25

Running in the same test environment but removing VRF Test I see a routing table that I don't understand, but makes BFD work correctly. My question is on the 2.2.2.2 and 3.3.3.3 routes why wouldn't they both have OSPF cost like in the Test VRF? Is this something special because of unnumbered interfaces? I would think that we would learn to reach 3.3.3.3 via rt1-eth0 as the OSPF cost would be lower. But with these routes BFD packets are sent on the correct interfaces.

rt1# do show ip route
Codes: K - kernel route, C - connected, L - local, S - static,
       R - RIP, O - OSPF, I - IS-IS, B - BGP, E - EIGRP, N - NHRP,
       T - Table, v - VNC, V - VNC-Direct, A - Babel, F - PBR,
       f - OpenFabric, t - Table-Direct,
       > - selected route, * - FIB route, q - queued, r - rejected, b - backup
       t - trapped, o - offload failure
O   1.1.1.1/32 [110/0] is directly connected, lo, weight 1, 00:08:10
L * 1.1.1.1/32 is directly connected, rt1-eth1, 00:08:10
C * 1.1.1.1/32 is directly connected, rt1-eth1, 00:08:10
L * 1.1.1.1/32 is directly connected, rt1-eth0, 00:08:10
C * 1.1.1.1/32 is directly connected, rt1-eth0, 00:08:10
L * 1.1.1.1/32 is directly connected, lo, 00:08:10
C>* 1.1.1.1/32 is directly connected, lo, 00:08:10
O>* 2.2.2.2/32 [110/10] via 2.2.2.2, rt1-eth0 onlink, weight 1, 00:07:58
O>* 3.3.3.3/32 [110/50] via 3.3.3.3, rt1-eth1 onlink, weight 1, 00:07:58

Versions OS Version: Ubuntu 20.04.5 LTS Kernel: 5.15.91 FRR Version: 9.1

Additional context We have tried debugging this issue and adding logs and Socket options to make sure that FRR is attempting to send BFD packets out correct interfaces.

2024/01/03 13:00:17.659761 BFD: [T2RS6-ZKJ87] _ptm_bfd_send: sending to r1-eth1 (index 3) dst 2.2.2.2 src 0.0.0.0 sd 27
2024/01/03 13:00:17.659833 BFD: [T2RS6-ZKJ87] _ptm_bfd_send: sending to r1-eth2 (index 4) dst 3.3.3.3 src 1.1.1.1 sd 29

Different socket options have been tried to see if we are incorrectly setting them but I've not been able to fix this issue. And it seems more of an issue on how the routes are installed in the kernel.

in bp_peer_socket(const struct bfd_session *bs)
...
#ifdef SO_BINDTODEVICE
    int ret = 0;
    frr_with_privs(&bglobal.bfdd_privs) {
        zlog_warn("!!!! BINDTODEVICE iface %s", bs->ifp->name);
        ret = setsockopt(sd, SOL_SOCKET, SO_BINDTODEVICE, bs->ifp->name,
                 strlen(bs->ifp->name));
        zlog_warn("!!!! ret %d sd %d", ret, sd);
    }
#endif

lynnemorrison commented 8 months ago

zebra logs for default VRF for adding 2.2.2.2/32 and 3.3.3.3/32 routes:

2024/01/15 13:04:07.525403 ZEBRA: [HT241-2F7BY] zread_route_add: p=(0:0)2.2.2.2/32, msg flags=0x5, flags=0x0
2024/01/15 13:04:07.525406 ZEBRA: [QTHVB-8XP01] nexthop_from_zapi: nh=2.2.2.2, vrf_id=0, ifindex=2
2024/01/15 13:04:07.525410 ZEBRA: [NFFEX-16SYW] zapi_read_nexthops: nh=2.2.2.2 if 2, vrf_id=0 
2024/01/15 13:04:07.525416 ZEBRA: [HT241-2F7BY] zread_route_add: p=(0:0)3.3.3.3/32, msg flags=0x5, flags=0x0
2024/01/15 13:04:07.525417 ZEBRA: [QTHVB-8XP01] nexthop_from_zapi: nh=3.3.3.3, vrf_id=0, ifindex=3
2024/01/15 13:04:07.525417 ZEBRA: [NFFEX-16SYW] zapi_read_nexthops: nh=3.3.3.3 if 3, vrf_id=0 
2024/01/15 13:04:07.536942 ZEBRA: [MFYWV-KH3MC] process_subq_early_route_add: (0:?):2.2.2.2/32: Inserting route rn 0x563714a38760, re 0x563714c00fe0 (ospf) existing 0x0, same_count 0
2024/01/15 13:04:07.537076 ZEBRA: [MFYWV-KH3MC] process_subq_early_route_add: (0:?):3.3.3.3/32: Inserting route rn 0x563714a38840, re 0x563714a37f40 (ospf) existing 0x0, same_count 0
2024/01/15 13:04:07.537083 ZEBRA: [ZFRN1-EZNJZ] default(0:254):2.2.2.2/32: Adding route rn 0x563714a38760, re 0x563714c00fe0 (ospf)
2024/01/15 13:04:07.537138 ZEBRA: [ZFRN1-EZNJZ] default(0:254):3.3.3.3/32: Adding route rn 0x563714a38840, re 0x563714a37f40 (ospf)
2024/01/15 13:04:07.537186 ZEBRA: [YXCJP-0WZWV] netlink_nexthop_msg_encode: ID (15): 2.2.2.2, via rt1-eth0(2) vrf default(0)  
2024/01/15 13:04:07.537191 ZEBRA: [R43C6-KYHWT] netlink_nexthop_msg_encode: RTM_NEWNEXTHOP, id=15
2024/01/15 13:04:07.537192 ZEBRA: [YXPF5-B2CE0] netlink_route_multipath_msg_encode: RTM_NEWROUTE 2.2.2.2/32 vrf 0(254)
2024/01/15 13:04:07.537194 ZEBRA: [J87BH-XW5PP] netlink_route_multipath_msg_encode: 2.2.2.2/32 nhg_id is 15
2024/01/15 13:04:07.537194 ZEBRA: [YXCJP-0WZWV] netlink_nexthop_msg_encode: ID (16): 3.3.3.3, via rt1-eth1(3) vrf default(0)  
2024/01/15 13:04:07.537195 ZEBRA: [R43C6-KYHWT] netlink_nexthop_msg_encode: RTM_NEWNEXTHOP, id=16
2024/01/15 13:04:07.537195 ZEBRA: [YXPF5-B2CE0] netlink_route_multipath_msg_encode: RTM_NEWROUTE 3.3.3.3/32 vrf 0(254)
2024/01/15 13:04:07.537196 ZEBRA: [J87BH-XW5PP] netlink_route_multipath_msg_encode: 3.3.3.3/32 nhg_id is 16
2024/01/15 13:04:07.537196 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=200, msg cnt=4
2024/01/15 13:04:07.537275 ZEBRA: [TS3SH-1276M] default(0:254):2.2.2.2/32 update_from_ctx(): no fib nhg
2024/01/15 13:04:07.537278 ZEBRA: [HKQXC-4STSK] default(0:254):2.2.2.2/32 update_from_ctx(): rib nhg matched, changed 'true'
2024/01/15 13:04:07.537279 ZEBRA: [Z1MP1-RFGJA] (0:254):2.2.2.2/32(0): Redist update re 0x563714c00fe0 (ospf), old 0x0 (None)
2024/01/15 13:04:07.537282 ZEBRA: [TQKA8-0276P] Not Notifying Owner: ospf about prefix 2.2.2.2/32(254) 2 vrf: 0
2024/01/15 13:04:07.537284 ZEBRA: [TS3SH-1276M] default(0:254):3.3.3.3/32 update_from_ctx(): no fib nhg
2024/01/15 13:04:07.537285 ZEBRA: [HKQXC-4STSK] default(0:254):3.3.3.3/32 update_from_ctx(): rib nhg matched, changed 'true'
2024/01/15 13:04:07.537285 ZEBRA: [Z1MP1-RFGJA] (0:254):3.3.3.3/32(0): Redist update re 0x563714a37f40 (ospf), old 0x0 (None)
2024/01/15 13:04:07.537286 ZEBRA: [TQKA8-0276P] Not Notifying Owner: ospf about prefix 3.3.3.3/32(254) 2 vrf: 0

nexthop table for default VRF:

ip nexthop show
id 4 dev rt1-eth1 scope link proto zebra 
id 5 dev rt1-eth0 scope link proto zebra 
id 6 dev lo scope link proto zebra 
id 10 dev rt1-eth0 scope link proto zebra 
id 15 via 2.2.2.2 dev rt1-eth0 scope link proto zebra onlink 
id 16 via 3.3.3.3 dev rt1-eth1 scope link proto zebra onlink

zebra logs for Test VRF adding 2.2.2.2/32 and 3.3.3.3/32 routes:

2024/01/15 15:51:52.630562 ZEBRA: [V3DSZ-Y9H3W] Read 4 packets from client: ospf
2024/01/15 15:51:52.630687 ZEBRA: [G37DH-KRAE9] bfd_dst_register msg from client ospf: length=37
2024/01/15 15:51:52.630807 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) Neigh 2.2.2.2 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:51:52.630811 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) Neigh 2.2.2.2 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:51:52.630812 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) Neigh 2.2.2.2 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:51:52.630813 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=192, msg cnt=3
2024/01/15 15:51:52.632061 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REPLAY:5:35] comes from socket [38]
2024/01/15 15:51:52.632091 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: bfd
2024/01/15 15:51:52.632117 ZEBRA: [V0KXZ-QFE4D] bfd_dst_update msg from client bfd: length=25
2024/01/15 15:51:53.749612 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_NEIGH_DISCOVER:5:20] comes from socket [33]
2024/01/15 15:51:53.749616 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_NEIGH_DISCOVER:5:20] comes from socket [33]
2024/01/15 15:51:53.749618 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REGISTER:5:47] comes from socket [33]
2024/01/15 15:51:53.749629 ZEBRA: [V3DSZ-Y9H3W] Read 3 packets from client: ospf
2024/01/15 15:51:53.749792 ZEBRA: [G37DH-KRAE9] bfd_dst_register msg from client ospf: length=37
2024/01/15 15:51:53.749876 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_NEIGH_DISCOVER:5:20] comes from socket [33]
2024/01/15 15:51:53.749884 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:51:53.749869 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth2(4) Neigh 3.3.3.3 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:51:53.749873 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth2(4) Neigh 3.3.3.3 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:51:53.749874 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=128, msg cnt=2
2024/01/15 15:51:53.749984 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth2(4) Neigh 3.3.3.3 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:51:53.749986 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=64, msg cnt=1
2024/01/15 15:51:53.750269 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REPLAY:5:35] comes from socket [38]
2024/01/15 15:51:53.750278 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: bfd
2024/01/15 15:51:53.750353 ZEBRA: [V0KXZ-QFE4D] bfd_dst_update msg from client bfd: length=25
2024/01/15 15:51:53.800638 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_ROUTE_ADD:5:48] comes from socket [33]
2024/01/15 15:51:53.800659 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:51:53.800798 ZEBRA: [HT241-2F7BY] zread_route_add: p=(5:0)2.2.2.2/32, msg flags=0x5, flags=0x0
2024/01/15 15:51:53.800807 ZEBRA: [QTHVB-8XP01] nexthop_from_zapi: nh=2.2.2.2, vrf_id=5, ifindex=3
2024/01/15 15:51:53.800812 ZEBRA: [NFFEX-16SYW] zapi_read_nexthops: nh=2.2.2.2 if 3, vrf_id=5 
2024/01/15 15:51:53.812497 ZEBRA: [MFYWV-KH3MC] process_subq_early_route_add: (5:?):2.2.2.2/32: Inserting route rn 0x55fec2e6b110, re 0x55fec2e36920 (ospf) existing 0x0, same_count 0
2024/01/15 15:51:53.812520 ZEBRA: [ZFRN1-EZNJZ] Test(5:11):2.2.2.2/32: Adding route rn 0x55fec2e6b110, re 0x55fec2e36920 (ospf)
2024/01/15 15:51:53.812667 ZEBRA: [YXCJP-0WZWV] netlink_nexthop_msg_encode: ID (16): 2.2.2.2, via r1-eth1(3) vrf Test(5)  

2024/01/15 15:51:53.812675 ZEBRA: [R43C6-KYHWT] netlink_nexthop_msg_encode: RTM_NEWNEXTHOP, id=16

2024/01/15 15:51:53.812677 ZEBRA: [YXPF5-B2CE0] netlink_route_multipath_msg_encode: RTM_NEWROUTE 2.2.2.2/32 vrf 5(11)
2024/01/15 15:51:53.812680 ZEBRA: [J87BH-XW5PP] netlink_route_multipath_msg_encode: 2.2.2.2/32 nhg_id is 16
2024/01/15 15:51:53.812681 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=100, msg cnt=2
2024/01/15 15:51:53.812910 ZEBRA: [TS3SH-1276M] Test(5:11):2.2.2.2/32 update_from_ctx(): no fib nhg
2024/01/15 15:51:53.812918 ZEBRA: [HKQXC-4STSK] Test(5:11):2.2.2.2/32 update_from_ctx(): rib nhg matched, changed 'true'
2024/01/15 15:51:53.812920 ZEBRA: [Z1MP1-RFGJA] (5:11):2.2.2.2/32(0): Redist update re 0x55fec2e36920 (ospf), old 0x0 (None)
2024/01/15 15:51:53.812925 ZEBRA: [TQKA8-0276P] Not Notifying Owner: ospf about prefix 2.2.2.2/32(11) 2 vrf: 5
2024/01/15 15:51:53.988057 ZEBRA: [WPPMZ-G9797] if_zebra_speed_update: r1-eth1 old speed: 0 new speed: 10000
2024/01/15 15:51:53.988064 ZEBRA: [R0MNE-C165S] MESSAGE: ZEBRA_INTERFACE_ADD r1-eth1 vrf Test(5)
2024/01/15 15:51:53.988096 ZEBRA: [SPGA0-07CWN] interface r1-eth1 vrf Test(5) index 3 is added.
2024/01/15 15:51:53.988133 ZEBRA: [WPPMZ-G9797] if_zebra_speed_update: r1-eth2 old speed: 0 new speed: 10000
2024/01/15 15:51:53.988134 ZEBRA: [R0MNE-C165S] MESSAGE: ZEBRA_INTERFACE_ADD r1-eth2 vrf Test(5)
2024/01/15 15:51:53.988167 ZEBRA: [SPGA0-07CWN] interface r1-eth2 vrf Test(5) index 4 is added.
2024/01/15 15:51:54.442858 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REPLAY:5:35] comes from socket [38]
2024/01/15 15:51:54.442872 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: bfd
2024/01/15 15:51:54.442907 ZEBRA: [V0KXZ-QFE4D] bfd_dst_update msg from client bfd: length=25
2024/01/15 15:51:57.761942 ZEBRA: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_NEWNEIGH(28), len=84, seq=0, pid=0
2024/01/15 15:51:57.761950 ZEBRA: [TDS34-MNEJW]     Neighbor Entry received is not on a VLAN or a BRIDGE, ignoring
2024/01/15 15:51:57.761953 ZEBRA: [KKAC1-JMWTB] Rx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) vrf Test(5) IP 2.2.2.2 MAC 5a:ae:43:ad:40:6a state 0x10 flags 0x0 ext_flags 0x0
2024/01/15 15:51:57.761957 ZEBRA: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_NEWNEIGH(28), len=84, seq=0, pid=0
2024/01/15 15:51:57.761958 ZEBRA: [TDS34-MNEJW]     Neighbor Entry received is not on a VLAN or a BRIDGE, ignoring
2024/01/15 15:51:57.761958 ZEBRA: [KKAC1-JMWTB] Rx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) vrf Test(5) IP 2.2.2.2 MAC 5a:ae:43:ad:40:6a state 0x2 flags 0x0 ext_flags 0x0
2024/01/15 15:51:58.751061 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_ROUTE_ADD:5:48] comes from socket [33]
2024/01/15 15:51:58.751074 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:51:58.751124 ZEBRA: [HT241-2F7BY] zread_route_add: p=(5:0)3.3.3.3/32, msg flags=0x5, flags=0x0
2024/01/15 15:51:58.751129 ZEBRA: [QTHVB-8XP01] nexthop_from_zapi: nh=3.3.3.3, vrf_id=5, ifindex=4
2024/01/15 15:51:58.751132 ZEBRA: [NFFEX-16SYW] zapi_read_nexthops: nh=3.3.3.3 if 4, vrf_id=5 
2024/01/15 15:51:58.761146 ZEBRA: [MFYWV-KH3MC] process_subq_early_route_add: (5:?):3.3.3.3/32: Inserting route rn 0x55fec2e6cbc0, re 0x55fec2e367e0 (ospf) existing 0x0, same_count 0
2024/01/15 15:51:58.761154 ZEBRA: [ZFRN1-EZNJZ] Test(5:11):3.3.3.3/32: Adding route rn 0x55fec2e6cbc0, re 0x55fec2e367e0 (ospf)
2024/01/15 15:51:58.761231 ZEBRA: [YXCJP-0WZWV] netlink_nexthop_msg_encode: ID (18): 3.3.3.3, via r1-eth2(4) vrf Test(5)  
2024/01/15 15:51:58.761235 ZEBRA: [R43C6-KYHWT] netlink_nexthop_msg_encode: RTM_NEWNEXTHOP, id=18
2024/01/15 15:51:58.761236 ZEBRA: [YXPF5-B2CE0] netlink_route_multipath_msg_encode: RTM_NEWROUTE 3.3.3.3/32 vrf 5(11)
2024/01/15 15:51:58.761237 ZEBRA: [J87BH-XW5PP] netlink_route_multipath_msg_encode: 3.3.3.3/32 nhg_id is 18
2024/01/15 15:51:58.761238 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=100, msg cnt=2
2024/01/15 15:51:58.761297 ZEBRA: [TS3SH-1276M] Test(5:11):3.3.3.3/32 update_from_ctx(): no fib nhg
2024/01/15 15:51:58.761300 ZEBRA: [HKQXC-4STSK] Test(5:11):3.3.3.3/32 update_from_ctx(): rib nhg matched, changed 'true'
2024/01/15 15:51:58.761301 ZEBRA: [Z1MP1-RFGJA] (5:11):3.3.3.3/32(0): Redist update re 0x55fec2e367e0 (ospf), old 0x0 (None)
2024/01/15 15:51:58.761303 ZEBRA: [TQKA8-0276P] Not Notifying Owner: ospf about prefix 3.3.3.3/32(11) 2 vrf: 5
2024/01/15 15:51:58.787194 ZEBRA: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_NEWNEIGH(28), len=84, seq=0, pid=0
2024/01/15 15:51:58.787202 ZEBRA: [TDS34-MNEJW]     Neighbor Entry received is not on a VLAN or a BRIDGE, ignoring
2024/01/15 15:51:58.787205 ZEBRA: [KKAC1-JMWTB] Rx RTM_NEWNEIGH family ipv4 IF r1-eth2(4) vrf Test(5) IP 3.3.3.3 MAC c2:78:dc:a9:22:39 state 0x10 flags 0x0 ext_flags 0x0
2024/01/15 15:51:58.787209 ZEBRA: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_NEWNEIGH(28), len=84, seq=0, pid=0
2024/01/15 15:51:58.787210 ZEBRA: [TDS34-MNEJW]     Neighbor Entry received is not on a VLAN or a BRIDGE, ignoring
2024/01/15 15:51:58.787210 ZEBRA: [KKAC1-JMWTB] Rx RTM_NEWNEIGH family ipv4 IF r1-eth2(4) vrf Test(5) IP 3.3.3.3 MAC c2:78:dc:a9:22:39 state 0x2 flags 0x0 ext_flags 0x0
2024/01/15 15:51:59.114277 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REPLAY:5:35] comes from socket [38]
2024/01/15 15:51:59.114288 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: bfd
2024/01/15 15:51:59.114324 ZEBRA: [V0KXZ-QFE4D] bfd_dst_update msg from client bfd: length=25
2024/01/15 15:51:59.528946 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REPLAY:5:35] comes from socket [38]
2024/01/15 15:51:59.528956 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: bfd
2024/01/15 15:51:59.529001 ZEBRA: [V0KXZ-QFE4D] bfd_dst_update msg from client bfd: length=25
2024/01/15 15:51:59.529945 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_DEREGISTER:5:47] comes from socket [33]
2024/01/15 15:51:59.529951 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:51:59.529993 ZEBRA: [T4P6D-CDT49] bfd_dst_deregister msg from client ospf: length=37
2024/01/15 15:51:59.530037 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_ROUTE_DELETE:5:28] comes from socket [33]
2024/01/15 15:51:59.530040 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:51:59.530058 ZEBRA: [HT241-2F7BY] zread_route_del: p=(5:11)2.2.2.2/32, msg flags=0x0, flags=0x0
2024/01/15 15:51:59.540108 ZEBRA: [QE6V0-J8BG5] rib_delnode: (5:11):2.2.2.2/32: rn 0x55fec2e6b110, re 0x55fec2e36920, removing
2024/01/15 15:51:59.540117 ZEBRA: [XRK1F-B5A0E] (5:11):2.2.2.2/32: Redist del: re 0x55fec2e36920 (0:ospf), new re 0x0 (0:None)
2024/01/15 15:51:59.540120 ZEBRA: [S59C1-4C5PP] Test(5:11):2.2.2.2/32: Deleting route rn 0x55fec2e6b110, re 0x55fec2e36920 (ospf)
2024/01/15 15:51:59.540133 ZEBRA: [NM15X-X83N9] rib_process: (5:11):2.2.2.2/32: rn 0x55fec2e6b110, removing re 0x55fec2e36920
2024/01/15 15:51:59.540134 ZEBRA: [Y53JX-CBC5H] rib_unlink: (5:11):2.2.2.2/32: rn 0x55fec2e6b110, re 0x55fec2e36920
2024/01/15 15:51:59.540137 ZEBRA: [KT8QQ-45WQ0] rib_gc_dest: (5:?):2.2.2.2/32: removing dest from table
2024/01/15 15:51:59.540171 ZEBRA: [YXPF5-B2CE0] netlink_route_multipath_msg_encode: RTM_DELROUTE 2.2.2.2/32 vrf 5(11)
2024/01/15 15:51:59.540173 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=44, msg cnt=1
2024/01/15 15:51:59.540279 ZEBRA: [TQKA8-0276P] Not Notifying Owner: ospf about prefix 2.2.2.2/32(11) 3 vrf: 5
2024/01/15 15:52:02.627930 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_NEIGH_DISCOVER:5:20] comes from socket [33]
2024/01/15 15:52:02.627934 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_NEIGH_DISCOVER:5:20] comes from socket [33]
2024/01/15 15:52:02.627936 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REGISTER:5:47] comes from socket [33]
2024/01/15 15:52:02.627944 ZEBRA: [V3DSZ-Y9H3W] Read 3 packets from client: ospf
2024/01/15 15:52:02.627994 ZEBRA: [G37DH-KRAE9] bfd_dst_register msg from client ospf: length=37
2024/01/15 15:52:02.628040 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) Neigh 2.2.2.2 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:52:02.628045 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) Neigh 2.2.2.2 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:52:02.628046 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=128, msg cnt=2
2024/01/15 15:52:02.628211 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_BFD_DEST_REPLAY:5:35] comes from socket [38]
2024/01/15 15:52:02.628214 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: bfd
2024/01/15 15:52:02.628234 ZEBRA: [V0KXZ-QFE4D] bfd_dst_update msg from client bfd: length=25
2024/01/15 15:52:02.628255 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_NEIGH_DISCOVER:5:20] comes from socket [33]
2024/01/15 15:52:02.628258 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:52:02.628317 ZEBRA: [NH6N7-54CD1] Tx RTM_NEWNEIGH family ipv4 IF r1-eth1(3) Neigh 2.2.2.2 MAC null flags 0x1 state 0x1 ext ext_flags 0x0
2024/01/15 15:52:02.628320 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=64, msg cnt=1
2024/01/15 15:52:02.628860 ZEBRA: [YXG8K-BCYMV] zebra message[ZEBRA_ROUTE_ADD:5:48] comes from socket [33]
2024/01/15 15:52:02.628865 ZEBRA: [V3DSZ-Y9H3W] Read 1 packets from client: ospf
2024/01/15 15:52:02.628890 ZEBRA: [HT241-2F7BY] zread_route_add: p=(5:0)2.2.2.2/32, msg flags=0x5, flags=0x0
2024/01/15 15:52:02.628894 ZEBRA: [QTHVB-8XP01] nexthop_from_zapi: nh=3.3.3.3, vrf_id=5, ifindex=4
2024/01/15 15:52:02.628897 ZEBRA: [NFFEX-16SYW] zapi_read_nexthops: nh=3.3.3.3 if 4, vrf_id=5 
2024/01/15 15:52:02.639692 ZEBRA: [MFYWV-KH3MC] process_subq_early_route_add: (5:?):2.2.2.2/32: Inserting route rn 0x55fec2e34c00, re 0x55fec2e36b80 (ospf) existing 0x0, same_count 0
2024/01/15 15:52:02.639705 ZEBRA: [ZFRN1-EZNJZ] Test(5:11):2.2.2.2/32: Adding route rn 0x55fec2e34c00, re 0x55fec2e36b80 (ospf)
2024/01/15 15:52:02.639741 ZEBRA: [YXPF5-B2CE0] netlink_route_multipath_msg_encode: RTM_NEWROUTE 2.2.2.2/32 vrf 5(11)
2024/01/15 15:52:02.639743 ZEBRA: [J87BH-XW5PP] netlink_route_multipath_msg_encode: 2.2.2.2/32 nhg_id is 18
2024/01/15 15:52:02.639743 ZEBRA: [HYEHE-CQZ9G] nl_batch_send: netlink-dp (NS 0), batch size=52, msg cnt=1
2024/01/15 15:52:02.639780 ZEBRA: [TS3SH-1276M] Test(5:11):2.2.2.2/32 update_from_ctx(): no fib nhg
2024/01/15 15:52:02.639782 ZEBRA: [HKQXC-4STSK] Test(5:11):2.2.2.2/32 update_from_ctx(): rib nhg matched, changed 'false'
2024/01/15 15:52:02.639783 ZEBRA: [Z1MP1-RFGJA] (5:11):2.2.2.2/32(0): Redist update re 0x55fec2e36b80 (ospf), old 0x0 (None)
2024/01/15 15:52:02.639786 ZEBRA: [TQKA8-0276P] Not Notifying Owner: ospf about prefix 2.2.2.2/32(11) 2 vrf: 5

nh table for VRF Test:

ip nexthop show
id 3 dev r1-eth0 scope link proto zebra 
id 4 dev r1-eth1 scope link proto zebra 
id 6 dev r1-eth2 scope link proto zebra 
id 12 dev Test scope link proto zebra 
id 16 via 2.2.2.2 dev r1-eth1 scope link proto zebra onlink 
id 18 via 3.3.3.3 dev r1-eth2 scope link proto zebra onlink 

ip nexthop show vrf Test
id 4 dev r1-eth1 scope link proto zebra 
id 6 dev r1-eth2 scope link proto zebra 
id 18 via 3.3.3.3 dev r1-eth2 scope link proto zebra onlink

Should there be two nexthops in the VRF Test? In the logs above we add route 2.2.2.2/32 and then deleted it and add it again with different nexthop id

github-actions[bot] commented 2 months ago

This issue is stale because it has been open 180 days with no activity. Comment or remove the autoclose label in order to avoid having this issue closed.

frrbot[bot] commented 2 months ago

This issue will be automatically closed in the specified period unless there is further activity.

FRRouting / frr

BFD fails when running over OSPF unnumbered interfaces in a non-default VRF #15099