FRRouting / frr

The FRRouting Protocol Suite
https://frrouting.org/
Other
3.21k stars 1.24k forks source link

Route install failed #5215

Open lucasalvatore opened 4 years ago

lucasalvatore commented 4 years ago

Describe the bug BGP routes received from upstream peer are not installed into the kernel. Routes exist in the BGP table, but nothing in the kernel / nht. bgpd.log shows logs such as:

2019/10/23 14:34:49 ZEBRA: 0:192.168.216.17/32 Processing dplane ctx 0x3699e90, op ROUTE_UPDATE result FAILURE
2019/10/23 14:34:49 ZEBRA: 0:192.168.216.17/32 Stale dplane result for old_re 0x369c790
2019/10/23 14:34:49 ZEBRA: 0:192.168.216.17/32: Route install failed

Versions

# sh ver
FRRouting 7.3-dev-MyOwnFRRVersion-gacf061a (stingray1-maia).
Copyright 1996-2005 Kunihiro Ishiguro, et al.
This is a git build of frr-7.1-dev-849-gacf061a
Associated branch(es):
    local:master
    github/frrouting/frr.git/master

configured with:
    '--prefix=/usr' '--includedir=${prefix}/include' '--enable-exampledir=${prefix}/share/doc/frr/examples' '--bindir=${prefix}/bin' '--sbindir=${prefix}/lib/frr' '--libdir=${prefix}/lib/frr' '--libexecdir=${prefix}/lib/frr' '--localstatedir=/var/run/frr' '--sysconfdir=/etc/frr' '--with-moduledir=${prefix}/lib/frr/modules' '--with-libyang-pluginsdir=${prefix}/lib/frr/libyang_plugins' '--enable-configfile-mask=0640' '--enable-logfile-mask=0640' '--enable-snmp=agentx' '--enable-multipath=64' '--enable-user=frr' '--enable-group=frr' '--enable-vty-group=frrvty' '--with-pkg-git-version' '--with-pkg-extra-version=-MyOwnFRRVersion' '--enable-systemd'

Ubuntu 16.04.6 LTS Kernel 4.14.95

[x] Did you check if this is a duplicate issue? Seems like similar issues reported in #4471 & #2713 [x ] Did you test it on the latest FRRouting/frr master branch?

To Reproduce Steps to reproduce the behavior: 1) Setup BGP peering 2) Advertise routes from neighbor 3) Check if they are installed

Expected behavior Routes are installed into the FIB

Additional context Some additional logging / config:

router bgp 65000
 bgp ebgp-requires-policy
 neighbor EVPN peer-group
 neighbor EVPN remote-as 65530
 neighbor EVPN ebgp-multihop 255
 neighbor EVPN update-source 10.10.10.10
 neighbor TOR-SWITCHES peer-group
 neighbor TOR-SWITCHES remote-as 65530
 neighbor 10.88.99.0 peer-group TOR-SWITCHES
 neighbor 10.88.99.2 peer-group TOR-SWITCHES
 !
 address-family ipv4 unicast
  network 10.10.10.10/32
  neighbor 10.88.99.0 soft-reconfiguration inbound
  neighbor 10.88.99.0 route-map IMPORT in
  neighbor 10.88.99.0 route-map EXPORT out
  neighbor 10.88.99.2 soft-reconfiguration inbound
  neighbor 10.88.99.2 route-map IMPORT in
  neighbor 10.88.99.2 route-map EXPORT out
 exit-address-family
!
ip prefix-list LOOPBACK seq 5 permit 10.10.10.10/32
!
route-map EXPORT permit 10
 match ip address prefix-list LOOPBACK
!
route-map IMPORT permit 10
!
line vty
!
end
stingray1-maia# show ip bgp sum

IPv4 Unicast Summary:
BGP router identifier 10.10.10.10, local AS number 65000 vrf-id 0
BGP table version 142
RIB entries 3, using 552 bytes of memory
Peers 2, using 41 KiB of memory
Peer groups 2, using 128 bytes of memory

