Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Kernel routes are not updated properly in zebra RIB / nhg nexthop check is wrong #13561

Open
2 tasks done
zdc opened this issue May 19, 2023 · 7 comments
Open
2 tasks done

Kernel routes are not updated properly in zebra RIB / nhg nexthop check is wrong #13561

zdc opened this issue May 19, 2023 · 7 comments
Labels
autoclose zebra

Comments

@zdc
Copy link

zdc commented May 19, 2023

Describe the bug

In certain conditions, kernel routes are not properly updated in zebra, for example when an IP address is flushed from an interface.

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

To Reproduce

Reproducing is really simple:

ip link set dev eth0 up
ip -4 addr add 192.168.0.2/24 dev eth0
ip -4 route add default via 192.168.0.1
ip -4 addr flush dev eth0

After this, the kernel will have no routes, but FRR still has an active default route:

K>* 0.0.0.0/0 [0/0] via 192.168.0.1, eth0, 00:00:07

Logs after ip -4 addr flush dev eth0:

May 19 14:41:28 vyos zebra[3764]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELADDR(21), len=80, seq=1684507290, pid=3800
May 19 14:41:28 vyos zebra[3764]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELROUTE(25), len=60, seq=0, pid=0
May 19 14:41:28 vyos zebra[3764]: [SKNFJ-G938V] RTM_DELROUTE ipv4 unicast proto kernel NS 0
May 19 14:41:28 vyos zebra[3764]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELROUTE(25), len=60, seq=0, pid=0
May 19 14:41:28 vyos zebra[3764]: [SKNFJ-G938V] RTM_DELROUTE ipv4 broadcast proto kernel NS 0
May 19 14:41:28 vyos zebra[3764]: [J3J81-V75NW] Route rtm_type: broadcast(3) intentionally ignoring
May 19 14:41:28 vyos zebra[3764]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELROUTE(25), len=60, seq=0, pid=0
May 19 14:41:28 vyos zebra[3764]: [SKNFJ-G938V] RTM_DELROUTE ipv4 local proto kernel NS 0
May 19 14:41:28 vyos zebra[3764]: [J3J81-V75NW] Route rtm_type: local(2) intentionally ignoring
May 19 14:41:28 vyos zebra[3764]: [K8FXY-V65ZJ] Intf dplane ctx 0x7f4988026dd0, op INTF_ADDR_DEL, ifindex (2), result QUEUED
May 19 14:41:28 vyos zebra[3764]: [MZPZA-W042K] zebra_if_addr_update_ctx: INTF_ADDR_DEL: ifindex eth0(2), addr 192.168.0.2/24
May 19 14:41:28 vyos zebra[3764]: [XN0NB-2NSYE] MESSAGE: ZEBRA_INTERFACE_ADDRESS_DELETE 192.168.0.2/24 on eth0 vrf default(0)
May 19 14:41:28 vyos zebra[3764]: [X55C6-A6ZXJ] Route 192.168.0.0/24(0) queued for processing into sub-queue Early Route Processing
May 19 14:41:28 vyos zebra[3764]: [X55C6-A6ZXJ] Route 192.168.0.0/24(0) queued for processing into sub-queue Early Route Processing
May 19 14:41:28 vyos zebra[3764]: [QQWTF-ZKJDD] rib_update: Scheduled VRF (ALL), event RIB_UPDATE_KERNEL
May 19 14:41:28 vyos zebra[3764]: [M8JMF-J6PZV] rib_update_handle_vrf_all: Handling VRF (ALL) event RIB_UPDATE_KERNEL
May 19 14:41:28 vyos zebra[3764]: [QR5K4-A1079] rib_update_table: IPv4 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:41:28 vyos zebra[3764]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):0.0.0.0/0: queued rn 0x56103e25dcd0 into sub-queue Kernel Routes
May 19 14:41:28 vyos zebra[3764]: [QR5K4-A1079] rib_update_table: IPv4 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:41:28 vyos zebra[3764]: [QR5K4-A1079] rib_update_table: IPv6 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:41:28 vyos zebra[3764]: [QR5K4-A1079] rib_update_table: IPv6 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:41:28 vyos zebra[3764]: [KMXEB-K771Y] netlink_parse_info: netlink-dp-in (NS 0) type RTM_DELADDR(21), len=80, seq=1684507290, pid=3800
May 19 14:41:28 vyos zebra[3764]: [RGWF1-EHXT1] netlink_interface_addr_dplane: RTM_DELADDR nsid 0 ifindex 2 flags 0x80:
May 19 14:41:28 vyos zebra[3764]: [XMC8C-4ZFJ9]   IFA_LOCAL     192.168.0.2/24
May 19 14:41:28 vyos zebra[3764]: [ME3M2-X6YT9]   IFA_ADDRESS   192.168.0.2/24
May 19 14:41:28 vyos zebra[3764]: [Y9HR3-XD5TG]   IFA_LABEL     eth0
May 19 14:41:28 vyos zebra[3764]: [P2VPT-508WP]   IFA_CACHEINFO pref -1, valid -1
May 19 14:41:28 vyos zebra[3764]: [QE6V0-J8BG5] rib_delnode: (0:254):192.168.0.0/24: rn 0x56103e40adc0, re 0x56103e40afd0, removing
May 19 14:41:28 vyos zebra[3764]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):192.168.0.0/24: queued rn 0x56103e40adc0 into sub-queue Connected Routes
May 19 14:41:28 vyos zebra[3764]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x56103e40ab00 (0[]), refcnt 0, NH directly connected, eth0
May 19 14:41:28 vyos zebra[3764]: [QE6V0-J8BG5] rib_delnode: (0:254):192.168.0.0/24 (MRIB): rn 0x56103e40b8a0, re 0x56103e40b940, removing
May 19 14:41:28 vyos zebra[3764]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):192.168.0.0/24 (MRIB): queued rn 0x56103e40b8a0 into sub-queue Connected Routes
May 19 14:41:28 vyos zebra[3764]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x56103e40b6d0 (0[]), refcnt 0, NH directly connected, eth0
May 19 14:41:28 vyos zebra[3764]: [NZNZ4-7P54Y] default(0:254):192.168.0.0/24: Processing rn 0x56103e40adc0
May 19 14:41:28 vyos zebra[3764]: [ZJVZ4-XEGPF] default(0:254):192.168.0.0/24: Examine re 0x56103e40afd0 (connected) status: Removed Installed flags: Selected dist 0 metric 0
May 19 14:41:28 vyos zebra[3764]: [JPJF4-TGCY5] default(0:254):192.168.0.0/24: After processing: old_selected 0x56103e40afd0 new_selected 0x0 old_fib 0x56103e40afd0 new_fib 0x0
May 19 14:41:28 vyos zebra[3764]: [S31W0-H281H] 0:254192.168.0.0/24: Redist del: re 0x56103e40afd0 (0:connected), new re 0x0 (0:None)
May 19 14:41:28 vyos zebra[3764]: [S59C1-4C5PP] default(0:254):192.168.0.0/24: Deleting route rn 0x56103e40adc0, re 0x56103e40afd0 (connected)
May 19 14:41:28 vyos zebra[3764]: [NM15X-X83N9] rib_process: (0:254):192.168.0.0/24: rn 0x56103e40adc0, removing re 0x56103e40afd0
May 19 14:41:28 vyos zebra[3764]: [Y53JX-CBC5H] rib_unlink: (0:254):192.168.0.0/24: rn 0x56103e40adc0, re 0x56103e40afd0
May 19 14:41:28 vyos zebra[3764]: [WDEB1-93HCZ] zebra_nhg_decrement_ref: nhe 0x56103e409a10 (66[if 2]) 2 => 1
May 19 14:41:28 vyos zebra[3764]: [KT8QQ-45WQ0] rib_gc_dest: (0:?):192.168.0.0/24: removing dest from table
May 19 14:41:28 vyos zebra[3764]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 192.168.0.0/24 Being examined for Nexthop Tracking Count: 0
May 19 14:41:28 vyos zebra[3764]: [N744R-XB3J9] 192.168.0.0/24 has no tracking NHTs. Bailing
May 19 14:41:28 vyos zebra[3764]: [HH6N2-PDCJS] default(0:0):192.168.0.0/24 rn 0x56103e40adc0 dequeued from sub-queue Connected Routes
May 19 14:41:28 vyos zebra[3764]: [NZNZ4-7P54Y] default(0:254):192.168.0.0/24: Processing rn 0x56103e40b8a0
May 19 14:41:28 vyos zebra[3764]: [ZJVZ4-XEGPF] default(0:254):192.168.0.0/24: Examine re 0x56103e40b940 (connected) status: Removed flags: Selected dist 0 metric 0
May 19 14:41:28 vyos zebra[3764]: [JPJF4-TGCY5] default(0:254):192.168.0.0/24: After processing: old_selected 0x56103e40b940 new_selected 0x0 old_fib 0x0 new_fib 0x0
May 19 14:41:28 vyos zebra[3764]: [S31W0-H281H] 0:254192.168.0.0/24: Redist del: re 0x56103e40b940 (0:connected), new re 0x0 (0:None)
May 19 14:41:28 vyos zebra[3764]: [NM15X-X83N9] rib_process: (0:254):192.168.0.0/24 (MRIB): rn 0x56103e40b8a0, removing re 0x56103e40b940
May 19 14:41:28 vyos zebra[3764]: [Y53JX-CBC5H] rib_unlink: (0:254):192.168.0.0/24 (MRIB): rn 0x56103e40b8a0, re 0x56103e40b940
May 19 14:41:28 vyos zebra[3764]: [WDEB1-93HCZ] zebra_nhg_decrement_ref: nhe 0x56103e409a10 (66[if 2]) 1 => 0
May 19 14:41:28 vyos zebra[3764]: [KT8QQ-45WQ0] rib_gc_dest: (0:?):192.168.0.0/24 (MRIB): removing dest from table
May 19 14:41:28 vyos zebra[3764]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 192.168.0.0/24 Being examined for Nexthop Tracking Count: 0
May 19 14:41:28 vyos zebra[3764]: [N744R-XB3J9] 192.168.0.0/24 has no tracking NHTs. Bailing
May 19 14:41:28 vyos zebra[3764]: [HH6N2-PDCJS] default(0:0):192.168.0.0/24 rn 0x56103e40b8a0 dequeued from sub-queue Connected Routes
May 19 14:41:28 vyos zebra[3764]: [NZNZ4-7P54Y] default(0:254):0.0.0.0/0: Processing rn 0x56103e25dcd0
May 19 14:41:28 vyos zebra[3764]: [ZJVZ4-XEGPF] default(0:254):0.0.0.0/0: Examine re 0x56103e40b110 (kernel) status: Changed Installed flags: Selected dist 0 metric 0
May 19 14:41:28 vyos zebra[3764]: [VTD0C-NR53W] nexthop_active_update: re 0x56103e40b110 nhe 0x56103e40ac40 (67[192.168.0.1 if 2]), curr_nhe 0x56103e40afd0
May 19 14:41:28 vyos zebra[3764]: [T9JWA-N8HM5] nexthop_active_check: re 0x56103e40b110, nexthop 192.168.0.1, via eth0
May 19 14:41:28 vyos zebra[3764]: [ZG85Y-SBJH3] nexthop_active_update: re 0x56103e40b110 curr_active 1
May 19 14:41:28 vyos zebra[3764]: [MA7PW-DZFV7] zebra_nhg_rib_find_nhe: rt_nhe 0x56103e40afd0 (0[])
May 19 14:41:28 vyos zebra[3764]: [YDEFD-9VKZX] zebra_nhe_find: id 0, lookup 0x56103e40afd0, vrf 0, type 28, depends 0x0
May 19 14:41:28 vyos zebra[3764]: [XCWSF-H8QAB] zebra_nhe_find: lookup => 0x56103e40ac40 (67[192.168.0.1 if 2])
May 19 14:41:28 vyos zebra[3764]: [W4Z4R-NTSMD] zebra_nhg_rib_find_nhe: => nhe 0x56103e40ac40 (67[192.168.0.1 if 2])
May 19 14:41:28 vyos zebra[3764]: [J6P4K-BSDDN] nexthop_active_update: re 0x56103e40b110 CHANGED: nhe 0x56103e40ac40 (67[192.168.0.1 if 2]) => new_nhe 0x56103e40ac40 (67[192.168.0.1 if 2])
May 19 14:41:28 vyos zebra[3764]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x56103e40afd0 (0[]), refcnt 0, NH 192.168.0.1, via eth0
May 19 14:41:28 vyos zebra[3764]: [JPJF4-TGCY5] default(0:254):0.0.0.0/0: After processing: old_selected 0x56103e40b110 new_selected 0x56103e40b110 old_fib 0x56103e40b110 new_fib 0x56103e40b110
May 19 14:41:28 vyos zebra[3764]: [X2YHK-SWH93] default(0:254):0.0.0.0/0: Updating route rn 0x56103e25dcd0, re 0x56103e40b110 (kernel)
May 19 14:41:28 vyos zebra[3764]: [PJXNX-HZST8] zebra_nhg_install_kernel: valid flag set for nh 67[192.168.0.1 if 2]
May 19 14:41:28 vyos zebra[3764]: [HH6N2-PDCJS] default(0:254):0.0.0.0/0 rn 0x56103e25dcd0 dequeued from sub-queue Kernel Routes
May 19 14:41:28 vyos zebra[3764]: [TQKA8-0276P] Not Notifying Owner: connected about prefix 192.168.0.0/24(254) 3 vrf: 0
May 19 14:41:28 vyos zebra[3764]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 192.168.0.0/24 Being examined for Nexthop Tracking Count: 0
May 19 14:41:28 vyos zebra[3764]: [N744R-XB3J9] 192.168.0.0/24 has no tracking NHTs. Bailing
May 19 14:41:28 vyos zebra[3764]: [GHWHS-ZKQM5] update_from_ctx: default(0:254):0.0.0.0/0: SELECTED, re 0x56103e40b110
May 19 14:41:28 vyos zebra[3764]: [TS3SH-1276M] default(0:254):0.0.0.0/0 update_from_ctx(): no fib nhg
May 19 14:41:28 vyos zebra[3764]: [HKQXC-4STSK] default(0:254):0.0.0.0/0 update_from_ctx(): rib nhg matched, changed 'false'
May 19 14:41:28 vyos zebra[3764]: [Z1MP1-RFGJA] (0:254):0.0.0.0/0(0): Redist update re 0x56103e40b110 (kernel), old 0x56103e40b110 (kernel)
May 19 14:41:28 vyos zebra[3764]: [TQKA8-0276P] Not Notifying Owner: kernel about prefix 0.0.0.0/0(254) 2 vrf: 0
May 19 14:41:28 vyos zebra[3764]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 0.0.0.0/0 Being examined for Nexthop Tracking Count: 0

