Re: System no longer connects to wifi network after router firmware upgrade, how to troubleshoot more?



Thank you Beniamino. You taught me how to troubleshoot NetworkManager and wifi [1]. I think nmcli dev wifi 
list results may be misleading or cached. The 5 GHz network probably isn't being detected now. In 
wpa_supplicant logs I see lines such as:

Sep 09 08:59:25 raptor wpa_supplicant[565]: nl80211: Scan probed for SSID 'wln'
Sep 09 08:59:33 raptor wpa_supplicant[565]: nl80211: Scan probed for SSID 'wln'
Sep 09 08:59:40 raptor wpa_supplicant[565]: nl80211: Scan probed for SSID 'wln'
Sep 09 08:59:45 raptor wpa_supplicant[565]: nl80211: Scan probed for SSID 'wln'

In contrast the found network looks like this:

Sep 09 08:59:25 raptor wpa_supplicant[565]: wlx1831bf53a3a2: 22: 04:d9:f5:fa:d4:f8 ssid='wln_legacy' 
wpa_ie_len=0 rsn_ie_len=20 caps=0x1411 level=-50 freq=2442  wps
Sep 09 08:59:25 raptor wpa_supplicant[565]: wlx1831bf53a3a2:    skip - SSID mismatch

Also running
iwlist interface_name scan
doesn't show the desired wln SSID at all.

So... probably need to communicate with the driver people. Or the router firmware people. At least now I know 
what to start with beyond "my wifi doesn't connect anymore!"

[1] To make this explicit for others, this is how to turn on full logging for NetworkManager and 
wpa_supplicant, at least under current versions of Debian.
(a) Set the logging level to trace in NetworkManager. Add this stanza to 
/etc/NetworkManager/NetworkManager.conf:
[logging]
level=trace

(b) Turn on debug level logging in wpa_supplicant. Edit /lib/systemd/system/wpa_supplicant.service:
Edit the command line in the ExecStart option to add -ddd as an argument.

(c) Tell journald not to filter messages. Edit /etc/systemd/journald.conf:
Set RateLimitBurst=0

After collecting the logs for analysis, revert all these changes for normal operation.


On Sep 9, 2021, at 08:32, Beniamino Galvani <bgalvani redhat com> wrote:

On Sat, Sep 04, 2021 at 08:52:41AM -0700, Alan Tu via networkmanager-list wrote:
Hello, A router firmware upgrade has caused my network-manager system not to be able to connect to the 
fastest wifi access point. I'd like to know how to troubleshoot exactly what is going on so I can provide 
feedback to either the NIC driver maintainers, the software stack, the Asus firmware people, etc.

I'm running Debian testing (v11 + updates.) network-manager is at version 1.30.6-1. The NIC is an Asus USB 
dongle running the rtl8814au module from aircrack-ng. The access point is an Asus RT-AX88u router (irony, 
I know).

This system was connected to a wifi network called wln. Because of old smart speakers, I had to split my 
network. wln runs on the 5 GHz band and "wln_legacy" runs on the 2.4 GHz band. The server was connected to 
the wln SSID.

I upgraded the Asus router firmware, a mistake in hindsight. My Windows tablet and my iDevices are talking 
with the 5 GHz wln network just fine as before. But network-manager (or something underneath that) is not 
able to connect.

The wln network is still visible:
$ nmcli dev wifi list
...
*       04:D9:F5:FA:D4:F8  wln_legacy  Infra  7     540 Mbit/s  87      ▂▄▆█  WPA2     
       04:D9:F5:FA:D4:FC  wln           Infra  52    540 Mbit/s  24      ▂___  WPA2      

But when trying to bring the wln connection up, I see messages in the system journal like this:

Sep 03 12:46:11 raptor NetworkManager[555]: <info>  [1630698371.4330] device (wlx1831bf53a3a2): 
Activation: starting connection 'wln' (afc892b2-7e5f-45a5-9858-16a155bc8bb3)
Sep 03 12:46:11 raptor NetworkManager[555]: <info>  [1630698371.4384] device (wlx1831bf53a3a2): state 
change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Sep 03 12:46:11 raptor NetworkManager[555]: <info>  [1630698371.5565] device (wlx1831bf53a3a2): state 
change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Sep 03 12:46:11 raptor NetworkManager[555]: <info>  [1630698371.5575] device (wlx1831bf53a3a2): state 
change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Sep 03 12:46:11 raptor NetworkManager[555]: <info>  [1630698371.5637] device (wlx1831bf53a3a2): state 
change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Sep 03 12:46:11 raptor NetworkManager[555]: <info>  [1630698371.5751] device (wlx1831bf53a3a2): supplicant 
interface state: disconnected -> scanning
Sep 03 12:46:37 raptor wpa_supplicant[564]: wlx1831bf53a3a2: Reject scan trigger since one is already 
pending
Sep 03 12:46:37 raptor NetworkManager[555]: <info>  [1630698397.1961] device (wlx1831bf53a3a2): state 
change: config -> failed (reason 'ssid-not-found', sys-iface-state: 'managed')

How can I gather more debug information, to better articulate what is going on? I'd appreciate some 
pointers! Thank you in advance.


In cases like this, more verbose NM and wpa_supplicant logs are helpful.

Increase NM logging level by setting "level=TRACE" in the [logging]
section of NetworkManager.conf. For wpa_supplicant, add '-ddd' to the
command line argument. Both changes require a restart of the daemon.

Since those logs can be quite verbose, if you are using
systemd-journal you should probably disable rate-limiting by setting
e.g. "RateLimitBurst=0" in /etc/systemd/journald.conf.

Beniamino


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]