Neighbor        V         AS MsgRcvd MsgSent   TblVer  InQ OutQ  Up/Down State/PfxRcd
10.88.99.0      4      65530    2176    2008        0    0    0 00:05:58            1
10.88.99.2      4      65530    2178    2009        0    0    0 00:06:02            1

Total number of neighbors 2
stingray1-maia# sh ip nht
10.88.99.0(Connected)
 resolved via connected
 is directly connected, enP8p1s0f6
 Client list: bgp(fd 15) static(fd 33)
10.88.99.2(Connected)
 resolved via connected
 is directly connected, enP8p1s0f7d1
 Client list: bgp(fd 15)

Logs with debugging:

2019/10/23 14:41:55 ZEBRA: 0:192.168.216.17/32 Dplane route update ctx 0x369c7f0 op ROUTE_INSTALL
2019/10/23 14:41:55 ZEBRA: netlink_talk_info: >> netlink message dump [sent]
2019/10/23 14:41:55 ZEBRA:
0x0000ffff7fef2428: 50 00 00 00 18 00 01 05 P.......
0x0000ffff7fef2430: b4 00 00 00 ba e5 cc e9 ........
0x0000ffff7fef2438: 02 20 00 00 fe ba 00 01 . ......
0x0000ffff7fef2440: 00 00 00 00 08 00 01 00 ........
0x0000ffff7fef2448: 93 4b c8 62 08 00 06 00 .K.b....
0x0000ffff7fef2450: 14 00 00 00 24 00 09 00 ....$...
0x0000ffff7fef2458: 10 00 00 00 08 00 00 00 ........
0x0000ffff7fef2460: 08 00 05 00 0a 58 63 00 .....Xc.
0x0000ffff7fef2468: 10 00 00 00 09 00 00 00 ........
0x0000ffff7fef2470: 08 00 05 00 0a 58 63 02 .....Xc.

2019/10/23 14:41:55 ZEBRA: netlink_parse_info: << netlink message dump [recv]
2019/10/23 14:41:55 ZEBRA:
0x0000ffff7feea2b8: 64 00 00 00 02 00 00 00 d.......
0x0000ffff7feea2c0: b4 00 00 00 ba e5 cc e9 ........
0x0000ffff7feea2c8: ea ff ff ff 50 00 00 00 ....P...
0x0000ffff7feea2d0: 18 00 01 05 b4 00 00 00 ........
0x0000ffff7feea2d8: ba e5 cc e9 02 20 00 00 ..... ..
0x0000ffff7feea2e0: fe ba 00 01 00 00 00 00 ........
0x0000ffff7feea2e8: 08 00 01 00 93 4b c8 62 .....K.b
0x0000ffff7feea2f0: 08 00 06 00 14 00 00 00 ........
0x0000ffff7feea2f8: 24 00 09 00 10 00 00 00 $.......
0x0000ffff7feea300: 08 00 00 00 08 00 05 00 ........
0x0000ffff7feea308: 0a 58 63 00 10 00 00 00 .Xc.....
0x0000ffff7feea310: 09 00 00 00 08 00 05 00 ........
0x0000ffff7feea318: 0a 58 63 02             .Xc.