Expected behavior

FRR should remove a route, if it does not exist in a kernel anymore.

I traced the problem till the nexthop_active_check() in

frr/zebra/zebra_nhg.c

Line 2565 in 32b20e1

static unsigned nexthop_active_check(struct route_node *rn,
.

I think the problem is that kernel routes are trusted too much. This check does not seem to be right:

frr/zebra/zebra_nhg.c

Lines 2589 to 2602 in 32b20e1

/*
* If this is a kernel route, then if the interface is *up* then
* by golly gee whiz it's a good route.
*/
if (re->type == ZEBRA_ROUTE_KERNEL || re->type == ZEBRA_ROUTE_SYSTEM) {
struct interface *ifp;
ifp = if_lookup_by_index(nexthop->ifindex, nexthop->vrf_id);
if (ifp && (if_is_operative(ifp) || if_is_up(ifp))) {
SET_FLAG(nexthop->flags, NEXTHOP_FLAG_ACTIVE);
goto skip_check;
}
}

For example, in this case, an interface status is up, and goto skip_check is activated, but there are no IP addresses on this interface.

Without this check, everything looks better:

May 19 14:48:34 vyos zebra[4116]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELADDR(21), len=80, seq=1684507716, pid=4152
May 19 14:48:34 vyos zebra[4116]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELROUTE(25), len=60, seq=0, pid=0
May 19 14:48:34 vyos zebra[4116]: [SKNFJ-G938V] RTM_DELROUTE ipv4 unicast proto kernel NS 0
May 19 14:48:34 vyos zebra[4116]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELROUTE(25), len=60, seq=0, pid=0
May 19 14:48:34 vyos zebra[4116]: [SKNFJ-G938V] RTM_DELROUTE ipv4 broadcast proto kernel NS 0
May 19 14:48:34 vyos zebra[4116]: [J3J81-V75NW] Route rtm_type: broadcast(3) intentionally ignoring
May 19 14:48:34 vyos zebra[4116]: [KMXEB-K771Y] netlink_parse_info: netlink-listen (NS 0) type RTM_DELROUTE(25), len=60, seq=0, pid=0
May 19 14:48:34 vyos zebra[4116]: [SKNFJ-G938V] RTM_DELROUTE ipv4 local proto kernel NS 0
May 19 14:48:34 vyos zebra[4116]: [J3J81-V75NW] Route rtm_type: local(2) intentionally ignoring
May 19 14:48:34 vyos zebra[4116]: [K8FXY-V65ZJ] Intf dplane ctx 0x7f2144026dd0, op INTF_ADDR_DEL, ifindex (2), result QUEUED
May 19 14:48:34 vyos zebra[4116]: [MZPZA-W042K] zebra_if_addr_update_ctx: INTF_ADDR_DEL: ifindex eth0(2), addr 192.168.0.2/24
May 19 14:48:34 vyos zebra[4116]: [XN0NB-2NSYE] MESSAGE: ZEBRA_INTERFACE_ADDRESS_DELETE 192.168.0.2/24 on eth0 vrf default(0)
May 19 14:48:34 vyos zebra[4116]: [X55C6-A6ZXJ] Route 192.168.0.0/24(0) queued for processing into sub-queue Early Route Processing
May 19 14:48:34 vyos zebra[4116]: [X55C6-A6ZXJ] Route 192.168.0.0/24(0) queued for processing into sub-queue Early Route Processing
May 19 14:48:34 vyos zebra[4116]: [QQWTF-ZKJDD] rib_update: Scheduled VRF (ALL), event RIB_UPDATE_KERNEL
May 19 14:48:34 vyos zebra[4116]: [M8JMF-J6PZV] rib_update_handle_vrf_all: Handling VRF (ALL) event RIB_UPDATE_KERNEL
May 19 14:48:34 vyos zebra[4116]: [QR5K4-A1079] rib_update_table: IPv4 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:48:34 vyos zebra[4116]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):0.0.0.0/0: queued rn 0x5566f5aafcd0 into sub-queue Kernel Routes
May 19 14:48:34 vyos zebra[4116]: [QR5K4-A1079] rib_update_table: IPv4 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:48:34 vyos zebra[4116]: [QR5K4-A1079] rib_update_table: IPv6 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:48:34 vyos zebra[4116]: [QR5K4-A1079] rib_update_table: IPv6 VRF default Table 254 event RIB_UPDATE_KERNEL Route type: wildcard
May 19 14:48:34 vyos zebra[4116]: [KMXEB-K771Y] netlink_parse_info: netlink-dp-in (NS 0) type RTM_DELADDR(21), len=80, seq=1684507716, pid=4152
May 19 14:48:34 vyos zebra[4116]: [RGWF1-EHXT1] netlink_interface_addr_dplane: RTM_DELADDR nsid 0 ifindex 2 flags 0x80:
May 19 14:48:34 vyos zebra[4116]: [XMC8C-4ZFJ9]   IFA_LOCAL     192.168.0.2/24
May 19 14:48:34 vyos zebra[4116]: [ME3M2-X6YT9]   IFA_ADDRESS   192.168.0.2/24
May 19 14:48:34 vyos zebra[4116]: [Y9HR3-XD5TG]   IFA_LABEL     eth0
May 19 14:48:34 vyos zebra[4116]: [P2VPT-508WP]   IFA_CACHEINFO pref -1, valid -1
May 19 14:48:34 vyos zebra[4116]: [QE6V0-J8BG5] rib_delnode: (0:254):192.168.0.0/24: rn 0x5566f5c5cd40, re 0x5566f5c5cfb0, removing
May 19 14:48:34 vyos zebra[4116]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):192.168.0.0/24: queued rn 0x5566f5c5cd40 into sub-queue Connected Routes
May 19 14:48:34 vyos zebra[4116]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x5566f5c5d1d0 (0[]), refcnt 0, NH directly connected, eth0
May 19 14:48:34 vyos zebra[4116]: [QE6V0-J8BG5] rib_delnode: (0:254):192.168.0.0/24 (MRIB): rn 0x5566f5c5d880, re 0x5566f5c5d920, removing
May 19 14:48:34 vyos zebra[4116]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):192.168.0.0/24 (MRIB): queued rn 0x5566f5c5d880 into sub-queue Connected Routes
May 19 14:48:34 vyos zebra[4116]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x5566f5c5cb80 (0[]), refcnt 0, NH directly connected, eth0
May 19 14:48:34 vyos zebra[4116]: [NZNZ4-7P54Y] default(0:254):192.168.0.0/24: Processing rn 0x5566f5c5cd40
May 19 14:48:34 vyos zebra[4116]: [ZJVZ4-XEGPF] default(0:254):192.168.0.0/24: Examine re 0x5566f5c5cfb0 (connected) status: Removed Installed flags: Selected dist 0 metric 0
May 19 14:48:34 vyos zebra[4116]: [JPJF4-TGCY5] default(0:254):192.168.0.0/24: After processing: old_selected 0x5566f5c5cfb0 new_selected 0x0 old_fib 0x5566f5c5cfb0 new_fib 0x0
May 19 14:48:34 vyos zebra[4116]: [S31W0-H281H] 0:254192.168.0.0/24: Redist del: re 0x5566f5c5cfb0 (0:connected), new re 0x0 (0:None)
May 19 14:48:34 vyos zebra[4116]: [S59C1-4C5PP] default(0:254):192.168.0.0/24: Deleting route rn 0x5566f5c5cd40, re 0x5566f5c5cfb0 (connected)
May 19 14:48:34 vyos zebra[4116]: [NM15X-X83N9] rib_process: (0:254):192.168.0.0/24: rn 0x5566f5c5cd40, removing re 0x5566f5c5cfb0
May 19 14:48:34 vyos zebra[4116]: [Y53JX-CBC5H] rib_unlink: (0:254):192.168.0.0/24: rn 0x5566f5c5cd40, re 0x5566f5c5cfb0
May 19 14:48:34 vyos zebra[4116]: [WDEB1-93HCZ] zebra_nhg_decrement_ref: nhe 0x5566f5c5cc20 (76[if 2]) 2 => 1
May 19 14:48:34 vyos zebra[4116]: [KT8QQ-45WQ0] rib_gc_dest: (0:?):192.168.0.0/24: removing dest from table
May 19 14:48:34 vyos zebra[4116]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 192.168.0.0/24 Being examined for Nexthop Tracking Count: 0
May 19 14:48:34 vyos zebra[4116]: [N744R-XB3J9] 192.168.0.0/24 has no tracking NHTs. Bailing
May 19 14:48:34 vyos zebra[4116]: [HH6N2-PDCJS] default(0:0):192.168.0.0/24 rn 0x5566f5c5cd40 dequeued from sub-queue Connected Routes
May 19 14:48:34 vyos zebra[4116]: [NZNZ4-7P54Y] default(0:254):192.168.0.0/24: Processing rn 0x5566f5c5d880
May 19 14:48:34 vyos zebra[4116]: [ZJVZ4-XEGPF] default(0:254):192.168.0.0/24: Examine re 0x5566f5c5d920 (connected) status: Removed flags: Selected dist 0 metric 0
May 19 14:48:34 vyos zebra[4116]: [JPJF4-TGCY5] default(0:254):192.168.0.0/24: After processing: old_selected 0x5566f5c5d920 new_selected 0x0 old_fib 0x0 new_fib 0x0
May 19 14:48:34 vyos zebra[4116]: [S31W0-H281H] 0:254192.168.0.0/24: Redist del: re 0x5566f5c5d920 (0:connected), new re 0x0 (0:None)
May 19 14:48:34 vyos zebra[4116]: [NM15X-X83N9] rib_process: (0:254):192.168.0.0/24 (MRIB): rn 0x5566f5c5d880, removing re 0x5566f5c5d920
May 19 14:48:34 vyos zebra[4116]: [Y53JX-CBC5H] rib_unlink: (0:254):192.168.0.0/24 (MRIB): rn 0x5566f5c5d880, re 0x5566f5c5d920
May 19 14:48:34 vyos zebra[4116]: [WDEB1-93HCZ] zebra_nhg_decrement_ref: nhe 0x5566f5c5cc20 (76[if 2]) 1 => 0
May 19 14:48:34 vyos zebra[4116]: [KT8QQ-45WQ0] rib_gc_dest: (0:?):192.168.0.0/24 (MRIB): removing dest from table
May 19 14:48:34 vyos zebra[4116]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 192.168.0.0/24 Being examined for Nexthop Tracking Count: 0
May 19 14:48:34 vyos zebra[4116]: [N744R-XB3J9] 192.168.0.0/24 has no tracking NHTs. Bailing
May 19 14:48:34 vyos zebra[4116]: [HH6N2-PDCJS] default(0:0):192.168.0.0/24 rn 0x5566f5c5d880 dequeued from sub-queue Connected Routes
May 19 14:48:34 vyos zebra[4116]: [NZNZ4-7P54Y] default(0:254):0.0.0.0/0: Processing rn 0x5566f5aafcd0
May 19 14:48:34 vyos zebra[4116]: [ZJVZ4-XEGPF] default(0:254):0.0.0.0/0: Examine re 0x5566f5c5d6f0 (kernel) status: Changed Installed flags: Selected dist 0 metric 0
May 19 14:48:34 vyos zebra[4116]: [VTD0C-NR53W] nexthop_active_update: re 0x5566f5c5d6f0 nhe 0x5566f5c5c520 (77[192.168.0.1 if 2]), curr_nhe 0x5566f5c5cfb0
May 19 14:48:34 vyos zebra[4116]: [T9JWA-N8HM5] nexthop_active_check: re 0x5566f5c5d6f0, nexthop 192.168.0.1, via eth0
May 19 14:48:34 vyos zebra[4116]: [YPVDZ-KQPM9]         nexthop_active: Matched against ourself and prefix length is not max bit length
May 19 14:48:34 vyos zebra[4116]: [HJ48M-MB610]         nexthop_active_check: Unable to find active nexthop
May 19 14:48:34 vyos zebra[4116]: [ZG85Y-SBJH3] nexthop_active_update: re 0x5566f5c5d6f0 curr_active 0
May 19 14:48:34 vyos zebra[4116]: [MA7PW-DZFV7] zebra_nhg_rib_find_nhe: rt_nhe 0x5566f5c5cfb0 (0[])
May 19 14:48:34 vyos zebra[4116]: [YDEFD-9VKZX] zebra_nhe_find: id 0, lookup 0x5566f5c5cfb0, vrf 0, type 28, depends 0x0
May 19 14:48:34 vyos zebra[4116]: [XCWSF-H8QAB] zebra_nhe_find: lookup => 0x0 ([NULL])
May 19 14:48:34 vyos zebra[4116]: [J7G3Y-G97PX] nhg_get_next_id: ID 78 checking
May 19 14:48:34 vyos zebra[4116]: [PKSQ5-QBSHW] zebra_nhe_find: => created 0x5566f5c5d510 (78[192.168.0.1 if 2])
May 19 14:48:34 vyos zebra[4116]: [W4Z4R-NTSMD] zebra_nhg_rib_find_nhe: => nhe 0x5566f5c5d510 (78[192.168.0.1 if 2])
May 19 14:48:34 vyos zebra[4116]: [J6P4K-BSDDN] nexthop_active_update: re 0x5566f5c5d6f0 CHANGED: nhe 0x5566f5c5c520 (77[192.168.0.1 if 2]) => new_nhe 0x5566f5c5d510 (78[192.168.0.1 if 2])
May 19 14:48:34 vyos zebra[4116]: [WDEB1-93HCZ] zebra_nhg_increment_ref: nhe 0x5566f5c5d510 (78[192.168.0.1 if 2]) 0 => 1
May 19 14:48:34 vyos zebra[4116]: [WDEB1-93HCZ] zebra_nhg_decrement_ref: nhe 0x5566f5c5c520 (77[192.168.0.1 if 2]) 1 => 0
May 19 14:48:34 vyos zebra[4116]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x5566f5c5cfb0 (78[]), refcnt 0, NH 192.168.0.1, via eth0
May 19 14:48:34 vyos zebra[4116]: [TQKA8-0276P] Not Notifying Owner: kernel about prefix 0.0.0.0/0(254) 0 vrf: 0
May 19 14:48:34 vyos zebra[4116]: [JPJF4-TGCY5] default(0:254):0.0.0.0/0: After processing: old_selected 0x5566f5c5d6f0 new_selected 0x0 old_fib 0x5566f5c5d6f0 new_fib 0x0
May 19 14:48:34 vyos zebra[4116]: [S31W0-H281H] 0:2540.0.0.0/0: Redist del: re 0x5566f5c5d6f0 (0:kernel), new re 0x0 (0:None)
May 19 14:48:34 vyos zebra[4116]: [S59C1-4C5PP] default(0:254):0.0.0.0/0: Deleting route rn 0x5566f5aafcd0, re 0x5566f5c5d6f0 (kernel)
May 19 14:48:34 vyos zebra[4116]: [NM15X-X83N9] rib_process: (0:254):0.0.0.0/0: rn 0x5566f5aafcd0, removing re 0x5566f5c5d6f0
May 19 14:48:34 vyos zebra[4116]: [Y53JX-CBC5H] rib_unlink: (0:254):0.0.0.0/0: rn 0x5566f5aafcd0, re 0x5566f5c5d6f0
May 19 14:48:34 vyos zebra[4116]: [WDEB1-93HCZ] zebra_nhg_decrement_ref: nhe 0x5566f5c5d510 (78[192.168.0.1 if 2]) 1 => 0
May 19 14:48:34 vyos zebra[4116]: [JE46R-G2NEE] zebra_nhg_release: nhe 0x5566f5c5d510 (78[192.168.0.1 if 2])
May 19 14:48:34 vyos zebra[4116]: [VKWCR-QB19H] zebra_nhg_free: nhe 0x5566f5c5d510 (78[192.168.0.1 if 2]), refcnt 0, NH 192.168.0.1, via eth0
May 19 14:48:34 vyos zebra[4116]: [HH6N2-PDCJS] default(0:0):0.0.0.0/0 rn 0x5566f5aafcd0 dequeued from sub-queue Kernel Routes
May 19 14:48:34 vyos zebra[4116]: [TQKA8-0276P] Not Notifying Owner: connected about prefix 192.168.0.0/24(254) 3 vrf: 0
May 19 14:48:34 vyos zebra[4116]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 192.168.0.0/24 Being examined for Nexthop Tracking Count: 0
May 19 14:48:34 vyos zebra[4116]: [N744R-XB3J9] 192.168.0.0/24 has no tracking NHTs. Bailing
May 19 14:48:34 vyos zebra[4116]: [TQKA8-0276P] Not Notifying Owner: kernel about prefix 0.0.0.0/0(254) 3 vrf: 0
May 19 14:48:34 vyos zebra[4116]: [PS6CZ-GQDN1] zebra_rib_evaluate_rn_nexthops: 0.0.0.0/0 Being examined for Nexthop Tracking Count: 0
May 19 14:48:34 vyos zebra[4116]: [N744R-XB3J9] 0.0.0.0/0 has no tracking NHTs. Bailing

