GNOME.org
 

NetworkManager sometimes ignores DHCP setting then later the interface disappears

Hi, I am trying to setup network bridges for virtual machines to bind to, some VMs will bind to a basic bridge and some will bind to a bridge for one particular VLAN. I have found some strange behaviour with NetworkManager with bridge interfaces getting a DHCP IP address despite having ipv4.method set as disabled (although this seems to resolve on a reboot).
I am really struggling to figure out how to fix this. Does anyone have any suggestions? 

I am using the following commands to setup the interfaces...


        nmcli con add ifname br1q con-name br1q type bridge stp no
        nmcli con mod br1q ipv4.method "disabled"
        nmcli con add type bridge-slave master br1q ifname enp6s0 con-name enp6s0 802-3-ethernet.mac-address a8:a1:59:2a:00:e2 
#       nmcli con mod enp6s0 ipv4.method "disabled"
        nmcli con add type vlan vlan.id 100 vlan.parent br1q ifname br1q.100 con-name br1q.100         nmcli con mod br1q.100 ipv4.addresses "192.168.131.6/24" ipv4.gateway "192.168.131.1" ipv4.method "manual" 

# nmcli con show

NAME      UUID                                  TYPE      DEVICE
br1q.100  b772cfca-fd4a-4231-bd2b-b1ee4a1c0b3f  vlan      br1q.100
br1q      bc7d795b-21df-4733-aab2-773bef830ff2  bridge    br1q
enp6s0    146ba781-6990-48b2-87a2-a07e785d772c  ethernet  enp6s0
For some reason br1q gets a DHCP address and br1q.100 appears to have no IP address, even though one is manually configured.
Then a short while later (about 30 seconds) the br1q.100 interface disappears (stops showing up in /proc/net/dev), from the logs this appears to be because of a DHCP timeout. For some reason the newtork interface is deleted because of a DHCP timeout (on an interface that has DHCP disabled). 

# nmcli con show

NAME      UUID                                  TYPE      DEVICE
br1q      bc7d795b-21df-4733-aab2-773bef830ff2  bridge    br1q
enp6s0    146ba781-6990-48b2-87a2-a07e785d772c  ethernet  enp6s0
br1q.100  b772cfca-fd4a-4231-bd2b-b1ee4a1c0b3f  vlan      --
If I reboot the PC then it again comes up as expected (for a short while). br1q has no IP address and br1q.100 has it's manually assigned IP address. All of the interfaces appear as expected. 

# nmcli con show

NAME      UUID                                  TYPE      DEVICE
br1q.100  b772cfca-fd4a-4231-bd2b-b1ee4a1c0b3f  vlan      br1q.100
br1q      bc7d795b-21df-4733-aab2-773bef830ff2  bridge    br1q
enp6s0    146ba781-6990-48b2-87a2-a07e785d772c  ethernet  enp6s0
A short while after the reboot *all* of the interfaces disappear (stops showing up in cat /proc/net/dev) 

# nmcli con show

NAME      UUID                                  TYPE      DEVICE
br1q      70e29069-cd91-4737-9dda-339720dd2848  bridge    --
br1q.100  bda1fc26-e9d7-411f-a72a-252ac9556190  vlan      --
enp6s0    d71e0ff6-46f5-4e51-be3d-20dca12b5c80  ethernet  --
Looking at the logs when I run the commands to configure the networking, I see that br1q gets a DHCP address (not sure why) but br1q.100 does not (no DHCP server available) and then for some reason it just deletes the interface. 

--------------------------------------------
Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9334] dhcp4 (br1q): state changed unknown -> bound Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9345] device (br1q): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed') Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9360] device (br1q): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed') Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9362] device (br1q): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed') Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9372] manager: NetworkManager state is now CONNECTED_SITE Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9373] policy: set 'br1q' (br1q) as default for IPv4 routing and DNS Aug 08 13:14:04 host2.<mydomain>.net dbus-broker-launch[803]: Activation request for 'org.freedesktop.resolve1' failed: The systemd unit 'dbus-org.freedesktop.resolve1.service' could not be found. Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9418] device (br1q): Activation: successful, device activated. Aug 08 13:14:04 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856444.9425] manager: NetworkManager state is now CONNECTED_GLOBAL Aug 08 13:14:04 host2.<mydomain>.net chronyd[793]: Source 192.168.131.24 online Aug 08 13:14:14 host2.<mydomain>.net systemd[1]: NetworkManager-dispatcher.service: Succeeded. Aug 08 13:14:14 host2.<mydomain>.net audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Aug 08 13:14:35 host2.<mydomain>.net chronyd[793]: Selected source 192.168.131.24 Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <warn>  [1596856488.9883] dhcp4 (br1q.100): request timed out Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856488.9884] dhcp4 (br1q.100): state changed unknown -> timeout Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856488.9885] device (br1q.100): state change: ip-config -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed') Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <warn>  [1596856488.9895] device (br1q.100): Activation: failed for connection 'br1q.100' Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856488.9897] device (br1q.100): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed') Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856488.9981] dhcp4 (br1q.100): canceled DHCP transaction Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856488.9982] dhcp4 (br1q.100): state changed timeout -> done Aug 08 13:14:48 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856488.9990] policy: auto-activating connection 'br1q.100' (bda1fc26-e9d7-411f-a72a-252ac9556190) Aug 08 13:14:49 host2.<mydomain>.net NetworkManager[806]: <info>  [1596856489.0107] device (br1q.100): state change: disconnected -> unmanaged (reason 'user-requested', sys-iface-state: 'managed') 
------------------------------------------------
Upon reboot there seem to be some error messages about NetworkManager failing to start, even though it has actually configured the network initially. Then it deactivates all the networking before a log entry saying "startup complete" and "Succeeded" 

