neutron

  1. Bug #2024481
  2. Comment #0

Comment 0 for bug 2024481

Revision history for this message
Dmitrii Shcherbakov (dmitriis) wrote :

Hit a race with the Antelope (22.0.0) version of NDR in one of our functional test runs:

1) neutron-bgp-dragent got restarted right before creating a speaker and adding an external network and tenant network to it;
2) As can be seen in the service log below, just after neutron-bgp-dragent started, it tried to advertise a route (00:03:21.766) before a speaker got added to it (00:03:22.251).
https://github.com/openstack/neutron-dynamic-routing/blob/13e0d8a63dbdbd9e1a863144999794d4fc9af22d/neutron_dynamic_routing/services/bgp/agent/driver/os_ken/driver.py#L150-L154

3) As a result, the peer (FRR in our case) only got a floating IP route (/32) in the test result in the tenant network route (/24) was never advertised.

Test steps (downstream) that generated the log lines: https://github.com/openstack-charmers/zaza-openstack-tests/blob/edd7717dc2ca300cfb94729d9d6bb7021787906c/zaza/openstack/configure/bgp_speaker.py#L65-L100

The lack of a route at the peer side can be seen at 2023-06-19 00:03:32 here:
https://openstack-ci-reports.ubuntu.com/artifacts/e4c/886157/8/check/jammy-antelope-ovn/e4c9b5d/job-output.txt
2023-06-19 00:03:32.346994 | focal-medium |
2023-06-19 00:03:32.347012 | focal-medium | B>* 100.64.0.144/32 [20/0] via 172.16.27.207, ens3, weight 1, 00:00:07
2023-06-19 00:03:32.347045 | focal-medium |

Summary: It looks like neutron-bgp-dragent may try to advertise routes it gets from a DB before a speaker is added by it. It should properly make sure a speaker is present before trying to advertise routes. If speakers aren't scheduled to it yet, it should attempt to advertise as soon as one is present on it.

-------

Functional test log:

2023-06-19 00:03:19.709430 | focal-medium | 2023-06-19 00:03:19 [INFO] Setting up BGP speaker
2023-06-19 00:03:20.307141 | focal-medium | 2023-06-19 00:03:20 [INFO] Creating BGP Speaker
2023-06-19 00:03:20.434428 | focal-medium | 2023-06-19 00:03:20 [INFO] Advertising BGP routes
2023-06-19 00:03:20.678231 | focal-medium | 2023-06-19 00:03:20 [INFO] Advertising ext_net network on BGP Speaker bgp-speaker
2023-06-19 00:03:20.919232 | focal-medium | 2023-06-19 00:03:20 [INFO] Advertising private network on BGP Speaker bgp-speaker
2023-06-19 00:03:21.155337 | focal-medium | 2023-06-19 00:03:21 [INFO] Setting up BGP peer
2023-06-19 00:03:22.099859 | focal-medium | 2023-06-19 00:03:22 [INFO] Creating BGP Peer
2023-06-19 00:03:22.142524 | focal-medium | 2023-06-19 00:03:22 [INFO] Adding BGP peer to BGP speaker
2023-06-19 00:03:22.143374 | focal-medium | 2023-06-19 00:03:22 [INFO] Adding peer osci-frr on BGP Speaker bgp-speaker
2023-06-19 00:03:22.208265 | focal-medium | 2023-06-19 00:03:22 [INFO] Creating floating IP to advertise
2023-06-19 00:03:22.301280 | focal-medium | 2023-06-19 00:03:22 [INFO] Creating port: NDR_TEST_FIP
2023-06-19 00:03:23.599942 | focal-medium | 2023-06-19 00:03:23 [INFO] Creating floatingip
2023-06-19 00:03:26.351808 | focal-medium | 2023-06-19 00:03:26 [INFO] Advertised floating IP: 100.64.0.144

neutron-bgp-dragent.log:

2023-06-19 00:03:20.751 26428 INFO neutron.common.config [-] Logging enabled!
2023-06-19 00:03:20.751 26428 INFO neutron.common.config [-] /usr/bin/neutron-bgp-dragent version 22.0.0
2023-06-19 00:03:21.533 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [-] Initializing os-ken driver for BGP functionality.
2023-06-19 00:03:21.533 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [-] Initialized os-ken BGP Speaker driver interface with bgp_router_id=172.16.0.46
2023-06-19 00:03:21.578 26428 INFO neutron_dynamic_routing.services.bgp.agent.bgp_dragent [-] BGP dynamic routing agent started
2023-06-19 00:03:21.748 26428 INFO bgpspeaker.api.base [None req-3e563ce5-7b78-46d2-9dd3-02067da4e197 - - - - - -] API method core.start called with args: {'waiter': <os_ken.lib.hub.Event object at 0x7fb16c0c6950>, 'local_as': 4279238701, 'router_id': '172.16.0.46', 'bgp_server_hosts': ('0.0.0.0', '::'), 'bgp_server_port': 0, 'refresh_stalepath_time': 0, 'refresh_max_eor_time': 0, 'label_range': (100, 100000), 'allow_local_as_in_count': 0, 'cluster_id': None, 'local_pref': 100}
2023-06-19 00:03:21.766 26428 ERROR neutron_dynamic_routing.services.bgp.agent.bgp_dragent [None req-f082fe6d-cb70-4761-b02d-19f38bda7ae2 - - - - - -] Call to driver for BGP Speaker 04d9b59c-e4b9-4756-92b3-df364fa7bd0d advertise_route has failed with exception BGP Speaker for local_as=4279238701 with router_id=172.16.0.46 not added yet..: neutron_dynamic_routing.services.bgp.agent.driver.exceptions.BgpSpeakerNotAdded: BGP Speaker for local_as=4279238701 with router_id=172.16.0.46 not added yet.
2023-06-19 00:03:21.768 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [None req-3e563ce5-7b78-46d2-9dd3-02067da4e197 - - - - - -] Added BGP Speaker for local_as=4279238701 with router_id= 172.16.0.46.
2023-06-19 00:03:22.249 26428 INFO bgpspeaker.api.base [None req-eac9e066-f8a0-417e-a2cb-9c5995f1011d 166ebaf50413428c83ab07b94245479d 61efb6f767ed4ac39728f0e96f87a7f6 - - 729a6868d7ef40cea300ac221475d98e 729a6868d7ef40cea300ac221475d98e] API method neighbor.create called with args: {'connect_mode': 'active', 'is_next_hop_self': False, 'cap_mbgp_ipv6': True, 'is_route_server_client': False, 'remote_as': 4279238721, 'is_route_reflector_client': False, 'cap_enhanced_refresh': False, 'cap_mbgp_l2vpnfs': False, 'cap_mbgp_ipv4fs': False, 'cap_mbgp_vpnv4': False, 'cap_mbgp_ipv6fs': False, 'cap_mbgp_vpnv6fs': False, 'peer_next_hop': None, 'cap_mbgp_ipv4': True, 'cap_mbgp_vpnv4fs': False, 'cap_four_octet_as_number': True, 'ip_address': '172.16.0.66', 'cap_mbgp_vpnv6': False, 'remote_port': 179, 'cap_mbgp_evpn': False}
2023-06-19 00:03:22.251 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [None req-eac9e066-f8a0-417e-a2cb-9c5995f1011d 166ebaf50413428c83ab07b94245479d 61efb6f767ed4ac39728f0e96f87a7f6 - - 729a6868d7ef40cea300ac221475d98e 729a6868d7ef40cea300ac221475d98e] Added BGP Peer 172.16.0.66 for remote_as=4279238721 to BGP Speaker running for local_as=4279238701.
2023-06-19 00:03:23.261 26428 INFO bgpspeaker.peer [-] Connection to peer: 172.16.0.66 established
2023-06-19 00:03:23.263 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [-] BGP Peer 172.16.0.66 for remote_as=23456 is UP.
2023-06-19 00:03:24.370 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [-] Best path change observed. cidr=172.16.0.0/16, nexthop=172.16.0.66, remote_as=4279238721, is_withdraw=False
2023-06-19 00:03:25.450 26428 INFO bgpspeaker.api.base [None req-af11f291-7671-4ff9-bce2-d7a8dedd5037 - - - - - -] API method network.add called with args: {'prefix': '100.64.0.144/32', 'next_hop': '172.16.27.207'}
2023-06-19 00:03:25.451 26428 INFO neutron_dynamic_routing.services.bgp.agent.driver.os_ken.driver [None req-af11f291-7671-4ff9-bce2-d7a8dedd5037 - - - - - -] Route cidr=100.64.0.144/32, nexthop=172.16.27.207 is advertised for BGP Speaker running for local_as=4279238701.
2023-06-19 00:03:25.507 26428 ERROR bgpspeaker.peer [-] AS_PATH on UPDATE message has loops. Ignoring this message: BGPUpdate(len=53,nlri=[BGPNLRI(addr='100.64.0.144',length=32)],path_attributes=[BGPPathAttributeOrigin(flags=64,length=1,type=1,value=0), BGPPathAttributeAsPath(flags=80,length=10,type=2,value=[[4279238721, 4279238701]]), BGPPathAttributeNextHop(flags=64,length=4,type=3,value='172.16.0.66')],total_path_attribute_len=25,type=2,withdrawn_routes=[],withdrawn_routes_len=0)