I think the check should be removed or modified to take into account more info than only interface status.

Screenshots

Versions

  • OS Version: Debian 8, Debian 11
  • Kernel: Linux 5.4.210, Linux 6.1.27
  • FRR Version: 7.5.1, 8.5.1, 9.0/master (32b20e1ad65e8db2ef80dd39b255f34de2802cd2)

Additional context

It could be that described problem may be a reason also for:

#11592
#12197
@zdc zdc added the triage Needs further investigation label May 19, 2023
@SwimGeek
Copy link

SwimGeek commented Aug 4, 2023

Hi. We see the same issue.

FRRouting 8.5.2, on Linux 6.1.35, Debian 12

We add/delete routes with "ip route". Sometimes FRR continues to advertise one of these kernel routes after it's been deleted, indefinitely. Nothing in FRR logs.

Example
cpt-ter-rs2# ip route del 102.216.77.157/32

Route is gone from kernel:
cpt-ter-rs2# ip route sh | grep '102.216.77'
102.216.77.0/25 dev br0.777 proto kernel scope link src 102.216.77.1 rt_offload
blackhole 102.216.77.0/24 proto static metric 20 rt_offload
102.216.77.135 dev br0.300 scope link src 102.216.77.129 rt_offload

cpt-ter-rs2# ip route sh match 102.216.77.157/32
default via 196.250.236.145 dev br0.1576 proto kernel onlink offload rt_offload
blackhole 102.216.77.0/24 proto static metric 20 rt_offload

