Network Manager not working anymore (Ubuntu Core 16)

Hello,

I am a bit puzzled. I am using the network manager and nmcli from my snap which runs on an raspberry pi for a longer time now but since the weekend it is not working anymore.
It seems that it does not find any wifi connections (although they are definitely there and I also checked with two different raspberry pis, so no hardware problem and also did a complete new device setup).
Before that I had no problems with the network manager. Could it be due to a core or kernel update?

I’ve installed the following and followed the installation guide for the network-manager (https://docs.ubuntu.com/core/en/stacks/network/network-manager/docs/installation):

 core             16-2.39                   6961  stable     canonical✓  core 
 network-manager  1.2.2-22        383   stable    canonical✓  -
 pi2-kernel       4.4.0-1110.118            89    stable     canonical✓  kernel
 pi3              16.04-0.7                 30    stable     canonical✓  gadget

Here is a snipped from the syslog:

Jun  5 15:32:55 localhost systemd-networkd[719]: wlan0: Gained carrier
Jun  5 15:32:55 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:32:55 localhost systemd-networkd[719]: wlan0: DHCPv4 address 192.168.178.23/24 via 192.168.178.1
Jun  5 15:32:55 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:32:55 localhost systemd[1]: Starting Update resolvconf for networkd DNS...
Jun  5 15:32:55 localhost wpa_supplicant[2478]: ctrl_iface exists and seems to be in use - cannot override it
Jun  5 15:32:55 localhost wpa_supplicant[2478]: Delete '/run/wpa_supplicant/wlan0' manually if it is not used anymore
Jun  5 15:32:55 localhost wpa_supplicant[2478]: Failed to initialize control interface '/run/wpa_supplicant'.#012You may have another wpa_supplicant process already running or the file was#012left by an unclean termination of wpa_supplicant in which case you will need#012to manually remove this file before starting wpa_supplicant again.
Jun  5 15:32:55 localhost systemd-networkd[719]: wlan0: Lost carrier
Jun  5 15:32:55 localhost systemd-networkd[719]: wlan0: DHCP lease lost
Jun  5 15:32:55 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:32:55 localhost systemd-networkd[719]: wlan0: Gained carrier
Jun  5 15:32:55 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:32:55 localhost systemd-networkd[719]: wlan0: DHCPv4 address 192.168.178.23/24 via 192.168.178.1
Jun  5 15:32:55 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:32:55 localhost systemd[1]: Started Update resolvconf for networkd DNS.
Jun  5 15:32:55 localhost wpa_supplicant[2478]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Jun  5 15:32:55 localhost NetworkManager[3790]: <error> [1559748775.8150] sup-iface[0x2214ef0,wlan0]: error adding interface: wpa_supplicant couldn't grab this interface.
Jun  5 15:32:55 localhost NetworkManager[3790]: <info>  [1559748775.8152] device (wlan0): supplicant interface state: starting -> down
Jun  5 15:32:55 localhost NetworkManager[3790]: <info>  [1559748775.8153] device (wlan0): supplicant interface keeps failing, giving up
Jun  5 15:33:00 localhost wpa_supplicant[942]: wlan0: CTRL-EVENT-DISCONNECTED bssid=98:9b:cb:99:11:4c reason=0 locally_generated=1
Jun  5 15:33:00 localhost systemd-networkd[719]: wlan0: Lost carrier
Jun  5 15:33:00 localhost systemd-networkd[719]: wlan0: DHCP lease lost
Jun  5 15:33:00 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:33:00 localhost systemd[1]: Starting Update resolvconf for networkd DNS...
Jun  5 15:33:00 localhost kernel: [  865.288848] brcmf_cfg80211_reg_notifier: not a ISO3166 code
Jun  5 15:33:00 localhost kernel: [  865.294878] cfg80211: World regulatory domain updated:
Jun  5 15:33:00 localhost kernel: [  865.294897] cfg80211:  DFS Master region: unset
Jun  5 15:33:00 localhost kernel: [  865.294910] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
Jun  5 15:33:00 localhost kernel: [  865.294926] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:00 localhost kernel: [  865.294942] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000 KHz AUTO), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:00 localhost kernel: [  865.294954] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:00 localhost kernel: [  865.294968] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:00 localhost kernel: [  865.294983] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
Jun  5 15:33:00 localhost kernel: [  865.294996] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
Jun  5 15:33:00 localhost kernel: [  865.295009] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:00 localhost kernel: [  865.295021] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
Jun  5 15:33:00 localhost wpa_supplicant[942]: p2p-dev-wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Jun  5 15:33:00 localhost sh[4372]: sed: can't read /run/systemd/netif/leases/*: No such file or directory
Jun  5 15:33:02 localhost sh[4372]: message repeated 2 times: [ sed: can't read /run/systemd/netif/leases/*: No such file or directory]
Jun  5 15:33:03 localhost wpa_supplicant[942]: wlan0: Trying to associate with 98:9b:cb:99:11:4d (SSID='FRITZ!Box 7520 TE' freq=5180 MHz)
Jun  5 15:33:03 localhost wpa_supplicant[942]: wlan0: Associated with 98:9b:cb:99:11:4d
Jun  5 15:33:03 localhost systemd-networkd[719]: wlan0: Gained carrier
Jun  5 15:33:03 localhost systemd-networkd[719]: wlan0: Lost carrier
Jun  5 15:33:03 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:33:03 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:33:03 localhost wpa_supplicant[942]: wlan0: WPA: Key negotiation completed with 98:9b:cb:99:11:4d [PTK=CCMP GTK=CCMP]
Jun  5 15:33:03 localhost wpa_supplicant[942]: wlan0: CTRL-EVENT-CONNECTED - Connection to 98:9b:cb:99:11:4d completed [id=0 id_str=]
Jun  5 15:33:03 localhost systemd-networkd[719]: wlan0: Gained carrier
Jun  5 15:33:03 localhost kernel: [  867.998512] cfg80211: Regulatory domain changed to country: DE
Jun  5 15:33:03 localhost kernel: [  867.998538] cfg80211:  DFS Master region: ETSI
Jun  5 15:33:03 localhost kernel: [  867.998547] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
Jun  5 15:33:03 localhost kernel: [  867.998563] cfg80211:   (2400000 KHz - 2483500 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:03 localhost kernel: [  867.998578] cfg80211:   (5150000 KHz - 5250000 KHz @ 80000 KHz, 200000 KHz AUTO), (N/A, 2000 mBm), (N/A)
Jun  5 15:33:03 localhost kernel: [  867.998593] cfg80211:   (5250000 KHz - 5350000 KHz @ 80000 KHz, 200000 KHz AUTO), (N/A, 2000 mBm), (0 s)
Jun  5 15:33:03 localhost kernel: [  867.998606] cfg80211:   (5470000 KHz - 5725000 KHz @ 160000 KHz), (N/A, 2698 mBm), (0 s)
Jun  5 15:33:03 localhost kernel: [  867.998619] cfg80211:   (5725000 KHz - 5875000 KHz @ 80000 KHz), (N/A, 1397 mBm), (N/A)
Jun  5 15:33:03 localhost kernel: [  867.998631] cfg80211:   (57000000 KHz - 66000000 KHz @ 2160000 KHz), (N/A, 4000 mBm), (N/A)
Jun  5 15:33:03 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
Jun  5 15:33:03 localhost wpa_supplicant[942]: p2p-dev-wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE
Jun  5 15:33:03 localhost systemd-networkd[719]: wlan0: DHCPv4 address 192.168.178.23/24 via 192.168.178.1
Jun  5 15:33:03 localhost systemd-timesyncd[804]: No network connectivity, watching for changes.
1 Like

Short update on this:

I tried to use Ubuntu Core 18 but I get the same issue.

If I install network-manager very quickly after a new setup of a raspberry pi (before all updates on the core, … snaps are performed -> core18 18 721 stable), it seems to be working. After the update (-> core18 20190508 974) it fails.

If I install wpa-supplicant manually before the network-manager I see at least some wifi connections and I can establish connections but it is not running smoothly and I run into bugs and things which are not working.

This is really a big issue for us because it destroys our complete application and probably just because of a software update. Is this possible?
It would be fantastic if you could help here quickly.

Thanks

Do you see any apparmor denials in dmesg output? Could you please also share the output of snap interfaces?

Also, the list of snaps in your first message show UC16, byt then you mention UC18. What image are you using, UC16 or UC18? And which NM version/channel?

1 Like

Thanks for your reply.

I tested first on core16 and later I tried on core18. I get the same result on both.

All network-manager interfaces are connected except for:

-                         network-manager:modem-manager
-                         network-manager:wpa

I get no denials in the logs if I execute any nmcli command, e.g. nmcli d wifi list. Though I just get no result at all, no wifis are shown.

But I found out something: Network-manager is working if I do not setup a wifi initially (during raspberry pi setup) but use an ethernet connection. If I install afterwards network-manager it is working. So looks like the initial wifi-setup during startup is mixing up the network-manager configuration. Any idea why this might be the case?

Do things improve if you run the following:

snap connect network-manager:wpa wpa-supplicant:service

With that plug disconnected, the AppArmor policy would prevent the two services from communicating. That would likely break wifi support.

It doesn’t look like the stable channels of either network-manager or wpa-supplicant have changed in months though, so I wonder what happened? There is a new 1.10 track on network-manager though, so I wonder if something was temporarily pushed that broke the interface connection?

With that plug disconnected, the AppArmor policy would prevent the two services from communicating. That would likely break wifi support.

Not really, the interface needs to be connected exclusively if using the wpa-supplicant snap. Usually, the snap is not installed and wpa-supplicant from the core snap is the one being used. So no, that is not the reason for this problem, most probably.

It is possible that there is a conflict between the wifi configuration from console setup, which uses networkd, and the one from NM. I recommend that you remove the wifi connection from networkd before configuring one from NM - you need to use one or another.

Also, please do not install the wpa-supplicant snap - you do not need it. NM can use the one included in the core snap. The wpa-supplicant snap is of interest only if you want to use WoWLAN.

Thanks for your replies and help
I tried wpa-supplicant before but as you said it won’t help, just made things worse.
As you said the conflict between networkd and NM seems to be the problem. I got it working now and maybe this gets improved in the future.