[Bug 1860926] Re: Ubuntu 20.04 Systemd fails to configure bridged network

[Dan Streetman]

This happens because the bridge interface comes up with carrier
(specifically, with +LOWER_UP interface flag) and begins setting its
addresses/routes, but then briefly loses carrier.  I'm not sure why the
bridge comes up with +LOWER_UP when ens3 appears to *not* be up:

Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Flags change: +UP +LOWER_UP +RUNNING
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Link UP
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Gained carrier
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Setting addresses
...
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Remembering updated address: 192.168.122.105/24 (valid forever)
...
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Flags change: -LOWER_UP
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Lost carrier
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Removing address 192.168.122.105
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: State is configuring, dropping config
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: ens3: Joined netdev
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: ens3: Bringing link up
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Flags change: -RUNNING
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Remembering updated address: 192.168.122.105/24 (valid forever)
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Addresses set
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Configuring route: dst: n/a, src: n/a, gw: 192.168.122.1, prefsrc: n/a, scope: global, table: main, proto: static, type: unicast
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Setting routes
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Forgetting address: 192.168.122.105/24 (valid forever)
...
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: ens3: Flags change: +UP +LOWER_UP +RUNNING
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: ens3: Link UP
...
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: ens3: Gained carrier
...
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Flags change: +LOWER_UP +RUNNING
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Gained carrier
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Setting addresses
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Could not set route: Nexthop has invalid gateway. Network is unreachable
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Failed
...
Apr 27 10:46:56 lp1860926-f systemd-networkd[643]: br0: Remembering updated address: 192.168.122.105/24 (valid forever)


Note that on carrier loss, networkd begins removing the address, but doesn't actually complete address removal until after carrier is back up, which then causes setting the network route to fail, right before the address is added again.


With upstream systemd, this doesn't happen, because the bridge interface
comes up without carrier (again, specifically, without +LOWER_UP
interface flag):

Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Flags change: +UP
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Link UP
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Remembering updated address: 192.168.122.231/24 (valid forever)
...
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Addresses set
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Configuring route: dst: n/a, src: n/a, gw: 192.168.122.1, prefsrc: n/a, scope: global, table: main, proto: static, type: unicast
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Setting routes
...
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: ens3: Joined netdev
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: ens3: Bringing link up
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Received remembered route: dst: n/a, src: n/a, gw: 192.168.122.1, prefsrc: n/a, scope: global, table: main, proto: static, type: unicast
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Routes set
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: State changed: configuring -> configured
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: ens3: Flags change: +UP +LOWER_UP +RUNNING
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: ens3: Link UP
...
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: ens3: Gained carrier
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: ens3: State changed: configuring -> configured
...
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Flags change: +LOWER_UP +RUNNING
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Gained carrier
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: State changed: configured -> configuring
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Setting addresses
...
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Remembering updated address: 192.168.122.231/24 (valid forever)
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Addresses set
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Configuring route: dst: n/a, src: n/a, gw: 192.168.122.1, prefsrc: n/a, scope: global, table: main, proto: static, type: unicast
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Setting routes
Apr 27 10:23:05 lp1860926-u systemd-networkd[600]: br0: Routes set


Note in both situations, the bridge interface happens twice.  This is because netplan adds ConfigureWithoutCarrier=yes to the bridge configuration, which causes networkd to start configuring the bridge before it's ready.  However, netplan doesn't also set IgnoreCarrierLoss=yes, so networkd removes the bridge configuration when it detects carrier loss, which results in a race condition to re-setup the bridge when the carrier is lost, since the loss happens in the middle of initial configuration.

If the networkd configuration is changed to remove
ConfigureWithoutCarrier=yes (or set it to no/false), or if the networkd
configuration is changed to add IgnoreCarrierLoss=yes (and leave
ConfigureWithoutCarrier=yes), then this bug *appears* fixed, at least in
my testing.  However, I'm still concerned about this race and I haven't
had time to fully analyze the situation of carrier drop during
configuration; I feel like this is still a potential issue regardless of
the ConfigureWithoutCarrier and/or IgnoreCarrierLoss settings.

For now, I'll build a test kernel that defaults IgnoreCarrierLoss= to
the value of ConfigureWithoutCarrier= (and open an upstream bug) to see
if that also fixes this for others affected.

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1860926

Title:
  Ubuntu 20.04  Systemd fails to configure bridged network

Status in systemd package in Ubuntu:
  Confirmed
Status in systemd source package in Focal:
  Confirmed

