Home / ubuntu / Questions / 1245903
In Process
pip1726
Asked: 2020-06-02 12:42:22 +0800 CST

Network sporadicatlly freezes while performing a wifi-scan Ubuntu 20.04

  • 772

After upgrading from Ubuntu 18.04 to 20.04 (network-manager version 1.22.10-1ubuntu2.1), I am getting sporadic WiFi network connectivity. I'm using the r88x2bu network driver from the rtl88x2bu-dkms package. I can be browsing and suddenly the connection drops for a minute or two, and then it eventually reconnects. The problem is so persistent that it makes simple tasks such as browsing almost impossible. I tried exploring different paths to debug this problem.

I don't think this problem is related to a DDos, since all of my other devices in the network are receiving about the same amount of incoming traffic.

Exploring the NetworkManager and wpa-supplicant debug logs, I see that when the issue arises, the logs look as follows. The network-manager starts a wifi-scan and network requests are blocked until the wifi-scan is successfully done. 

Jun 03 16:45:35 pipemon-desktop NetworkManager[1140]: <debug> [1591217135.3233] device[2daeef8128d7ad35] (wlx74ee2af4348b): wifi-scan: scanning requested but not allowed at this time
Jun 03 16:45:35 pipemon-desktop NetworkManager[1140]: <debug> [1591217135.3233] device[2daeef8128d7ad35] (wlx74ee2af4348b): wifi-scan: scheduled in 120 seconds (interval now 120 seconds)
Jun 03 16:45:41 pipemon-desktop kernel: [UFW BLOCK] IN=wlx74ee2af4348b OUT= MAC=74:ee:2a:f4:34:8b:40:ce:24:74:a9:b2:08:00 SRC=18.20.245.218 DST=18.20.198.88 LEN=40 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=TCP SPT=631 DPT=34756 WINDOW=0 RES=0x00 RST URGP=0
Jun 03 16:45:59 pipemon-desktop kernel: [UFW BLOCK] IN=wlx74ee2af4348b OUT= MAC=74:ee:2a:f4:34:8b:40:ce:24:74:a9:b2:08:00 SRC=5.188.210.109 DST=18.20.198.88 LEN=40 TOS=0x00 PREC=0x00 TTL=241 ID=58332 PROTO=TCP SPT=56836 DPT=8080 WINDOW=1024 RES=0x00 SYN URGP=0
Jun 03 16:46:07 pipemon-desktop kernel: [UFW BLOCK] IN=wlx74ee2af4348b OUT= MAC=74:ee:2a:f4:34:8b:40:ce:24:74:a9:b2:08:00 SRC=52.114.128.10 DST=18.20.198.88 LEN=40 TOS=0x00 PREC=0x00 TTL=112 ID=18141 DF PROTO=TCP SPT=443 DPT=47960 WINDOW=0 RES=0x00 ACK RST URGP=0
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Remove id 89198 BSSID c4:6e:1f:2c:89:42 SSID 'PRG-IRCP2.4' due to wpa_bss_flush_by_age
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89198'
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Remove id 89199 BSSID 58:f3:9c:f0:e7:eb SSID 'eduroam' due to wpa_bss_flush_by_age
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89199'
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Remove id 89200 BSSID 58:f3:9c:af:d2:12 SSID 'MIT SECURE' due to wpa_bss_flush_by_age
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89200'
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Remove id 89201 BSSID 58:f3:9c:af:d2:13 SSID '\x00' due to wpa_bss_flush_by_age
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89201'
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Remove id 89202 BSSID 58:f3:9c:f0:e7:e2 SSID 'MIT SECURE' due to wpa_bss_flush_by_age
...
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89258'
Jun 03 16:46:12 pipemon-desktop wpa_supplicant[1173]: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
Jun 03 16:46:24 pipemon-desktop kernel: [UFW BLOCK] IN=wlx74ee2af4348b OUT= MAC=01:00:5e:00:00:01:b4:de:31:be:26:b7:08:00 SRC=18.4.115.12 DST=224.0.0.1 LEN=28 TOS=0x00 PREC=0xC0 TTL=1 ID=27935 PROTO=2
Jun 03 16:46:26 pipemon-desktop kernel: [UFW BLOCK] IN=wlx74ee2af4348b OUT= MAC=01:00:5e:7f:ff:fa:7c:b2:7d:6f:b3:23:08:00 SRC=18.20.212.77 DST=239.255.255.250 LEN=71 TOS=0x00 PREC=0x00 TTL=1 ID=41164 PROTO=UDP SPT=5050 DPT=5050 LEN=51
Jun 03 16:46:37 pipemon-desktop kernel: [UFW BLOCK] IN=wlx74ee2af4348b OUT= MAC=01:00:5e:7f:ff:fa:50:1a:c5:f0:31:b3:08:00 SRC=18.20.210.73 DST=239.255.255.250 LEN=680 TOS=0x00 PREC=0x00 TTL=1 ID=20222 PROTO=UDP SPT=62748 DPT=3702 LEN=660 
Jun 03 16:46:42 pipemon-desktop colord[1291]: failed to get session [pid 262019]: No data available
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: bgscan simple: Request a background scan
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Add radio work 'scan'@0x564aa014b180
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: First radio work item in the queue - schedule start immediately
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Starting radio work 'scan'@0x564aa014b180 after 0.000006 second wait
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: nl80211: scan request
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Scan SSID MIT SECURE
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: Scan requested (ret=0) - scan timeout 30 seconds
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Event message available
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Drv Event 33 (NL80211_CMD_TRIGGER_SCAN) received for wlx74ee2af4348b
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: nl80211: Scan trigger
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Event SCAN_STARTED (47) received
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Own scan request started a scan in 0.000015 seconds
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Event message available
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Drv Event 34 (NL80211_CMD_NEW_SCAN_RESULTS) received for wlx74ee2af4348b
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: nl80211: New scan results available
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Scan probed for SSID 'MIT SECURE'
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Scan included frequencies: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 2467 2472 5180 5200 5220 5240 5260 5280 5300 5320 5500 5520 5540 5560 5580 5600 5620 5640 5660 5680 5700 5745 5765 5785 5805 5825
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Event SCAN_RESULTS (3) received
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Scan completed in 0.000029 seconds
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Received scan results (62 BSSes)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: nl80211: Scan results indicate BSS status with 58:f3:9c:f0:e7:ed as associated
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Start scan result update 8833
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Add new id 89259 BSSID c4:6e:1f:2c:89:42 SSID 'PRG-IRCP2.4' freq 2462
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89259'
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Add new id 89260 BSSID 58:f3:9c:f0:e7:eb SSID 'eduroam' freq 5805
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89260'
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: BSS: Add new id 89261 BSSID 58:f3:9c:af:d2:12 SSID 'MIT SECURE' freq 2412
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89261'
...
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: BSS: last_scan_res_used=62/64
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: New scan results available (own=1 ext=0)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: bgscan simple: scan result notification
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: AP[0] c4:6e:1f:2c:89:42 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: AP[1] 04:4e:5a:fc:2f:9a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: AP[2] 78:d2:94:9a:0a:f7 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Radio work 'scan'@0x564aa014b180 done in 0.002779 seconds
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: radio_work_free('scan'@0x564aa014b180): num_active_works --> 0
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Scan results matching the currently selected network
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 1: 58:f3:9c:f0:e7:ed freq=5805 level=-58 snr=34 est_throughput=65001
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 3: 58:f3:9c:af:d2:12 freq=2412 level=-53 snr=36 est_throughput=65000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 5: 58:f3:9c:f0:e7:e2 freq=2412 level=-57 snr=32 est_throughput=65000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 9: 58:f3:9c:af:d2:1d freq=5220 level=-72 snr=20 est_throughput=54000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 11: 58:f3:9c:a0:9d:72 freq=2412 level=-70 snr=19 est_throughput=54000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 12: 10:05:ca:73:7c:42 freq=2412 level=-70 snr=19 est_throughput=54000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 20: b0:26:80:8b:12:0d freq=5745 level=-83 snr=9 est_throughput=40501
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 23: 58:f3:9c:e5:c4:3d freq=5320 level=-80 snr=12 est_throughput=36000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: Selecting BSS from priority group 0
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 0: c4:6e:1f:2c:89:42 ssid='PRG-IRCP2.4' wpa_ie_len=0 rsn_ie_len=20 caps=0x431 level=-57 freq=2462  wps
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b:    skip - SSID mismatch
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 1: 58:f3:9c:f0:e7:ed ssid='MIT SECURE' wpa_ie_len=0 rsn_ie_len=20 caps=0x1111 level=-58 freq=5805
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b:    selected based on RSN IE
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b:    selected BSS 58:f3:9c:f0:e7:ed ssid='MIT SECURE'
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: RTM_NEWLINK: ifi_index=5 ifname=wlx74ee2af4348b wext ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/125
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89259) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: WPS: Unknown Vendor Extension (Vendor ID 9442)
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89260) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89261) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89262) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89263) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89264) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89265) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89266) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89267) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89268) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89269) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89270) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89271) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89272) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89273) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89274) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89275) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89276) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89277) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89278) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89279) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89280) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89281) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89282) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89283) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89284) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89285) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89286) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89287) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89288) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89289) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89290) [s]
Jun 03 16:46:56 pipemon-desktop NetworkManager[1140]: <debug> [1591217216.1498] device[2daeef8128d7ad35] (wlx74ee2af4348b): failed to match hidden AP 58:F3:9C:AF:D2:13
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89291) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89292) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89293) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89294) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89295) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89296) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89297) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89298) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89299) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89300) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89301) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89302) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89303) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89304) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89305) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89306) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89307) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89308) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89309) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89310) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89311) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89312) [s]
Jun 03 16:46:56 pipemon-desktop NetworkManager[1140]: <debug> [1591217216.1536] device[2daeef8128d7ad35] (wlx74ee2af4348b): failed to match hidden AP 58:F3:9C:A0:9D:73
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89313) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89314) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89315) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89316) [s]
Jun 03 16:46:56 pipemon-desktop NetworkManager[1140]: <debug> [1591217216.1543] device[2daeef8128d7ad35] (wlx74ee2af4348b): failed to match hidden AP 58:F3:9C:E5:C4:33
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89317) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89318) [s]
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/89319) [s]
Jun 03 16:46:56 pipemon-desktop NetworkManager[1140]: <debug> [1591217216.1592] device[2daeef8128d7ad35] (wlx74ee2af4348b): failed to match hidden AP 62:45:B1:BA:00:4A
Jun 03 16:46:56 pipemon-desktop NetworkManager[1140]: <debug> [1591217216.1712] device[2daeef8128d7ad35] (wlx74ee2af4348b): wifi-scan: scan-done callback: successful
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 24: 58:f3:9c:d0:19:7d freq=5560 level=-80 snr=12 est_throughput=36000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 27: 58:f3:9c:a0:9d:7d freq=5180 level=-82 snr=10 est_throughput=24000
Jun 03 16:46:56 pipemon-desktop wpa_supplicant[1173]: wlx74ee2af4348b: 28: b0:26:80:8b:12:02 freq=2412 level=-79 snr=10 est_throughput=24000

