From a1f69d8f141093607f387a23d428d9f77973bd1d Mon Sep 17 00:00:00 2001 From: Pavel Ivashchenko Date: Thu, 3 Aug 2023 14:01:51 +0000 Subject: [PATCH] zebra: fix assert in process_subq_route Bug is reporoduced in case of switching interfaces betwean VRFs. ospf6d is enabled and configured in each VRF. 'dest' can be removed from the route node in the time when the same route node waiting processing in another sub-queue. A route node must only be in one sub-queue at a time. Details: 1. Config: interface if0 ipv6 address 2001:db8:cafe:2::2/64 ipv6 nat inside ipv6 ospf6 area 0.0.0.51 ipv6 ospf6 cost 10 vrf test2 exit ! interface if1 ipv6 address 2001:db8:cafe:4::1/64 ipv6 nat outside ipv6 ospf6 area 0.0.0.0 ipv6 ospf6 cost 10 vrf test2 exit ! router ospf6 ospf6 router-id 2.2.2.2 exit ! router ospf6 vrf test1 ospf6 router-id 2.2.2.2 exit ! router ospf6 vrf test2 ospf6 router-id 2.2.2.2 exit I just quickly switched interfaces between different VRFs (default/test1/test2). 2. Log messages: Aug 02 16:51:56 ubuntu zebra[386985]: [MFYWV-KH3MC] process_subq_early_route_add: (0:?):2001:db8:cafe:2::/64: Inserting route rn 0x56267593de90, re 0x56267595ae40 (connected) existing 0x0, same_count 0 Aug 02 16:51:56 ubuntu zebra[386985]: [Q4T2G-E2SQF] process_subq_early_route_add: dumping RE entry 0x56267595ae40 for 2001:db8:cafe:2::/64 vrf default(0) Aug 02 16:51:56 ubuntu zebra[386985]: [GCGMT-SQR82] rib_link: (0:?):2001:db8:cafe:2::/64: rn 0x56267593de90 adding dest Aug 02 16:51:56 ubuntu zebra[386985]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):2001:db8:cafe:2::/64: queued rn 0x56267593de90 into sub-queue Connected Routes Aug 02 16:51:56 ubuntu zebra[386985]: [QE6V0-J8BG5] rib_delnode: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90, re 0x56267595ae40, removing Aug 02 16:51:56 ubuntu zebra[386985]: [KMPGN-JBRKW] rib_meta_queue_add: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90 is already queued in sub-queue Connected Routes Aug 02 16:51:56 ubuntu zebra[386985]: [MFYWV-KH3MC] process_subq_early_route_add: (0:254):2001:db8:cafe:2::/64: Inserting route rn 0x56267593de90, re 0x56267595abf0 (ospf6) existing 0x0, same_count 1 Aug 02 16:51:56 ubuntu zebra[386985]: [Q4T2G-E2SQF] process_subq_early_route_add: dumping RE entry 0x56267595abf0 for 2001:db8:cafe:2::/64 vrf default(0) Aug 02 16:51:56 ubuntu zebra[386985]: [KMPGN-JBRKW] rib_meta_queue_add: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90 is already queued in sub-queue Connected Routes Aug 02 16:51:56 ubuntu zebra[386985]: [YEYFX-TDSC2] process_subq_early_route_add: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90, removing unneeded re 0x56267595ae40 Aug 02 16:51:56 ubuntu zebra[386985]: [Y53JX-CBC5H] rib_unlink: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90, re 0x56267595ae40 Aug 02 16:51:56 ubuntu zebra[386985]: [QE6V0-J8BG5] rib_delnode: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90, re 0x56267595abf0, removing Aug 02 16:51:56 ubuntu zebra[386985]: [JF0K0-DVHWH] rib_meta_queue_add: (0:254):2001:db8:cafe:2::/64: queued rn 0x56267593de90 into sub-queue RIP/OSPF/ISIS/EIGRP/NHRP Routes Aug 02 16:51:56 ubuntu zebra[386985]: [NZNZ4-7P54Y] default(0:254):2001:db8:cafe:2::/64: Processing rn 0x56267593de90 Aug 02 16:51:56 ubuntu zebra[386985]: [ZJVZ4-XEGPF] default(0:254):2001:db8:cafe:2::/64: Examine re 0x56267595abf0 (ospf6) status: Removed Changed flags: None dist 110 metric 10 Aug 02 16:51:56 ubuntu zebra[386985]: [NM15X-X83N9] rib_process: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90, removing re 0x56267595abf0 Aug 02 16:51:56 ubuntu zebra[386985]: [Y53JX-CBC5H] rib_unlink: (0:254):2001:db8:cafe:2::/64: rn 0x56267593de90, re 0x56267595abf0 Aug 02 16:51:56 ubuntu zebra[386985]: [KT8QQ-45WQ0] rib_gc_dest: (0:?):2001:db8:cafe:2::/64: removing dest from table Aug 02 16:51:56 ubuntu zebra[386985]: [HH6N2-PDCJS] default(0:0):2001:db8:cafe:2::/64 rn 0x56267593de90 dequeued from sub-queue Connected Routes 3. ...and then assert: (gdb) bt #0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=140662163115136) at ./nptl/pthread_kill.c:44 #1 __pthread_kill_internal (signo=6, threadid=140662163115136) at ./nptl/pthread_kill.c:78 #2 __GI___pthread_kill (threadid=140662163115136, signo=signo@entry=6) at ./nptl/pthread_kill.c:89 #3 0x00007fee76753476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26 #4 0x00007fee767397f3 in __GI_abort () at ./stdlib/abort.c:79 #5 0x00007fee76a420fd in _zlog_assert_failed () from target:/usr/lib/x86_64-linux-gnu/frr/libfrr.so.0 #6 0x0000562674efe0f0 in process_subq_route (qindex=7 '\a', lnode=0x562675940c60) at zebra/zebra_rib.c:2540 #7 process_subq (qindex=META_QUEUE_NOTBGP, subq=0x562675574580) at zebra/zebra_rib.c:3055 #8 meta_queue_process (dummy=, data=0x56267556d430) at zebra/zebra_rib.c:3091 #9 0x00007fee76a386e8 in work_queue_run () from target:/usr/lib/x86_64-linux-gnu/frr/libfrr.so.0 #10 0x00007fee76a31c91 in thread_call () from target:/usr/lib/x86_64-linux-gnu/frr/libfrr.so.0 #11 0x00007fee769ee528 in frr_run () from target:/usr/lib/x86_64-linux-gnu/frr/libfrr.so.0 #12 0x0000562674e97ec5 in main (argc=5, argv=0x7ffd1e275958) at zebra/main.c:478 (gdb) print lnode->data $10 = (void *) 0x56267593de90 (gdb) p/x *(struct route_node *)0x56267593de90 $11 = { p = { family = 0xa, prefixlen = 0x40, u = { prefix = 0x20, prefix4 = { s_addr = 0xb80d0120 }, prefix6 = { __in6_u = { __u6_addr8 = {0x20, 0x1, 0xd, 0xb8, 0xca, 0xfe, 0x0, 0x2, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, __u6_addr16 = {0x120, 0xb80d, 0xfeca, 0x200, 0x0, 0x0, 0x0, 0x0}, __u6_addr32 = {0xb80d0120, 0x200feca, 0x0, 0x0} } }, ... table = 0x5626755ae010, parent = 0x5626755ae070, link = {0x0, 0x0}, lock = 0x4, nodehash = { hi = { next = 0x5626755ae0d0, hashval = 0xebe8bdbf } }, info = 0x0 3. What's happen: We removed unneeded re 0x56267595ae40 while adding re 0x56267595abf0. It was the last connected re, but rn 0x56267593de90 is still in the connected sub-queue. Then rib_delnode was called for 0x56267595abf0. (rn 0x56267593de90 is still in the connected sub-queue). rib_delnode have called rib_meta_queue_add which have checked, that rn is absent in sub-queue RIP/OSPF/ISIS/EIGRP/NHRP and have added rn in the second sub-queue. Fixes: d7ac4c4d88 ("zebra: Introduce early route processing on the MetaQ") Ticket :#3990187 Signed-off-by: Pavel Ivashchenko --- zebra/rib.h | 4 ++++ zebra/zebra_rib.c | 28 ++++++++++++++++++++++++---- 2 files changed, 28 insertions(+), 4 deletions(-) diff --git a/zebra/rib.h b/zebra/rib.h index 2de9e0e762fc..6e66ff0a50ea 100644 --- a/zebra/rib.h +++ b/zebra/rib.h @@ -198,6 +198,10 @@ struct route_entry { * don't generate routes */ #define MQ_SIZE 11 + +/* For checking that an object has already queued in some sub-queue */ +#define MQ_BIT_MASK ((1 << MQ_SIZE) - 1) + struct meta_queue { struct list *subq[MQ_SIZE]; uint32_t size; /* sum of lengths of all subqueues */ diff --git a/zebra/zebra_rib.c b/zebra/zebra_rib.c index 0b0190bdce7a..7f96e3e32b7e 100644 --- a/zebra/zebra_rib.c +++ b/zebra/zebra_rib.c @@ -3580,14 +3580,34 @@ static int rib_meta_queue_add(struct meta_queue *mq, void *data) return -1; /* Invariant: at this point we always have rn->info set. */ - if (CHECK_FLAG(rib_dest_from_rnode(rn)->flags, - RIB_ROUTE_QUEUED(qindex))) { - if (IS_ZEBRA_DEBUG_RIB_DETAILED) + /* A route node must only be in one sub-queue at a time. */ + if (CHECK_FLAG(rib_dest_from_rnode(rn)->flags, MQ_BIT_MASK)) { + if (IS_ZEBRA_DEBUG_RIB_DETAILED) { + /* + * curr_qindex_bitmask is power of 2, because a route + * node must only be in one sub-queue at a time, so for + * getting current sub-queue index from bitmask we may + * use part of classic msb function (find most + * significant set bit). + */ + const uint32_t curr_qindex_bitmask = CHECK_FLAG( + rib_dest_from_rnode(rn)->flags, MQ_BIT_MASK); + static const uint8_t pos[32] = { + 0, 1, 28, 2, 29, 14, 24, 3, 30, 22, 20, + 15, 25, 17, 4, 8, 31, 27, 13, 23, 21, 19, + 16, 7, 26, 12, 18, 6, 11, 5, 10, 9}; + + curr_qindex = pos[(uint32_t)(curr_qindex_bitmask * + 0x077CB531UL) >> + 27]; + rnode_debug(rn, re->vrf_id, "rn %p is already queued in sub-queue %s", - (void *)rn, subqueue2str(qindex)); + (void *)rn, subqueue2str(curr_qindex)); + } zebra_gr_increment_processed_rt_count(rn, re->vrf_id, true); + return -1; }