BFD protocol doesn't send packets after link flap up on switch
Hi, I have multihop BGP peering with BFD setup on it. One of the peers is a switch that runs Linux. I've run into situation where after link flap on interface that switch connects to BFD protocol after successfully detecting that flap BFD session cannot reestablich because switch side stops sending BFD packets. I'm suspecting that this is due to switch behavior that removes IP address of link when it goes down (BGP and BFD are using interface ip address to connect). Bird is trying to bind to IP address that is no longer available and that causes the issue. Logs below show following events 1. Correct BFD packet exchange 2. Link flaps at 14:07:38 3. Link is back up, starts receiving BFD packets from peer and state changes from Down to Init at 14:07:45. Note that no BFD packets are being generated, where they should be. 4. Removing 'bfd;' line and reconfiguring at 14:08:31 5. Adding 'bfd; line and reconfiguring at 14:08:47 which successfully restart BFD. 2018-08-24 14:07:37 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:07:37 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 expired 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 changed state from Up to Down 2018-08-24 14:07:38 <TRACE> bgp_gw_rs_1: BFD session down 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 removed 2018-08-24 14:07:38 <ERR> bfd1: Socket error: bind: Cannot assign requested address 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 added 2018-08-24 14:07:44 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:44 <TRACE> bfd1: Session to 172.30.2.1 changed state from Down to Init 2018-08-24 14:07:45 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:46 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:46 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] ... 2018-08-24 14:08:30 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:08:31 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:08:31 <TRACE> bfd1: Session to 172.30.2.1 removed 2018-08-24 14:08:31 <TRACE> bfd1: Reconfigured 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 added 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 reconfigured 2018-08-24 14:08:47 <TRACE> bfd1: Reconfigured 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 changed state from Down to Init 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Init A] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up PA] 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 changed state from Init to Up 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up FA] 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up PA] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up FA] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] Kuba Nowacki
I've found a workaround for this issue. Seems that crucial is line "2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 added" I'm assuming what's happening here is that Bird selects another interface as source which doesn't have connectivity and never goes back to proper interface after it comes back up. As a workaround I've used explicit BFD neighbor declaration with local IP specified: "neighbor ip [dev "interface"] [local ip] [multihop switch]" After adding this line to config BFD started working as expected. Above behavior might be however problematic with higher number of peers. On Fri, Aug 24, 2018 at 2:45 PM Jakub Nowacki <jnowacki@greywizard.com> wrote:
Hi,
I have multihop BGP peering with BFD setup on it. One of the peers is a switch that runs Linux. I've run into situation where after link flap on interface that switch connects to BFD protocol after successfully detecting that flap BFD session cannot reestablich because switch side stops sending BFD packets. I'm suspecting that this is due to switch behavior that removes IP address of link when it goes down (BGP and BFD are using interface ip address to connect). Bird is trying to bind to IP address that is no longer available and that causes the issue.
Logs below show following events 1. Correct BFD packet exchange 2. Link flaps at 14:07:38 3. Link is back up, starts receiving BFD packets from peer and state changes from Down to Init at 14:07:45. Note that no BFD packets are being generated, where they should be. 4. Removing 'bfd;' line and reconfiguring at 14:08:31 5. Adding 'bfd; line and reconfiguring at 14:08:47 which successfully restart BFD.
2018-08-24 14:07:37 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:07:37 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:07:38 <ERR> bfd1: Socket error: Invalid argument 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 expired 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 changed state from Up to Down 2018-08-24 14:07:38 <TRACE> bgp_gw_rs_1: BFD session down 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 removed 2018-08-24 14:07:38 <ERR> bfd1: Socket error: bind: Cannot assign requested address 2018-08-24 14:07:38 <TRACE> bfd1: Session to 172.30.2.1 added 2018-08-24 14:07:44 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:44 <TRACE> bfd1: Session to 172.30.2.1 changed state from Down to Init 2018-08-24 14:07:45 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:46 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:46 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:07:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] ... 2018-08-24 14:08:30 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:08:31 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:08:31 <TRACE> bfd1: Session to 172.30.2.1 removed 2018-08-24 14:08:31 <TRACE> bfd1: Reconfigured 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 added 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 reconfigured 2018-08-24 14:08:47 <TRACE> bfd1: Reconfigured 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Down A] 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 changed state from Down to Init 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Init A] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up PA] 2018-08-24 14:08:47 <TRACE> bfd1: Session to 172.30.2.1 changed state from Init to Up 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up FA] 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up PA] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up FA] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A] 2018-08-24 14:08:47 <TRACE> bfd1: CTL received from 172.30.2.1 [Up A] 2018-08-24 14:08:47 <TRACE> bfd1: Sending CTL to 172.30.2.1 [Up A]
Kuba Nowacki
-- Kuba Nowacki Senior NetOps M: +(48) 605 508 118 E: jnowacki@greywizard.com GreyWizard Sp. z o.o. ul. Palacza 113 60-273 Poznań, Poland NIP: 779-24-22-423 Regon: 302744400 KRS: 0000512326 greywizard.com support@greywizard.com +48 22 201 33 13 Sąd Rejonowy w Poznaniu, VIII Wydział Gospodarczy Krajowego Rejestru Sądowego. Kapitał zakładowy 10000 PLN.
participants (1)
-
Jakub Nowacki