My best guess is that this problem is a bug in the new NetworkManager, probably a blocking thread while network-manager performs a routine wifi-scan. I'm happy to provide any additional information that will help resolve this issue.

networking network-manager wpa-supplicant 20.04

1 Answers

  1. The logs indicate a (University) roaming environment, the wireless network "MIT Secure" that you're connected to is a so called Extended Service Set (ESS) comprising many individual access points / basic service sets (BSS-IDs).

    What you see are regular background scans for available BSSIDs, scheduled by NetworkManager, executed by wpa_supplicant. I speculate depending on the signal quality in the scan results, NM wants to choose the AP within the ESS with the best signal.

    In the log it looks like it re-chooses the BSS 58:f3:9c:f0:e7:ed after the scan, but I'm not too familiar with the debug output.

    I speculate there could be a bug in how NM chooses an AP, not skipping re-choosing or the driver not being quick enough. If you wouldn't reside in a roaming environment, disabling the bgscans and thus avoiding switching between access points is an option. If you sit mostly in the same corner, you could live with not roaming if it avoids the disruptive behaviour until it is better understood.

    For an explanation on background scans, see this Dan Williams blog post from 2016. The Dave Täht reference in the first paragraph holds a lot of information on the frustrations caused by the scans.

    For how nm schedules bgscans or not at all, I'll quote freely from the comments within nm_supplicant_config_add_bgscan in nm-supplicant-config.c Version 1.22.10 from 20.04:

    Scans will be disabled when

    (1) a shared connection (either AP or Ad-Hoc) is active

    (2) the connection is locked to a specific AP [..] (#513820)

    and contrary, will

    (3) default to a very long bgscan interval when signal is OK [..]

    (4) use a shorter bgscan interval [..] if using WPA Enterprise, Dynamic WEP or we have seen more than one AP

    So choosing either in gnome-settings or with nmcli dev wifi connect <bssid> one BSSID explicitly will use (2) and disable bgscans.

    gnome-settings-wifi

    For a dualband AP, this will also pick one band (2.4Ghz/5Ghz) over the other.

    Note how in enterprise networks (4) bgscans intervals are shorter, this applies to the roaming network you are connected to.

    Ubuntu 20.04 focal is also the first version to use a NetworkManager with this commit causing bgscans to occur more frequently in home network environments (dualband APs have distinct BSSIDs). A value of simple:30:-65:300 stands for scanning every 30 seconds when the signal is weaker than -65 dBm and every 300 seconds otherwise. The value can be customized in wpa_supplicant, see the archwiki.

    As noted, choosing a BSSID explicitly to avoid bgscans is a workaround until a bug is identified. Another option is to change the NM backend from wpa_supplicant to iwd as Canonical is trying to get early feedback on.

    • 1