NetworkManager fails to auto-activate wifi connection
NetworkManager fails to auto-activate wifi connection
Our system uses NetworkManager-1.24.2 and wpa_supplicant v2.9. Sometimes the wifi connection doesn't restore after we disable and enable our AP. I did some tracing and it looks like this is cause by NM.
Here's what happens:
- wifi successfully connects to AP "MikroTik-98786C".
- disable AP "MikroTik-98786C"
- enable AP (after e.g. 10 or 20 minutes)
- wifi fails to reconnect to AP "MikroTik-98786C".
It doesn't happen all the time, sometimes it works, sometimes it doesn't. In both cases the NM config and the "MikroTik-98786C" connection is configured exactly the same way. I'll attach MikroTik-98786C.nmconnection file as well as the some other relevant nm config settings.
In case it doesn't work, detailed NM logging shows the following at the moment we disable the AP.
daemon.debug NetworkManager[1352]: <debug> [1606438659.1524] device[011c29240929033b] (wlan0): wifi-scan: start periodic scan (2 SSIDs to probe scan [(empty), "MikroTik-98786C"])
daemon.debug NetworkManager[1352]: <trace> [1606438659.1527] sup-iface[1129bfb52c55b2c1,0,wlan0]: request-scan: request scanning (2 ssids)...
daemon.debug NetworkManager[1352]: <debug> [1606438659.1649] sup-iface[1129bfb52c55b2c1,0,wlan0]: request-scan: could not get scan request result: GDBus.Error:fi.w1.wpa_supplicant1.Interface.ScanError: Scan request rejected
daemon.debug NetworkManager[1352]: <trace> [1606438660.1335] sup-iface[1129bfb52c55b2c1,0,wlan0]: scanning: no (plain property)
daemon.debug NetworkManager[1352]: <trace> [1606438660.1634] sup-iface[1129bfb52c55b2c1,0,wlan0]: BSS /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/41153 updated
daemon.debug NetworkManager[1352]: <trace> [1606438660.1701] dbus-object[48a1fedc90922ca0]: export: "/org/freedesktop/NetworkManager/AccessPoint/41269"
daemon.debug NetworkManager[1352]: <trace> [1606438660.2686] sup-iface[1129bfb52c55b2c1,0,wlan0]: BSS /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/41054 updated
daemon.debug NetworkManager[1352]: <trace> [1606438660.2782] sup-iface[1129bfb52c55b2c1,0,wlan0]: BSS /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/41055 updated
and that is the last thing we receive from "device[011c29240929033b] (wlan0)"! There is no "... device[011c29240929033b] (wlan0): failed to match hidden AP C8:67:5E:5A:EE:14" entry nor any new "wifi-scan" or "add_pending_action" entries (which we do see in case it works). It certainly looks like this causes NM to be unaware of MikroTik-98786C which is why it won't reconnect. In case it works the log shows: daemon.info NetworkManager[1352]: [1606438104.5839] policy: auto-activating connection 'MikroTik-98786C' (6103392e-33b6-4392-c310-06542b92d4ec) I'll attach the full logs for the SUCCESS and FAILURE case.
I also examined what is happening on the wpa_supplicant D-Bus control interface. It looks like wpa_supplicant seems to respond fine to the "request-scan" from NM, in the failure case this is what happens:
signal time=1606482646.046717 sender=:1.26 -> destination=(null destination) serial=391840 path=/fi/w1/wpa_supplicant1/Interfaces/0; interface=fi.w1.wpa_supplicant1.Interface; member=PropertiesChanged, Scanning true
method call time=1606482646.657208 sender=:1.8 -> destination=:1.26 serial=782168 path=/fi/w1/wpa_supplicant1/Interfaces/0; interface=fi.w1.wpa_supplicant1.Interface; member=Scan, active, AllowRoam=false, MikroTik-98786C + ""
signal time=1606482648.534512 sender=:1.26 -> destination=(null destination) serial=391846 path=/fi/w1/wpa_supplicant1/Interfaces/0; interface=fi.w1.wpa_supplicant1.Interface; member=ScanDone, true
signal time=1606482648.549884 sender=:1.26 -> destination=(null destination) serial=391848 path=/fi/w1/wpa_supplicant1/Interfaces/0; interface=fi.w1.wpa_supplicant1.Interface; member=PropertiesChanged, Scanning false
<NO MORE SCAN>
after wpa_supplicant responded with ScanDone=true and "PropertiesChanged, Scanning false" there are no new NM scanning requests. In case things do work, NM will issue a new "interface=fi.w1.wpa_supplicant1.Interface; member=Scan" request (with arguments: active, AllowRoam=false, MikroTik-98786C + "")
If you want the detailed D-Bus ctrl i/f logs or any other additional log or info, please let me know.
We'd really like to solve this issue (even though currently we workaround by manually setting up the connection with "nmcli c up MikroTik-98786C").