FS#75670 - [linux][iwd][NetworkManager] Kernel 5.19 + NetworkManager with iwd breaks auto reconnect after resum

Attached to Project: Arch Linux
Opened by Arvid Norlander (VorpalGun) - Monday, 22 August 2022, 15:22 GMT
Last edited by Toolybird (Toolybird) - Saturday, 03 June 2023, 00:21 GMT
Task Type Bug Report
Category Kernel
Status Closed
Assigned To Tobias Powalowski (tpowa)
Jan Alexander Steffens (heftig)
David Runge (dvzrv)
Levente Polyak (anthraxx)
Architecture All
Severity Medium
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 3
Private No

Details

Description:

After upgrading to kernel 5.19 (tested both linux and linux-zen), wifi reconnect on resume is broken when using NetworkManager + iwd. When downgrading to 5.18 or linux-lts, auto reconnect starts working again. When switching NetworkManager to use wpa_supplicant auto reconnect starts working on newer kernel again. Manual reconnection works using iwd+new kernel.

Hardware:
* Lenovo Thinkpad T480 with "Intel Corporation Wireless 8265 / 8275 (rev 78)" (according to lspci).
* Access point is a Asus AC-68U running the Asus Merlin Firmware.

I have another laptop, with Atheros wifi and the same NM + iwd setup. It does not suffer from this problem. This appears to
be specific to this hardware.

The following messages show up in dmesg/journalctl when the problem is observed (MAC addresses and SSID changed for privacy):

Aug 22 09:47:56 athena kernel: iwlwifi 0000:03:00.0: Not associated and the time event is over already...
Aug 22 09:47:56 athena kernel: wlan0: Connection to AP 08:xx:xx:xx:xx:xx lost
Aug 22 09:47:56 athena kernel: wlan0: send auth to 08:xx:xx:xx:xx:xx (try 3/3)
Aug 22 09:47:56 athena kernel: iwlwifi 0000:03:00.0: Not associated and the time event is over already...
Aug 22 09:47:56 athena kernel: wlan0: Connection to AP 08:xx:xx:xx:xx:xx lost
Aug 22 09:47:57 athena kernel: wlan0: authentication with 08:xx:xx:xx:xx:xx timed out
Aug 22 09:47:57 athena iwd[1299]: authentication timed out
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4263] device (wlan0): new IWD device state is connecting
Aug 22 09:47:57 athena kernel: wlan0: authenticate with 08:xx:xx:xx:xx:xx
Aug 22 09:47:57 athena kernel: wlan0: bad VHT capabilities, disabling VHT
Aug 22 09:47:57 athena kernel: wlan0: 80 MHz not supported, disabling VHT
Aug 22 09:47:57 athena NetworkManager[1042]: <warn> [1661154477.4264] device (wlan0): IWD is connecting to the wrong AP, replacing activation
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4267] device (wlan0): state change: config -> failed (reason 'supplicant-disconnect', sys-iface-state: 'managed')
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4279] manager: NetworkManager state is now DISCONNECTED
Aug 22 09:47:57 athena NetworkManager[1042]: <warn> [1661154477.4287] device (wlan0): Activation: failed for connection 'MySSID-5GHz'
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4308] device (wlan0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4335] device (wlan0): Activation: starting connection 'MySSID-2.4GHz' (8cbb15e8-385e-48d2-b63f-f7a6ef62bc52)
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4341] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4351] manager: NetworkManager state is now CONNECTING
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4361] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Aug 22 09:47:57 athena kernel: wlan0: send auth to 08:xx:xx:xx:xx:xx (try 1/3)
Aug 22 09:47:57 athena kernel: wlan0: aborting authentication with 08:xx:xx:xx:xx:xx by local choice (Reason: 3=DEAUTH_LEAVING)
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4568] device (wlan0): new IWD device state is disconnecting
Aug 22 09:47:57 athena NetworkManager[1042]: <error> [1661154477.4573] device (wlan0): Activation: (wifi) Network.Connect failed: GDBus.Error:net.connman.iwd.Failed: Operation failed
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4578] device (wlan0): state change: config -> failed (reason 'no-secrets', sys-iface-state: 'managed')
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4589] manager: NetworkManager state is now DISCONNECTED
Aug 22 09:47:57 athena NetworkManager[1042]: <warn> [1661154477.4597] device (wlan0): Activation: failed for connection 'MySSID-2.4GHz'
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4600] device (wlan0): new IWD device state is disconnected
Aug 22 09:47:57 athena NetworkManager[1042]: <info> [1661154477.4607] device (wlan0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')

Additional info:
* package version(s):
- linux-5.19.2.arch1-2
- networkmanager-1.38.4-1
- iwd-1.29-1 (broken)
- wpa_supplicant-2:2.10-5 (works)
* config and/or log files etc.
* link to upstream bug report, if any: I don't know which package is the culprit, so I have not reported this upstream, since I don't know which upstream to report to.

Steps to reproduce:
1. Suspend computer with iwlwifi using NetworkManager + iwd
2. After computer has gone to sleep, wake it up
3. Observe failure to reconnect to wifi network that was connected before.

This task depends upon

Closed by  Toolybird (Toolybird)
Saturday, 03 June 2023, 00:21 GMT
Reason for closing:  Upstream
Additional comments about closing:  It's clearly an upstream issue and not an Arch packaging bug. Please follow up with upstream.
Comment by Arvid Norlander (VorpalGun) - Monday, 22 August 2022, 16:36 GMT
5.19.3 also affected. I ended up creating an upstream bug report at the kernel at least: https://bugzilla.kernel.org/show_bug.cgi?id=216397

Should I also create NetworkManager and/or IWD bug reports?
Comment by Toolybird (Toolybird) - Tuesday, 23 August 2022, 05:41 GMT
> Should I also create NetworkManager and/or IWD bug reports?

What, 3 bug reports for the price of one? Nah, it smells like a kernel regression so I'd say you're on the right track. Could also try posting to linux-wireless ml [1], although it seems primarily for development and patches. There's a similar report here [2], but sadly lacking in detail.

Other than that, usual suggestions for kernel regressions apply:

- try latest -rc kernel to see if it's fixed
- perform a git-bisection [3] to try and and find the offending commit
- stay on a working kernel and wait it out in the hope it gets fixed in the future

Please let us know if you have any joy.

[1] https://wireless.wiki.kernel.org/en/developers/mailinglists
[2] https://bugzilla.kernel.org/show_bug.cgi?id=216361
[3] https://wiki.archlinux.org/title/Bisecting_bugs_with_Git
Comment by Arvid Norlander (VorpalGun) - Tuesday, 23 August 2022, 07:43 GMT
This (especially the git bisection) sounds like a project for the weekend, except I'm going hiking then. I will see what I end up having time doing.
Comment by Toolybird (Toolybird) - Friday, 23 September 2022, 06:29 GMT
Any progress on this one?
Comment by Arvid Norlander (VorpalGun) - Saturday, 22 October 2022, 21:23 GMT
The issue remains, and there has been no progress in the upstream kernel. I don't know if that is a good reason for closing the bug though!

Loading...