-------------------------------------------------

Aug 08 13:20:09 host2.<mydomain>.net login[820]: ROOT LOGIN ON tty1
Aug 08 13:20:09 host2.<mydomain>.net systemd[1]: NetworkManager-dispatcher.service: Succeeded. Aug 08 13:20:09 host2.<mydomain>.net audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Aug 08 13:20:29 host2.<mydomain>.net systemd[1]: NetworkManager-wait-online.service: Main process exited, code=exited, status=1/FAILURE Aug 08 13:20:29 host2.<mydomain>.net audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-wait-online comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed' Aug 08 13:20:29 host2.<mydomain>.net systemd[1]: NetworkManager-wait-online.service: Failed with result 'exit-code'. Aug 08 13:20:29 host2.<mydomain>.net systemd[1]: Failed to start Network Manager Wait Online. Aug 08 13:20:29 host2.<mydomain>.net systemd[1]: Reached target Network is Online. Aug 08 13:20:29 host2.<mydomain>.net systemd[1]: Startup finished in 2.802s (kernel) + 1.766s (initrd) + 31.181s (userspace) = 35.749s. Aug 08 13:20:29 host2.<mydomain>.net systemd[1]: systemd-hostnamed.service: Succeeded. Aug 08 13:20:29 host2.<mydomain>.net audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' 
Aug 08 13:20:29 host2.<mydomain>.net audit: BPF prog-id=31 op=UNLOAD
Aug 08 13:20:29 host2.<mydomain>.net audit: BPF prog-id=30 op=UNLOAD
Aug 08 13:20:34 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856834.9886] device (br1q): state change: ip-config -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed') Aug 08 13:20:34 host2.<mydomain>.net NetworkManager[801]: <warn>  [1596856834.9898] device (br1q): Activation: failed for connection 'br1q' Aug 08 13:20:34 host2.<mydomain>.net audit: ANOM_PROMISCUOUS dev=enp6s0 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295 Aug 08 13:20:34 host2.<mydomain>.net kernel: device enp6s0 left promiscuous mode Aug 08 13:20:34 host2.<mydomain>.net kernel: br1q: port 1(enp6s0) entered disabled state Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0041] device (br1q): detached bridge port enp6s0 Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0054] device (enp6s0): state change: activated -> deactivating (reason 'dependency-failed', sys-iface-state: 'managed') Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0062] device (br1q): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed') Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0074] policy: auto-activating connection 'br1q' (70e29069-cd91-4737-9dda-339720dd2848) Aug 08 13:20:35 host2.<mydomain>.net systemd[1]: Starting Network Manager Script Dispatcher Service... Aug 08 13:20:35 host2.<mydomain>.net systemd[1]: Started Network Manager Script Dispatcher Service. Aug 08 13:20:35 host2.<mydomain>.net audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0475] device (br1q): state change: disconnected -> unmanaged (reason 'user-requested', sys-iface-state: 'managed') Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0488] device (br1q.100): state change: activated -> unmanaged (reason 'unmanaged', sys-iface-state: 'removed') Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0597] manager: NetworkManager state is now DISCONNECTING Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0610] device (enp6s0): state change: deactivating -> disconnected (reason 'dependency-failed', sys-iface-state: 'managed') Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0624] manager: NetworkManager state is now DISCONNECTED Aug 08 13:20:35 host2.<mydomain>.net NetworkManager[801]: <info>  [1596856835.0632] manager: startup complete Aug 08 13:20:44 host2.<mydomain>.net systemd[1]: NetworkManager-dispatcher.service: Succeeded. Aug 08 13:20:44 host2.<mydomain>.net audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' 

--------------------------------------------

Note that I have the following line in the network manager config...

[main]
ignore-carrier=*

--------------------------------------------
Note also that even when an interface has used DHCP to get an ipv4 address, when I run "nmcli con show <interfacename>" it still includes the line... 

ipv4.method:                            manual
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]