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

[Alan Tu <8libra gmail com>]

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