2019/10/23 14:41:55 ZEBRA: [EC 4043309093] netlink-dp (NS 0) error: Invalid argument, type=RTM_NEWROUTE(24), seq=180, pid=3922519482
2019/10/23 14:41:55 ZEBRA: dplane dequeues 1 completed work from provider Kernel
2019/10/23 14:41:55 ZEBRA: dplane has 1 completed, 0 errors, for zebra main
2019/10/23 14:41:55 ZEBRA: 0:192.168.216.17/32 Processing dplane ctx 0x369c7f0, op ROUTE_INSTALL result FAILURE
2019/10/23 14:41:55 ZEBRA: 0:192.168.216.17/32: Route install failed
2019/10/23 14:41:56 BGP: %NOTIFICATION: rcvd End-of-RIB for IPv4 Unicast from 10.88.99.0 in vrf default
2019/10/23 14:42:19 ZEBRA: netlink_parse_info: << netlink message dump [recv]
2019/10/23 14:42:19 ZEBRA:
0x0000ffffef5c1dc8: 4c 00 00 00 1c 00 00 00 L.......
0x0000ffffef5c1dd0: 00 00 00 00 00 00 00 00 ........
0x0000ffffef5c1dd8: 02 00 00 00 08 00 00 00 ........
0x0000ffffef5c1de0: 04 00 00 01 08 00 01 00 ........
0x0000ffffef5c1de8: 0a 58 63 00 0a 00 02 00 .Xc.....
0x0000ffffef5c1df0: 10 0e 7e ae da 27 00 00 ..~..'..
0x0000ffffef5c1df8: 08 00 04 00 01 00 00 00 ........
0x0000ffffef5c1e00: 14 00 03 00 52 09 00 00 ....R...
0x0000ffffef5c1e08: 3e 0a 00 00 00 00 00 00 >.......
0x0000ffffef5c1e10: 01 00 00 00             ....

2019/10/23 14:42:30 ZEBRA: netlink_parse_info: << netlink message dump [recv]
2019/10/23 14:42:30 ZEBRA:
0x0000ffffef5c1dc8: 4c 00 00 00 1c 00 00 00 L.......
0x0000ffffef5c1dd0: 00 00 00 00 00 00 00 00 ........
0x0000ffffef5c1dd8: 02 00 00 00 08 00 00 00 ........
0x0000ffffef5c1de0: 10 00 00 01 08 00 01 00 ........
0x0000ffffef5c1de8: 0a 58 63 00 0a 00 02 00 .Xc.....
0x0000ffffef5c1df0: 10 0e 7e ae da 27 00 00 ..~..'..
0x0000ffffef5c1df8: 08 00 04 00 01 00 00 00 ........
0x0000ffffef5c1e00: 14 00 03 00 0a 02 00 00 ........
0x0000ffffef5c1e08: 0a 02 00 00 00 00 00 00 ........
0x0000ffffef5c1e10: 02 00 00 00             ....

2019/10/23 14:42:30 ZEBRA: netlink_parse_info: << netlink message dump [recv]
2019/10/23 14:42:30 ZEBRA:
0x0000ffffef5c1dc8: 4c 00 00 00 1c 00 00 00 L.......
0x0000ffffef5c1dd0: 00 00 00 00 00 00 00 00 ........
0x0000ffffef5c1dd8: 02 00 00 00 08 00 00 00 ........
0x0000ffffef5c1de0: 02 00 00 01 08 00 01 00 ........
0x0000ffffef5c1de8: 0a 58 63 00 0a 00 02 00 .Xc.....
0x0000ffffef5c1df0: 10 0e 7e ae da 27 00 00 ..~..'..
0x0000ffffef5c1df8: 08 00 04 00 01 00 00 00 ........
0x0000ffffef5c1e00: 14 00 03 00 00 00 00 00 ........
0x0000ffffef5c1e08: 0c 02 00 00 00 00 00 00 ........
0x0000ffffef5c1e10: 02 00 00 00             ....