But FRR is still seeing it:
cpt-ter-rs2# show ip route 102.216.77.157
Routing entry for 102.216.77.157/32
Known via "kernel", distance 0, metric 0, best
Last update 03:23:18 ago

  • directly connected, br0.300

cpt-ter-rs2# show ip bgp 102.216.77.157/32
BGP routing table entry for 102.216.77.157/32, version 22225
Paths: (1 available, best #1, table default)
Advertised to non peer-group peers:
cpt-ter-rs1(102.216.76.3) cpt-ter-r2(102.216.76.2)
Local
0.0.0.0(cpt-ter-rs2) from 0.0.0.0 (102.216.76.4)
Origin incomplete, metric 0, weight 32768, valid, sourced, best (First path received)
Last update: Tue Jul 11 15:30:27 2023

@rzalamena rzalamena added zebra and removed triage Needs further investigation labels Sep 22, 2023
@rzalamena rzalamena mentioned this issue Sep 22, 2023
Open
@rzalamena
Copy link
Member

These commits seem to explain that exception (from oldest to newest):

This behavior looks intentional to workaround interfaces going down bringing down other routes. Maybe we are missing stimulus somewhere else to remove these stale routes?

@github-actions GitHub Actions
Copy link

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.

@vgrebenschikov
Copy link

Similar to #9185 ?

@sever-sever
Copy link

Still, the bug. Are there any updates?

@DennyAgussy
Copy link

As per @zdc comment when we remove this check:
if (ifp && (if_is_operative(ifp) || if_is_up(ifp))) {
SET_FLAG(nexthop->flags, NEXTHOP_FLAG_ACTIVE);
goto skip_check;
}
It works fine and FRR removes this default route: K>* 0.0.0.0/0 [0/0] via 192.168.0.1, eth0, 00:00:07 .
The reason behind this is simple, though the interface is up and even though we don't have any connected ip addresses(after flush) "goto skip_check;" skips the intermediatory checks, so FRR isn't removing the default route is what my observation is. We need to add a check to see whether the interface has the connected routes.

@DennyAgussy DennyAgussy mentioned this issue Oct 9, 2024
Open
@badgerdog badgerdog mentioned this issue Oct 27, 2024
Open
2 tasks
@ykholod ykholod mentioned this issue Dec 18, 2024
Closed
@ykholod
Copy link

ykholod commented Dec 19, 2024

The fix was recently merged -- #17544
Hope to see it in stable/10.2 branch

P.S.: Thanks to the author

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
autoclose zebra
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@rzalamena @zdc @vgrebenschikov @SwimGeek @ykholod @sever-sever @DennyAgussy