Bug description:
  [impact]

  A bridged interface with static ipv4 address and gateway configuration
  will fail to properly add the route via the gateway, leaving the
  system without a globally working network.

  [test case]

  On a Focal system, remove all network configuration and create this
  netplan:

  network:
    version: 2
    renderer: networkd
    ethernets:
      enp4s0:
        dhcp4: false
    bridges:
      br0:
        interfaces: [enp4s0]
        dhcp4: no
        addresses: [192.168.0.4/24]
        gateway4: 192.168.0.1
        nameservers:
          search: [mydomain]
          addresses: [192.168.0.1,192.168.0.2,192.168.0.3]

  Replace the interface name 'enp4s0' with the actual interface name on
  the test system.

  Reboot the system, and check the route to the gateway, which will be
  missing:

  root at lp1860926-f:~# ip r
  192.168.0.0/24 dev br0 proto kernel scope link src 192.168.0.4

  The route is expected to be present, e.g.:

  ubuntu at lp1860926-e:~$ ip r
  default via 192.168.0.1 dev br0 proto static
  192.168.0.0/24 dev br0 proto kernel scope link src 192.168.0.4

  [regression potential]

  Not SRU - N/A

  [scope]

  This is not reproducable on Eoan or Bionic; this is needed only for
  Focal.

  [original description]

  Freshly installed Ubuntu 20.04 fully patched to days date with static
  IP address works fine and survives a reboot

  network:
    version: 2
    renderer: networkd
    ethernets:
      enp4s0:
        dhcp4: false
        addresses: [192.168.0.4/24]
        gateway4: 192.168.0.1
        nameservers:
          search: [mydomain]
          addresses: [192.168.0.1,192.168.0.2,192.168.0.3]

  however when converted to a bridged network for kvm

  network:
    version: 2
    renderer: networkd
    ethernets:
      enp4s0:
        dhcp4: false
    bridges:
      br0:
        interfaces: [enp4s0]
        dhcp4: no
        addresses: [192.168.0.4/24]
        gateway4: 192.168.0.1
        nameservers:
          search: [mydomain]
          addresses: [192.168.0.1,192.168.0.2,192.168.0.3]

  will not survive a reboot and required systemd-network to be restarted or
  @reboot /usr/sbin/netplan apply
  added to the crontab

  after a reboot the network can not b eaccseed and a
  systemctl status systemd-networkd produces

  systemd-networkd.service - Network Service
       Loaded: loaded (/lib/systemd/system/systemd-networkd.service; enabled; vendor preset: enabled)
       Active: active (running) since Sun 2020-01-26 16:36:28 UTC; 2min 27s ago
  TriggeredBy: ● systemd-networkd.socket
         Docs: man:systemd-networkd.service(8)
     Main PID: 979 (systemd-network)
       Status: "Processing requests..."
        Tasks: 1 (limit: 57662)
       Memory: 4.1M
       CGroup: /system.slice/systemd-networkd.service
               └─979 /lib/systemd/systemd-networkd

  Jan 26 16:38:02 firebolt systemd-networkd[979]: rtnl: received neighbor for link '5' we don't know about, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Link UP
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Gained carrier
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0: Link UP
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Link DOWN
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Lost carrier
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Kernel removed an address we don't remember: fe80::5054:ff:fed9:7e26/64 (valid forever), ignoring.

  systemctl restart systemd-networkd resolved the issue and a

  systemctl status systemd-network producessystemd-networkd.service - Network Service
       Loaded: loaded (/lib/systemd/system/systemd-networkd.service; enabled; vendor preset: enabled)
       Active: active (running) since Sun 2020-01-26 16:39:28 UTC; 41s ago
  TriggeredBy: ● systemd-networkd.socket
         Docs: man:systemd-networkd.service(8)
     Main PID: 1650 (systemd-network)
       Status: "Processing requests..."
        Tasks: 1 (limit: 57662)
       Memory: 1.6M
       CGroup: /system.slice/systemd-networkd.service
               └─1650 /lib/systemd/systemd-networkd

  Jan 26 16:39:28 firebolt systemd[1]: Starting Network Service...
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: netdev ready
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: Gained IPv6LL
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: Enumeration completed
  Jan 26 16:39:28 firebolt systemd[1]: Started Network Service.
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: netdev exists, using existing without changing its parameters
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: IPv6 successfully enabled

  a journalctl -u systemd-network produces

  Jan 26 16:36:28 firebolt systemd[1]: Starting Network Service...
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: netdev ready
  Jan 26 16:36:28 firebolt systemd-networkd[979]: Enumeration completed
  Jan 26 16:36:28 firebolt systemd-networkd[979]: wlp3s0: Interface name change detected, wlp3s0 has been renamed to wlan0.
  Jan 26 16:36:28 firebolt systemd[1]: Started Network Service.
  Jan 26 16:36:28 firebolt systemd-networkd[979]: wlan0: Interface name change detected, wlan0 has been renamed to wlp3s0.
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: IPv6 successfully enabled
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: Link UP
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: Gained carrier
  Jan 26 16:36:28 firebolt systemd-networkd[979]: enp4s0: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:36:28 firebolt systemd-networkd[979]: enp4s0: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: Lost carrier
  Jan 26 16:36:28 firebolt systemd-networkd[979]: enp4s0: Link UP
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: Gained carrier
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: Could not set route: Network is unreachable
  Jan 26 16:36:28 firebolt systemd-networkd[979]: br0: Failed
  Jan 26 16:36:30 firebolt systemd-networkd[979]: br0: Lost carrier
  Jan 26 16:36:31 firebolt systemd-networkd[979]: enp4s0: Gained carrier
  Jan 26 16:36:31 firebolt systemd-networkd[979]: br0: Gained carrier
  Jan 26 16:38:02 firebolt systemd-networkd[979]: rtnl: received neighbor for link '5' we don't know about, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0: rtnl: received neighbor message with invalid family, ignoring.
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Link UP
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Gained carrier
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0: Link UP
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Link DOWN
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Lost carrier
  Jan 26 16:38:02 firebolt systemd-networkd[979]: virbr0-nic: Kernel removed an address we don't remember: fe80::5054:ff:fed9:7e26/64 (valid forever), ignoring.
  Jan 26 16:39:28 firebolt systemd[1]: Stopping Network Service...
  Jan 26 16:39:28 firebolt systemd[1]: systemd-networkd.service: Succeeded.
  Jan 26 16:39:28 firebolt systemd[1]: Stopped Network Service.
  Jan 26 16:39:28 firebolt systemd[1]: Starting Network Service...
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: netdev ready
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: Gained IPv6LL
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: Enumeration completed
  Jan 26 16:39:28 firebolt systemd[1]: Started Network Service.
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: netdev exists, using existing without changing its parameters
  Jan 26 16:39:28 firebolt systemd-networkd[1650]: br0: IPv6 successfully enabled

  the network should restart properly after a reboot liek in earlier
  version of ubuntu 18.04 for example

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/systemd/+bug/1860926/+subscriptions