var/log/frr$ ip route show
default via 192.168.1.20 dev enP8p1s0f0 onlink
1.2.3.4 via 10.88.99.0 dev enP8p1s0f6  proto 196  metric 20
10.88.99.0/31 dev enP8p1s0f6  proto kernel  scope link  src 10.88.99.1
10.88.99.2/31 dev enP8p1s0f7d1  proto kernel  scope link  src 10.88.99.3
192.168.1.0/24 dev enP8p1s0f0  proto kernel  scope link  src 192.168.1.10`

# sh ip route
Codes: K - kernel route, C - connected, S - static, R - RIP,
       O - OSPF, I - IS-IS, B - BGP, E - EIGRP, N - NHRP,
       T - Table, v - VNC, V - VNC-Direct, A - Babel, D - SHARP,
       F - PBR, f - OpenFabric,
       > - selected route, * - FIB route, q - queued route, r - rejected route

K>* 0.0.0.0/0 [0/0] via 192.168.1.20, enP8p1s0f0 onlink, 16:28:47
S>* 1.2.3.4/32 [1/0] via 10.88.99.0, enP8p1s0f6, 00:10:24
C>* 10.10.10.10/32 is directly connected, lo, 16:28:46
C>* 10.88.99.0/31 is directly connected, enP8p1s0f6, 16:28:47
C>* 10.88.99.2/31 is directly connected, enP8p1s0f7d1, 16:28:47
B>r 192.168.216.1732 [20/0] via 10.88.99.0, enP8p1s0f6, 00:02:44
  r                         via 10.88.99.2, enP8p1s0f7d1, 00:02:44
C>* 192.168.1.0/24 is directly connected, enP8p1s0f0, 16:28:47```
sworleys commented 4 years ago

Decoded the netlink message and it looks OK I think. Censored your IP.

I will try and test on my box later.

(nl_decode_new) sworley@alfred ~/D/c/eng> python decoder.py pyroute2.netlink.rtnl.rtmsg.rtmsg sent.bin
50:00:00:00:18:00:01:05:b4:00:00:00:ba:e5:cc:e9:02:20:00:00:fe:ba:00:01:00:00:00:00:08:00:01:00:93:4b:c8:62:08:00:06:00:14:00:00:00:24:00:09:00:10:00:00:00:08:00:00:00:08:00:05:00:0a:58:63:00:10:00:00:00:09:00:00:00:08:00:05:00:0a:58:63:02:64:00:00:00:02:00:00:00:b4:00:00:00:ba:e5:cc:e9:ea:ff:ff:ff:50:00:00:00:18:00:
01:05:b4:00:00:00:ba:e5:cc:e9:02:20:00:00:fe:ba:00:01:00:00:00:00:08:00:01:00:93:4b:c8:62:08:00:06:00:14:00:00:00:24:00:09:00:10:00:00:00:08:00:00:00:08:00:05:00:0a:58:63:00:10:00:00:00:09:00:00:00:08:00:05:00:0a:58:63:02
{'attrs': [('RTA_DST', '[NOT POSTING YOUR IP HERE]'),
           ('RTA_PRIORITY', 20),
           ('RTA_MULTIPATH', [{'flags': 0, 'hops': 0, 'oif': 8, 'attrs': [('RTA_GATEWAY', '10.88.99.0')]}, {'flags': 0, 'hops': 0, 'oif': 9, 'attrs': [('RTA_GATEWAY', '10.88.99.2')]}])],
 'dst_len': 32,
 'family': 2,
 'flags': 0,
 'header': {'flags': 1281,
            'length': 80,
            'pid': 3922519482,
            'sequence_number': 180,
            'type': 24},
 'proto': 186,
 'scope': 0,
 'src_len': 0,
 'table': 254,
 'tos': 0,
 'type': 1}
........................................
64:00:00:00:02:00:00:00:b4:00:00:00:ba:e5:cc:e9:ea:ff:ff:ff:50:00:00:00:18:00:01:05:b4:00:00:00:ba:e5:cc:e9:02:20:00:00:fe:ba:00:01:00:00:00:00:08:00:01:00:93:4b:c8:62:08:00:06:00:14:00:00:00:24:00:09:00:10:00:00:00:08:00:00:00:08:00:05:00:0a:58:63:00:10:00:00:00:09:00:00:00:08:00:05:00:0a:58:63:02
{'attrs': [('RTA_UNSPEC', None)],
 'dst_len': 255,
 'family': 234,
 'flags': 83951640,
 'header': {'flags': 0,
            'length': 100,
            'pid': 3922519482,
            'sequence_number': 180,
            'type': 2},
 'proto': 0,
 'scope': 0,
 'src_len': 255,
 'table': 80,
 'tos': 255,
 'type': 0}
........................................
(nl_decode_new) sworley@alfred ~/D/c/eng>