Bug 203593 - iwlwifi: 9560: Unhandled alg: 0x707 - WIFI-24625
Summary: iwlwifi: 9560: Unhandled alg: 0x707 - WIFI-24625
Status: CLOSED CODE_FIX
Alias: None
Product: Drivers
Classification: Unclassified
Component: network-wireless (show other bugs)
Hardware: x86-64 Linux
: P1 high
Assignee: DO NOT USE - assign "network-wireless-intel" component instead
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-05-13 15:58 UTC by Vytenis
Modified: 2021-02-26 00:04 UTC (History)
20 users (show)

See Also:
Kernel Version: 5.0.16
Tree: Fedora
Regression: Yes


Attachments
A snippet from dmesg logs (17.24 KB, text/plain)
2019-05-13 15:58 UTC, Vytenis
Details
iwlwifi FW with debug configuration (2.43 MB, application/octet-stream)
2019-05-22 12:23 UTC, Ilan Peer
Details
Debug collection patch (3.49 KB, patch)
2019-05-22 12:23 UTC, Ilan Peer
Details | Diff
Driver patch to force FW crash on unhandled algorithm (2.39 KB, patch)
2019-05-23 06:10 UTC, Ilan Peer
Details | Diff
iwlwifi debug fw crash log (3.46 KB, text/plain)
2019-05-24 11:17 UTC, Vytenis
Details
encrypted dump (923.24 KB, application/pgp-encrypted)
2019-05-27 08:44 UTC, Vytenis
Details
iwlwifi FW with more debug information (1.39 MB, application/octet-stream)
2019-06-10 08:32 UTC, Ilan Peer
Details
encrypted dump 2 (1.76 MB, application/pgp-encrypted)
2019-06-10 14:37 UTC, Vytenis
Details
encrypted trace.dat (1.41 MB, application/pgp-encrypted)
2019-06-10 14:38 UTC, Vytenis
Details
Fix multicast frame forwaring (2.39 KB, application/mbox)
2019-06-11 10:21 UTC, Ilan Peer
Details
iwlist scan encrypted (2.95 KB, application/pgp-encrypted)
2019-06-11 12:06 UTC, Vytenis
Details
encrypted dump 3 (1.74 MB, application/pgp-encrypted)
2019-06-11 14:19 UTC, Vytenis
Details
encrypted trace.dat 2 (1.34 MB, application/pgp-encrypted)
2019-06-11 14:20 UTC, Vytenis
Details
encrypted snippet from journalctl logs (7.14 KB, application/pgp-encrypted)
2019-06-11 14:21 UTC, Vytenis
Details
Fix multicast frame forwaring with prints (2.46 KB, application/mbox)
2019-06-12 17:25 UTC, Ilan Peer
Details
encrypted trace.dat 3 (1.49 MB, application/pgp-encrypted)
2019-06-13 08:32 UTC, Vytenis
Details
encrypted snippet from journalctl logs 2 (4.31 KB, application/pgp-encrypted)
2019-06-13 08:32 UTC, Vytenis
Details
encrypted dump 4 (1.92 MB, application/pgp-encrypted)
2019-06-13 09:39 UTC, Vytenis
Details
encrypted snippet from journalctl logs 3 (2.85 KB, application/pgp-encrypted)
2019-06-13 09:39 UTC, Vytenis
Details

Description Vytenis 2019-05-13 15:58:14 UTC
Created attachment 282741 [details]
A snippet from dmesg logs

I have a Dell Latitude 5591 laptop with Intel Wireless-AC 9560 wifi card. Using kernel 5.0.13 on Fedora 30 distro. Loaded firmware is iwlwifi-9000-pu-b0-jf-b0-43.ucode

On a certain Wifi Access Point I'm getting my dmesg log spammed with
iwlwifi 0000:00:14.3: Unhandled alg: 0x707 messages (like 20 every second). Wifi works well during that, but system freezes irrecoverably after approximately an hour passes (maybe some memory limit for dmesg log size?). Magic sysrq key doesn't work after it freezes. Changing access point to a different one helps - dmesg goes silent. This different access point runs on the same router as the misbehaving one, so it's hardware is not the issue. 

There is a different laptop of the same model and same hardware running Ubuntu 18.04 LTS release with 4.18.5 kernel and does not have this issue on these same access points. 

Also attached a snippet from dmesg logs.
Comment 1 Emmanuel Grumbach 2019-05-13 19:33:16 UTC
What access point is that?
Comment 2 Vytenis 2019-05-13 19:35:49 UTC
It's a 5ghz 11ac access point. Don't know any more details, because it's my workplace access point and admins won't give much info about it
Comment 3 Vytenis 2019-05-14 05:03:38 UTC
Some additional details: both AP's seems to be mesh-networks (there seems to be 4-5 cells with the same ssid but different mac addresses). Both working and non working AP's have cells with the same frequency and mac address. They are both using 
IE: IEEE 802.11i/WPA2 Version 1
  Group Cipher : CCMP
  Pairwise Ciphers (1) : CCMP
  Authentication Suites (1) : PSK

And also I have tried to iwlwifi module options 11n_disable=1 and disable_11ac=1 separately and together to use 11g or 11n or 11ac exclusively. That made no change
Comment 4 Ilan Peer 2019-05-22 12:23:05 UTC
Created attachment 282909 [details]
iwlwifi FW with debug configuration
Comment 5 Ilan Peer 2019-05-22 12:23:51 UTC
Created attachment 282911 [details]
Debug collection patch
Comment 6 Ilan Peer 2019-05-22 12:32:42 UTC
Hi,

If you can, it would be useful for our debugging if you could collect some additional data data:

1. Please have a look at the following link which describes how to collect additional debug data: https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging#firmware_debugging

2. Please take the time to read our privacy note here:
https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging#privacy_aspects

3. If you can, use the attached fw, which includes debug data configuration.

4. If you can compile your costume kernel, apply the attached patch. With the attached patch there is no need to manually trigger the debug data collection.

5. It would be very useful if you could also capture kernel traces:

- install trace-cmd: yum install trace-cmd
- Run: trace-cmd record -e cfg80211 -e mac80211 -e iwlwifi -e iwlwifi_data
- Once done, send us the trace.dat file
- Note that using '-e iwlwifi_data' would capture all data traffic so you might want to skip data.

Thanks in advance,

Ilan.
Comment 7 Vytenis 2019-05-22 14:04:12 UTC
I get this when trying to apply the patch:
>Applying: iwlwifi: mvm: Trigger debug collection on unhandled algorithm
>error: patch failed: drivers/net/wireless/intel/iwlwifi/fw/error-dump.h:500
>error: drivers/net/wireless/intel/iwlwifi/fw/error-dump.h: patch does not
>apply
>error: patch failed: drivers/net/wireless/intel/iwlwifi/mvm/rx.c:8
>error: drivers/net/wireless/intel/iwlwifi/mvm/rx.c: patch does not apply
>Patch failed at 0097 iwlwifi: mvm: Trigger debug collection on unhandled
>algorithm

Can you help with getting this patch ready for kernel version 5.0.16?
Comment 8 Ilan Peer 2019-05-22 14:11:00 UTC
sure ... I'll try to get it later today or tomorrow morning.

Ilan.
Comment 9 Ilan Peer 2019-05-23 06:10:09 UTC
Created attachment 282919 [details]
Driver patch to force FW crash on unhandled algorithm

Sorry I got delayed with this.

The patch would cause a FW NMI, which would crash the FW and trigger debug data collection, thus, please make sure that u set the following option in '/etc/modprobe.d/iwlwifi.conf':

options iwlwifi fw_restart=0

Thanks,

Ilan.
Comment 10 Vytenis 2019-05-23 07:34:55 UTC
Hi, when using this patch, do I need to have any debugging options enabled in kernel? Do I need to load debug firmware you've provided? Will dmesg output after crash be enough?
Comment 11 Ilan Peer 2019-05-23 07:49:27 UTC
No other debugging options are need with this patch, but please use the FW I provided yesterday.

If you are going to provide trace-cmd data, then you should enable CONFIG_IWLWIFI_DEVICE_TRACING and enable kernel traces.
Comment 12 Vytenis 2019-05-24 11:17:00 UTC
Created attachment 282931 [details]
iwlwifi debug fw crash log

Added a crash log with debug firmware
Comment 13 Emmanuel Grumbach 2019-05-24 11:25:44 UTC
We'll need the firmware dump that was created if you followed the instructions from the wiki page. Thank you.
Comment 14 Vytenis 2019-05-24 11:30:32 UTC
Ah, sorry, I can do that only on monday
Comment 15 Vytenis 2019-05-27 08:44:02 UTC
Created attachment 282947 [details]
encrypted dump

Adding fw dump encrypted as per privacy instructions described here https://wireless.wiki.kernel.org/en/users/drivers/iwlwifi/debugging#privacy_aspects
Comment 16 Ilan Peer 2019-05-27 12:30:39 UTC
Thanks for the data. We are looking into it.

Would it be possible to also share the syslog or at least the network wlan security configuration: which authentication method is used, and which cipher suite were used?

Thanks,

Ilan.
Comment 17 Vytenis 2019-05-27 14:14:11 UTC
IE: IEEE 802.11i/WPA2 Version 1
  Group Cipher : CCMP
  Pairwise Ciphers (1) : CCMP
  Authentication Suites (1) : PSK

Is this info enough?
Comment 18 Ilan Peer 2019-05-27 14:25:59 UTC
For now yes. Thanks.
Comment 19 Vytenis 2019-06-03 14:00:30 UTC
Just a follow up - with Kernel 5.1.5 and firmware version 46 the problem is still present
Comment 20 Ilan Peer 2019-06-05 06:24:03 UTC
Hi,

Thanks for the update. We now have someone that is looking into the issue. Seems that the issue is with an encrypted multicast data frame that we do not decrypt. However, we still do not know why.

I'll keep you updated once we have more.

Thanks :)

Ilan.
Comment 21 Ilan Peer 2019-06-10 08:32:21 UTC
Created attachment 283171 [details]
iwlwifi FW with more debug information

Hi,

Based on the dump you provided we suspect that the issue is caused since no GTK was installed (the key used to decrypt multicast data frames from the AP to the station), but we cannot determine why. Can you please reproduce with the attached FW and in addition also provide trace-cmd data (as specified earlier)?

Providing trace-cmd is important since it would allow us to determine if the GTK was configured by the supplicant/driver or not.

Thanks in advance,

Ilan.
Comment 22 Ilan Peer 2019-06-10 08:40:09 UTC
Hi,

Just to clarify. Please reproduce with kernel 5.1 and with my patch.

Ilan.
Comment 23 Vytenis 2019-06-10 14:37:02 UTC
Created attachment 283175 [details]
encrypted dump 2

Adding dump from kernel 5.1.7 with 46 debug firmware
Comment 24 Vytenis 2019-06-10 14:38:02 UTC
Created attachment 283177 [details]
encrypted trace.dat

Adding trace.dat from kernel 5.1.7 with 46 debug firmware
Comment 25 Ilan Peer 2019-06-11 10:03:44 UTC
The parsed trace-cmd shows that following a successful connection establishment, after about 1 sec, the wpa_supplicant decided to deauthenticate from the AP, for an unknown reason (reason code in the deauthentiction frame is 3 == leaving). After the deauthentication, the wpa_supplicant issues as scan, and then tries to connect to the same AP, sending an authentication frame. However, before the authentication is complete, the FW forwards to the driver a multicast data frame which it was not able to decrypt (which is expected, as no keys were installed at this stage), and thus we get the "unhandled alg 0x707" message ... which is not really an error message.
Comment 26 Ilan Peer 2019-06-11 10:21:21 UTC
Created attachment 283189 [details]
Fix multicast frame forwaring

Can you please try the attached patch. As explained earlier, the driver configured the FW to pass multicast data frames before actually being able to handle them. This patch attempts to fix this (although such frames might still get to the driver after the association is complete but before the keys were installed).

More interesting would be the reason why the wpa_supplicant decided to deauthenticate from the AP, so if you can in your next reproduction please also provide (in addition to trace-cmd, dmesg and FW dump) wpa_supplicant logs (they should be available in the syslog).
Comment 27 Vytenis 2019-06-11 10:27:08 UTC
I can clarify the deathentication:
In order to collect this trace data I had to do the following:
1. rmmod iwlmvm && rmmod iwlwifi (it has crashed before and did not restart automatically)
2. modprobe iwlwifi (it started connecting to "BAM" AP which does not trigger the 0x707)
3. I manually disconnected from "BAM" AP (3 == leaving) and selected "BAW" AP to connect to

The reason you thought it was the same AP is that both BAM and BAW AP's share the same MAC address and are served from the same router
Comment 28 Ilan Peer 2019-06-11 10:43:28 UTC
This might also explain all the 0x707 messages :)

You have two APs configured with the same MAC address, so while the station is connected to AP1, it would still filter in multicast frames from AP2, but since AP2 uses a different key to encrypt them the station is not able to decrypt them .. and thus the error messages.

Does this make sense, or did you also get these messages in other scenarios?
Comment 29 Vytenis 2019-06-11 11:21:11 UTC
This makes sense, but doesn't explain why the second AP doesn't generate these messages...
Comment 30 Ilan Peer 2019-06-11 11:42:30 UTC
Maybe this is because when you are connected to the "good AP" the other AP does not have any stations associated with it so it does not transmit any multicast frames.

Regardless, can you confirm that this issue is not seen when the 2nd AP is turned off/on a different channel?
Comment 31 Vytenis 2019-06-11 12:06:45 UTC
Created attachment 283193 [details]
iwlist scan encrypted

Sorry, I have no control on these AP's being on or off. Providing iwlist scan results listing all AP nodes if these are any help. And will try your patch as well
Comment 32 Ilan Peer 2019-06-11 13:02:58 UTC
Hi,

Are u sure that "BAM" and "BAW" share the same MAC address? Seems to me that although the address are very similar there is at least 1 bit different between the addresses. At least the scan list that you attached does not have  duplication of MAC addresses.

Ilan.
Comment 33 Vytenis 2019-06-11 13:06:04 UTC
Actually...You are right. MAC addresses are similar, but not the same
Comment 34 Ilan Peer 2019-06-11 13:09:08 UTC
ok. So at least this is not the issue. 

Are u sure that the disconnection is done by u? It seems very fast after the initial connection.
Comment 35 Vytenis 2019-06-11 13:10:38 UTC
I've tried to do it as fast as I can. Finishing building kernel with your patch, will test this again
Comment 36 Vytenis 2019-06-11 14:19:55 UTC
Created attachment 283195 [details]
encrypted dump 3

this is from the run with the patch applied
Comment 37 Vytenis 2019-06-11 14:20:30 UTC
Created attachment 283197 [details]
encrypted trace.dat 2

with the patch applied
Comment 38 Vytenis 2019-06-11 14:21:05 UTC
Created attachment 283199 [details]
encrypted snippet from journalctl logs

with the patch applied
Comment 39 Vytenis 2019-06-11 14:22:08 UTC
So now I disabled auto connect and recorded without manual disconnect, as clean as I could
Comment 40 Ilan Peer 2019-06-12 06:34:18 UTC
Hi,

Based on the debug data you collected, it seems that the patch I send was not used.

Can you please double check that you are running a driver with the patch?

Thanks,

Ilan.
Comment 41 Vytenis 2019-06-12 15:03:32 UTC
Hi,
I've rebuilt the kernel, from build logs I saw the patch applied. After I've built the kernel, I've installed resulting RPMs with rpm -i --force option (as version were the same). Is there any way to find out if the patch was applied from the .ko file that is installed?
Comment 42 Ilan Peer 2019-06-12 17:16:04 UTC
Not really ... I'll prepare the same patch with some prints.

Will upload in few minutes.
Comment 43 Ilan Peer 2019-06-12 17:25:43 UTC
Created attachment 283231 [details]
Fix multicast frame forwaring with prints

This is the same patch as the previous + print. Give it a try :)

You should see: "Setting mcast filter"
Comment 44 Vytenis 2019-06-13 04:52:12 UTC
One small question - does the patch that crashes driver on 0x707 error have to be applied as well? Or this last one only?
Comment 45 Ilan Peer 2019-06-13 05:09:19 UTC
Either you use both patches, or you use only the new one and manually trigger debug dump. Better use both.

Ilan
Comment 46 Vytenis 2019-06-13 08:32:22 UTC
Created attachment 283241 [details]
encrypted trace.dat 3

trace.dat with both patches
Comment 47 Vytenis 2019-06-13 08:32:52 UTC
Created attachment 283243 [details]
encrypted snippet from journalctl logs 2

with both patches
Comment 48 Vytenis 2019-06-13 08:34:39 UTC
So I've deleted everything that I've compiled before, applied both patches, installed kernel and tried to connect to this "broken" AP - firmware didn't crash, logs are not being spammed. Will use this kernel for the day to make sure the system freeze doesn't happen as well. But looks like this helped :)
Comment 49 Vytenis 2019-06-13 09:39:17 UTC
Created attachment 283251 [details]
encrypted dump 4

An hour has passed (when the system used to freeze) and wifi driver has crashed again (but without freeze this time). I collected a dump and journalctl log (I see 0x707 error in it again). Seems that there is some re-handshake or something like that happening during the time. Don't know how to capture trace-cmd without a loot of useless info captured as well
Comment 50 Vytenis 2019-06-13 09:39:46 UTC
Created attachment 283253 [details]
encrypted snippet from journalctl logs 3
Comment 51 Ilan Peer 2019-06-13 13:41:29 UTC
hi,

This looks like a different problem. From the debug dump it looks like the AP started sending multicast frames using key index == 2 (before that it was using key index == 1).

The AP probably performed a GTK rekeying, but based on the dump, the new key was not propagated to the FW, so it fails to decrypt the multicast frame.

I cannot say why the key was not programmed to the FW.

It is possible that the AP performed the GTK rekey while the station was asleep so it missed this frames. If this is the case then this is a bug on the AP side.

I'll need to double check this assumption with some other guys (but that would probably happen only next week ... sorry).

For now I suggest that you work only with the 1st patch applied.

Thanks again for all your help,

Ilan.
Comment 52 Ilan Peer 2019-06-13 13:50:12 UTC
Another option, and a better one :)

Can you run with power save disabled?

In "/etc/modprobe.d/iwlwifi.conf" add:

options iwlmvm power_scheme=1

This would disable powersave. 

Ilan.
Comment 53 Vytenis 2019-06-14 05:12:33 UTC
Disabling powersave helped, now the firmware doesn't crash :) And by saying that I should work with the 1st patch applied - do you mean the one that kills the driver on 0x707 or the one that filters multicast frames? Anyways, thanks for the support and for solving this problem for me :) Can I expect mcast filtering to land in the mainline kernel?
Comment 54 Ilan Peer 2019-06-16 06:38:22 UTC
Hi,

Work only with the mcast filtering. The other patch was only to simplify the FW debug data collection.

The mcast filtering patch would make its way to mainline kernel as with other bug fixes.

FWIW, we are still troubled with the AP behavior during GTK rekeying, as it seems that it completed the GTK rekeys without our device being aware of it.

Can you please share the AP details (HW model, chipset and FW version) so we might be able to further investigate this?

Thanks for all your help :)

Ilan.
Comment 55 Vytenis 2019-06-17 11:02:30 UTC
So I got the following info about our AP:
Model: UniFi AP-AC-Pro, Version: 4.0.42.10433, Board Revision: 26
Should be running with this chipset: Qualcomm Atheros QCA9563 (taken from https://oldwiki.archive.openwrt.org/toh/ubiquiti/unifiac) but it's not running openwrt, it's running stock firmware
Comment 56 Ilan Peer 2019-06-18 06:38:13 UTC
Thanks for the info!

Ilan.
Comment 57 Vytenis 2019-06-19 06:11:14 UTC
It turns out that our AP's got upgraded to 4.0.42 version quite recently and it looks like it really helped. Still getting occasional 0x707, but no spamming and no freezes even on vanilla 5.1.9 kernel without powersave off (debug firmware though).
[   59.362211] wlo1: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
[   59.381188] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[   59.382258] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[   59.382500] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[   59.407156] wlo1: authenticated
[   59.408483] wlo1: associate with xx:xx:xx:xx:xx:xx (try 1/3)
[   59.413972] wlo1: RX AssocResp from xx:xx:xx:xx:xx:xx (capab=0x411 status=0 aid=1)
[   59.417822] wlo1: associated
and during one of GTK rekeying procedures
[ 2273.202206] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.202221] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.202226] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.304852] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.304870] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.304878] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.304885] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
[ 2273.305734] iwlwifi 0000:00:14.3: Unhandled alg: 0x707

Looks like it was the AP to blame after all... Don't know if this needs further looking into it...Thanks for all of your efforts :)
Comment 58 Ilan Peer 2019-06-19 13:42:58 UTC
Hi,

Good to hear :) As I describe above we indeed suspected that the AP performed the GTK rekey while the station was in power save which is not valid.

Just to be clear, your are getting the above without the patch that fixed multicast data handling. right?

Thanks,

Ilan.
Comment 59 Vytenis 2019-06-19 13:55:47 UTC
Yes, this is on vanilla kernel from fedora repositories
Comment 60 Ilan Peer 2019-06-22 16:40:32 UTC
Great :)

A modified version of the fix I gave you will make it to the kernel tree soon. 

Regards,

Ilan.
Comment 61 Emmanuel Grumbach 2019-06-22 19:04:21 UTC
I am closing this. We will still see any comment you'll add here.
Comment 62 Bjorn Helgaas 2019-07-08 17:00:08 UTC
Can you add the SHA1 of the upstream patch that fixes this issue, please, so we can figure out which kernel versions contain it?
Comment 63 Emmanuel Grumbach 2019-07-08 17:34:08 UTC
Hm... apparently Luca hasn't sent the fix upstream yet.

You can find it here:

https://git.kernel.org/pub/scm/linux/kernel/git/iwlwifi/backport-iwlwifi.git/commit/?id=2fc5847ec08431b1b6e04aa799db686f53eeb31c

This is our backport based driver. Any patch here will eventually reach upstream.
I typically handle the bugzilla issues (hopefully not for much longer..) and Luca handles the upstreaming work so that we're not always in sync..
Comment 64 Jason Straight 2019-08-12 17:49:37 UTC
How can one tell when the patch has been committed to the kernel?

I'm still getting this, and losing wifi, on 5.3 branch.
Comment 65 Pål Andreassen 2019-11-07 19:40:27 UTC
Lenovo ThinkPad P53
ElementaryOS 5 Juno (based on Ubuntu 18.04 LTS)
Linux PF1YAJ1Z 5.3.9-050309-generic #201911061337 SMP Wed Nov 6 13:39:34 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

Compiled drivers from source: 
https://git.kernel.org/pub/scm/linux/kernel/git/iwlwifi/backport-iwlwifi.git

AP: Unifi AC Pro (firmware 4.0.66.10832)

Keep getting these in the dmesg log too:
iwlwifi 0000:52:00.0: Unhandled alg: 0x707
Comment 66 Garrett Holmstrom 2019-11-08 08:24:19 UTC
Has this merged?  I'm still seeing it on 5.3.9 with an AX200.

ThinkPad P1 Gen 2
Linux magnesium 5.3.9-gentoo #1 SMP Fri Nov 8 14:41:32 PST 2019 x86_64 Intel(R) Core(TM) i9-9880H CPU # 2.30 GHz GenuineIntel GNU/Linux

dmesg is full of these:
iwlwifi 0000:52:00.0: Unhandled alg: 0x707
Comment 67 Simone Marchioni 2019-11-08 15:54:25 UTC
Same problem here.

Fedora 30 with kernel 5.3.8-200.fc30.x86_64

00:14.3 Network controller: Intel Corporation Wireless-AC 9560 [Jefferson Peak] (rev 10)

iwl7260-firmware-25.30.13.0-102.fc30.noarch

Access Point: Fortinet FortiAP FAP-221E

Keep coming these logs:

iwlwifi 0000:00:14.3: Unhandled alg: 0x707
dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/1
dbus: wpa_dbus_property_changed: no property RoamComplete in object /fi/w1/wpa_supplicant1/Interfaces/1

Wireless network is really unstable.
Comment 68 Arnau Oncins 2019-11-09 15:24:20 UTC
Same happens here.

Arch Linux with Kernel 5.3.8: linux-5.3.8.1-1-x86_64

00:14.3 Network controller: Intel Corporation Wireless-AC 9560 [Jefferson Peak] (rev 10)

dmesg:

[   12.593899] iwlwifi 0000:00:14.3: Found debug destination: EXTERNAL_DRAM
[   12.593900] iwlwifi 0000:00:14.3: Found debug configuration: 0
[   12.594124] iwlwifi 0000:00:14.3: loaded firmware version 46.6bf1df06.0 op_mode iwlmvm
...
[   13.219856] iwlwifi 0000:00:14.3: Detected Intel(R) Dual Band Wireless AC 9560, REV=0x318
[   13.227980] iwlwifi 0000:00:14.3: Applying debug destination EXTERNAL_DRAM
[   13.228133] iwlwifi 0000:00:14.3: Allocated 0x00400000 bytes for firmware monitor.
...
[  177.009149] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
Comment 69 Arnau Oncins 2019-11-09 15:26:34 UTC
Same happens here.

Arch Linux with Kernel 5.3.8: linux-5.3.8.1-1-x86_64

00:14.3 Network controller: Intel Corporation Wireless-AC 9560 [Jefferson Peak] (rev 10)

dmesg:

[   12.593899] iwlwifi 0000:00:14.3: Found debug destination: EXTERNAL_DRAM
[   12.593900] iwlwifi 0000:00:14.3: Found debug configuration: 0
[   12.594124] iwlwifi 0000:00:14.3: loaded firmware version 46.6bf1df06.0 op_mode iwlmvm
...
[   13.219856] iwlwifi 0000:00:14.3: Detected Intel(R) Dual Band Wireless AC 9560, REV=0x318
[   13.227980] iwlwifi 0000:00:14.3: Applying debug destination EXTERNAL_DRAM
[   13.228133] iwlwifi 0000:00:14.3: Allocated 0x00400000 bytes for firmware monitor.
...
[  177.009149] iwlwifi 0000:00:14.3: Unhandled alg: 0x707
Comment 70 Max Ammann 2019-11-09 16:29:33 UTC
This happens only in WPA2 Enterprise networks like eduroam in my case.
Comment 71 Simone Marchioni 2019-11-09 17:06:22 UTC
Adding more info to bug in comment 67: with my home WiFi network no problem.
Maybe as stated by Max Ammann in previous comment the problem happens only with WPA2 Enterprise.

I experience the problem only at work where we have 4 FortiAP FAP-221E and the users can roam on these.
Comment 72 Arnau Oncins 2019-11-09 22:58:55 UTC
Adding more info to bug in comment #69: I'm having the problem with my home WiFi, using Personal WPA2 and WiFi 802.11ac.
Comment 73 Ilan Peer 2019-11-10 14:23:18 UTC
Hi,

The complete fix was pushed in the following patch: 

https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=50f5604476b2

And was merged in v5.3-rc7.
Comment 74 Jérôme Benoit 2019-11-23 23:08:59 UTC
Hello,

Could you please explicitly asked for a stable backport of that patch?

Thanks.
Comment 75 James Winters 2019-11-26 03:25:54 UTC
Looks like this is still impacting some of us.  

It has definitely improved, but I still get this problem periodically on my Dell 5530 laptop...

Ubuntu 19.10 with Kernel 5.3.0-24

Network controller: Intel Corporation Wireless-AC 9260 (rev 29)

driver=iwlwifi driverversion=5.3.0-24-generic firmware=46.6bf1df06.0
Comment 76 Simone Marchioni 2019-11-26 11:29:05 UTC
Looking for more infos about the problem and found these ones:

https://www.spinics.net/lists/hostap/msg05474.html
https://bugzilla.redhat.com/show_bug.cgi?id=1599036

Tried to use:

nmcli connection modify '<connection-name>' wifi-sec.pmf disable

and can confirm the situation is much better.
These messages in the logs:

Unhandled alg: 0x707
dbus: wpa_dbus_property_changed: no property SessionLength in object /fi/w1/wpa_supplicant1/Interfaces/2
dbus: wpa_dbus_property_changed: no property RoamComplete in object /fi/w1/wpa_supplicant1/Interfaces/2

keep coming, but seems less frequently and the connection apparently is more stable.

Hope this helps.
Comment 77 Arnau Oncins 2019-12-01 14:54:31 UTC
Update at 2019-12-01 for comments #69 and #72.

Still is happening this error with both 802.11n and 802.11ac, more frequently with 802.11ac.

WiFi security: WPA2 Personal key.

00:14.3 Network controller: Intel Corporation Wireless-AC 9560 [Jefferson Peak] (rev 10)
        Subsystem: Intel Corporation Wireless-AC 9560 [Jefferson Peak]
        Flags: bus master, fast devsel, latency 0, IRQ 16
        Memory at a4310000 (64-bit, non-prefetchable) [size=16K]
        Capabilities: [c8] Power Management version 3
        Capabilities: [d0] MSI: Enable- Count=1/1 Maskable- 64bit+
        Capabilities: [40] Express Root Complex Integrated Endpoint, MSI 00
        Capabilities: [80] MSI-X: Enable+ Count=16 Masked-
        Capabilities: [100] Null
        Capabilities: [14c] Latency Tolerance Reporting
        Capabilities: [164] Vendor Specific Information: ID=0010 Rev=0 Len=014 <?>
        Kernel driver in use: iwlwifi
        Kernel modules: iwlwifi

Archlinux. Kernel: 5.3.13-arch1-1
Comment 78 Sven Köhler 2019-12-17 00:17:37 UTC
Still seeing this on 5.4.3-arch1-1 with AX200
Comment 79 Laurent Bonnaud 2019-12-19 10:34:56 UTC
I am also seeing this error message in Ubuntu 19.10 with kernel 5.4.5 and an AX200 adapter:

[   77.111745] iwlwifi 0000:02:00.0: Unhandled alg: 0x707
[   77.115703] iwlwifi 0000:02:00.0: Unhandled alg: 0x707
[   77.117485] iwlwifi 0000:02:00.0: Unhandled alg: 0x707
[   77.118470] iwlwifi 0000:02:00.0: Unhandled alg: 0x707
[   77.119363] iwlwifi 0000:02:00.0: Unhandled alg: 0x707
[   77.131412] iwlwifi 0000:02:00.0: Unhandled alg: 0x707
Comment 80 Thibault 2020-04-03 19:47:20 UTC
I also have this message. 

I'm running ubuntu server 18.04

Kernel version 5.3-rc7

What logs can I provide to find a solution to this issue?
Comment 81 Alec Istomin 2020-06-02 03:21:11 UTC
Similar issue on fedora 32's 5.6.14-300.fc32.x86_64 #1 SMP Wed May 20 20:47:32 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

Happened after a few days connected to the same AP and was fixed by interface restart.


Adapter:
3b:00.0 Network controller: Intel Corporation Wireless-AC 9260 (rev 29)
        Subsystem: Intel Corporation Device 4010
        Flags: bus master, fast devsel, latency 0, IRQ 16
        Memory at ed400000 (64-bit, non-prefetchable) [size=16K]
        Capabilities: [c8] Power Management version 3
        Capabilities: [d0] MSI: Enable- Count=1/1 Maskable- 64bit+
        Capabilities: [40] Express Endpoint, MSI 00
        Capabilities: [80] MSI-X: Enable+ Count=16 Masked-
        Capabilities: [100] Advanced Error Reporting
        Capabilities: [14c] Latency Tolerance Reporting
        Capabilities: [154] L1 PM Substates
        Kernel driver in use: iwlwifi
        Kernel modules: iwlwifi


Dmesg:
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: No beacon heard and the time event is over already...
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: No beacon heard and the time event is over already...
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: No beacon heard and the time event is over already...
iwlwifi 0000:3b:00.0: Queue 10 is active on fifo 1 and stuck for 10000 ms. SW [1, 18] HW [1, 18] FH TRB=0x0c010a000
iwlwifi 0000:3b:00.0: Microcode SW error detected. Restarting 0x0.
iwlwifi 0000:3b:00.0: Start IWL Error Log Dump:
iwlwifi 0000:3b:00.0: Status: 0x00000040, count: 6
iwlwifi 0000:3b:00.0: Loaded firmware version: 46.8902351f.0 9260-th-b0-jf-b0-46.ucode
iwlwifi 0000:3b:00.0: 0x00000084 | NMI_INTERRUPT_UNKNOWN
iwlwifi 0000:3b:00.0: 0x0080A210 | trm_hw_status0
iwlwifi 0000:3b:00.0: 0x00000000 | trm_hw_status1
iwlwifi 0000:3b:00.0: 0x004853D2 | branchlink2
iwlwifi 0000:3b:00.0: 0x004758E2 | interruptlink1
iwlwifi 0000:3b:00.0: 0x004758E2 | interruptlink2
iwlwifi 0000:3b:00.0: 0x0001AD94 | data1
iwlwifi 0000:3b:00.0: 0xFF000000 | data2
iwlwifi 0000:3b:00.0: 0xF0000008 | data3
iwlwifi 0000:3b:00.0: 0x1D00A576 | beacon time
iwlwifi 0000:3b:00.0: 0x49287A91 | tsf low
iwlwifi 0000:3b:00.0: 0x00000135 | tsf hi
iwlwifi 0000:3b:00.0: 0x00000000 | time gp1
iwlwifi 0000:3b:00.0: 0x0635EC2D | time gp2
iwlwifi 0000:3b:00.0: 0x00000001 | uCode revision type
iwlwifi 0000:3b:00.0: 0x0000002E | uCode version major
iwlwifi 0000:3b:00.0: 0x8902351F | uCode version minor
iwlwifi 0000:3b:00.0: 0x00000321 | hw version
iwlwifi 0000:3b:00.0: 0x18489004 | board version
iwlwifi 0000:3b:00.0: 0x00B5019C | hcmd
iwlwifi 0000:3b:00.0: 0x24022000 | isr0
iwlwifi 0000:3b:00.0: 0x01000000 | isr1
iwlwifi 0000:3b:00.0: 0x0800180A | isr2
iwlwifi 0000:3b:00.0: 0x004140C0 | isr3
iwlwifi 0000:3b:00.0: 0x00000000 | isr4
iwlwifi 0000:3b:00.0: 0xACE5009D | last cmd Id
iwlwifi 0000:3b:00.0: 0x0001AD94 | wait_event
iwlwifi 0000:3b:00.0: 0x00000080 | l2p_control
iwlwifi 0000:3b:00.0: 0x00010034 | l2p_duration
iwlwifi 0000:3b:00.0: 0x0000003F | l2p_mhvalid
iwlwifi 0000:3b:00.0: 0x000000CE | l2p_addr_match
iwlwifi 0000:3b:00.0: 0x0000000D | lmpm_pmg_sel
iwlwifi 0000:3b:00.0: 0x02052032 | timestamp
iwlwifi 0000:3b:00.0: 0x00003020 | flow_handler
iwlwifi 0000:3b:00.0: Start IWL Error Log Dump:
iwlwifi 0000:3b:00.0: Status: 0x00000040, count: 7
iwlwifi 0000:3b:00.0: 0x20000066 | NMI_INTERRUPT_HOST
iwlwifi 0000:3b:00.0: 0x00000000 | umac branchlink1
iwlwifi 0000:3b:00.0: 0xC0088BDA | umac branchlink2
iwlwifi 0000:3b:00.0: 0xC0084474 | umac interruptlink1
iwlwifi 0000:3b:00.0: 0xC0084474 | umac interruptlink2
iwlwifi 0000:3b:00.0: 0x01000000 | umac data1
iwlwifi 0000:3b:00.0: 0xC0084474 | umac data2
iwlwifi 0000:3b:00.0: 0xDEADBEEF | umac data3
iwlwifi 0000:3b:00.0: 0x0000002E | umac major
iwlwifi 0000:3b:00.0: 0x8902351F | umac minor
iwlwifi 0000:3b:00.0: 0x0635EC19 | frame pointer
iwlwifi 0000:3b:00.0: 0xC088627C | stack pointer
iwlwifi 0000:3b:00.0: 0x00B5019C | last host cmd
iwlwifi 0000:3b:00.0: 0x00000000 | isr status reg
iwlwifi 0000:3b:00.0: Fseq Registers:
iwlwifi 0000:3b:00.0: 0x29809555 | FSEQ_ERROR_CODE
iwlwifi 0000:3b:00.0: 0x00000000 | FSEQ_TOP_INIT_VERSION
iwlwifi 0000:3b:00.0: 0x2216A2E5 | FSEQ_CNVIO_INIT_VERSION
iwlwifi 0000:3b:00.0: 0x0000A371 | FSEQ_OTP_VERSION
iwlwifi 0000:3b:00.0: 0xF62FA5DF | FSEQ_TOP_CONTENT_VERSION
iwlwifi 0000:3b:00.0: 0x3605FCFC | FSEQ_ALIVE_TOKEN
iwlwifi 0000:3b:00.0: 0x49ABC47B | FSEQ_CNVI_ID
iwlwifi 0000:3b:00.0: 0x88A63481 | FSEQ_CNVR_ID
iwlwifi 0000:3b:00.0: 0x01000200 | CNVI_AUX_MISC_CHIP
iwlwifi 0000:3b:00.0: 0x01300202 | CNVR_AUX_MISC_CHIP
iwlwifi 0000:3b:00.0: 0x0000485B | CNVR_SCU_SD_REGS_SD_REG_DIG_DCDC_VTRIM
iwlwifi 0000:3b:00.0: 0x0BADCAFE | CNVR_SCU_SD_REGS_SD_REG_ACTIVE_VDIG_MIRROR
iwlwifi 0000:3b:00.0: Collecting data: trigger 2 fired.
iwlwifi 0000:3b:00.0: Applying debug destination EXTERNAL_DRAM
iwlwifi 0000:3b:00.0: Applying debug destination EXTERNAL_DRAM
iwlwifi 0000:3b:00.0: FW already configured (0) - re-configuring
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: No beacon heard and the time event is over already...
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
iwlwifi 0000:3b:00.0: Unhandled alg: 0x707
Comment 82 CaoCong 2020-09-18 01:27:44 UTC
Still seeing this on Fedora 5.8.9-200.fc32.x86_64 with Intel 9260AC

06:00.0 Network controller: Intel Corporation Wireless-AC 9260 (rev 29)
	Subsystem: Intel Corporation Device 0014
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 31
	Region 0: Memory at fca00000 (64-bit, non-prefetchable) [size=16K]
	Capabilities: <access denied>
	Kernel driver in use: iwlwifi
	Kernel modules: iwlwifi

dmesg
[    4.874253] iwlwifi 0000:06:00.0: enabling device (0000 -> 0002)
[    4.876750] iwlwifi 0000:06:00.0: Direct firmware load for iwlwifi-9260-th-b0-jf-b0-46.ucode failed with error -2
[    4.876779] iwlwifi 0000:06:00.0: Direct firmware load for iwlwifi-9260-th-b0-jf-b0-45.ucode failed with error -2
[    4.876800] iwlwifi 0000:06:00.0: Direct firmware load for iwlwifi-9260-th-b0-jf-b0-44.ucode failed with error -2
[    4.879423] iwlwifi 0000:06:00.0: loaded firmware version 43.95eb4e97.0 9260-th-b0-jf-b0-43.ucode op_mode iwlmvm
[    4.879460] iwlwifi 0000:06:00.0: Direct firmware load for iwl-debug-yoyo.bin failed with error -2
[    5.214618] iwlwifi 0000:06:00.0: Detected Intel(R) Wireless-AC 9260, REV=0x324
[    5.261385] iwlwifi 0000:06:00.0: base HW address: a0:51:0b:59:36:0c
[    5.337448] iwlwifi 0000:06:00.0 wlp6s0: renamed from wlan0
[   10.691585] wlp6s0: authenticate with f4:83:cd:39:3b:e0
[   10.695511] wlp6s0: send auth to f4:83:cd:39:3b:e0 (try 1/3)
[   10.734180] wlp6s0: authenticated
[   10.734992] wlp6s0: associate with f4:83:cd:39:3b:e0 (try 1/3)
[   10.742692] wlp6s0: RX AssocResp from f4:83:cd:39:3b:e0 (capab=0x431 status=0 aid=4)
[   10.746595] wlp6s0: associated
[   10.775646] IPv6: ADDRCONF(NETDEV_CHANGE): wlp6s0: link becomes ready
[20886.672051] iwlwifi 0000:06:00.0: Unhandled alg: 0x71b
[20886.677211] iwlwifi 0000:06:00.0: Unhandled alg: 0x71b
[20886.684446] iwlwifi 0000:06:00.0: Unhandled alg: 0x71b
[20886.697959] iwlwifi 0000:06:00.0: Unhandled alg: 0x71b
[20887.675252] iwlwifi 0000:06:00.0: Unhandled alg: 0x71b
[20887.965252] wlp6s0: authenticate with f4:83:cd:39:3b:e0
[20887.968097] wlp6s0: send auth to f4:83:cd:39:3b:e0 (try 1/3)
[20887.970380] iwlwifi 0000:06:00.0: Unhandled alg: 0x707
[20887.972482] iwlwifi 0000:06:00.0: Unhandled alg: 0x707
[20887.975214] wlp6s0: authenticated
[20887.975638] wlp6s0: associate with f4:83:cd:39:3b:e0 (try 1/3)
[20887.981314] wlp6s0: RX AssocResp from f4:83:cd:39:3b:e0 (capab=0x431 status=0 aid=4)
[20887.983750] wlp6s0: associated
Comment 83 CaoCong 2020-09-18 01:48:13 UTC
Wireless NIC Driver Information:
firmware-version: 43.95eb4e97.0 9260-th-b0-jf-b0-
Comment 84 Clemens Eisserer 2020-10-22 05:26:09 UTC
Just experienced a de- and reconnect with 5.8.15-201.fc32.x86_64 and 03:00.0 Network controller: Intel Corporation Wi-Fi 6 AX200 (rev 1a)

doesn't seem to be fixed, re-open it please.
Comment 85 Jeff Sauer 2020-12-27 00:15:22 UTC
still seeing this issue... HP Elitebook 845 G7 with Intel AX200 Wifi 6, Kernel: 5.9.14-arch1-1 

01:00.0 Network controller: Intel Corporation Wi-Fi 6 AX200 (rev 1a)

 3459.041727] wlan0: RX AssocResp from 24:a0:74:76:bb:8b (capab=0x1011 status=0 aid=4)
[ 3459.055040] wlan0: associated
[ 3459.060532] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 3459.095167] audit: type=1130 audit(1609026501.727:147): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 3459.119301] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 24:a0:74:76:bb:8b
[ 3459.131222] audit: type=1111 audit(1609026501.763:148): pid=616 uid=0 auid=4294967295 ses=4294967295 msg='op=statistics arg="refresh-rate-ms" pid=1508 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
[ 3462.711063] audit: type=1111 audit(1609026505.343:149): pid=616 uid=0 auid=4294967295 ses=4294967295 msg='op=statistics arg="refresh-rate-ms" pid=1508 uid=1000 result=success exe="/usr/bin/NetworkManager" hostname=? addr=? terminal=? res=success'
[ 3469.102684] audit: type=1131 audit(1609026511.733:150): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 3506.391595] wlan0: disconnect from AP 24:a0:74:76:bb:8b for new auth to 0c:51:01:e6:b4:d9
[ 3506.407380] wlan0: authenticate with 0c:51:01:e6:b4:d9
[ 3506.419377] wlan0: send auth to 0c:51:01:e6:b4:d9 (try 1/3)
[ 3506.450469] wlan0: authenticated
[ 3506.453322] wlan0: associate with 0c:51:01:e6:b4:d9 (try 1/3)
[ 3506.454983] wlan0: RX ReassocResp from 0c:51:01:e6:b4:d9 (capab=0x1011 status=0 aid=11)
[ 3506.472114] wlan0: associated
[ 3506.516260] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 0c:51:01:e6:b4:d9
[ 3639.286150] wlan0: disconnect from AP 0c:51:01:e6:b4:d9 for new auth to 24:a0:74:76:bb:8b
[ 3639.301487] wlan0: authenticate with 24:a0:74:76:bb:8b
[ 3639.313587] wlan0: send auth to 24:a0:74:76:bb:8b (try 1/3)
[ 3639.345303] wlan0: authenticated
[ 3639.346631] wlan0: associate with 24:a0:74:76:bb:8b (try 1/3)
[ 3639.348487] wlan0: RX ReassocResp from 24:a0:74:76:bb:8b (capab=0x1011 status=0 aid=4)
[ 3639.363596] wlan0: associated
[ 3639.446315] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 24:a0:74:76:bb:8b
[ 3643.438194] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3643.783182] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3671.678684] wlan0: disconnect from AP 24:a0:74:76:bb:8b for new auth to 34:12:98:08:83:8d
[ 3671.693385] wlan0: authenticate with 34:12:98:08:83:8d
[ 3671.708133] wlan0: send auth to 34:12:98:08:83:8d (try 1/3)
[ 3671.739019] wlan0: authenticated
[ 3671.739950] wlan0: associate with 34:12:98:08:83:8d (try 1/3)
[ 3671.742348] wlan0: RX ReassocResp from 34:12:98:08:83:8d (capab=0x1011 status=0 aid=6)
[ 3671.758709] wlan0: associated
[ 3671.763073] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 34:12:98:08:83:8d
[ 3704.708379] wlan0: disconnect from AP 34:12:98:08:83:8d for new auth to 0c:51:01:e6:b4:d9
[ 3704.723606] wlan0: authenticate with 0c:51:01:e6:b4:d9
[ 3704.737108] wlan0: send auth to 0c:51:01:e6:b4:d9 (try 1/3)
[ 3704.767799] wlan0: authenticated
[ 3704.769951] wlan0: associate with 0c:51:01:e6:b4:d9 (try 1/3)
[ 3704.771621] wlan0: RX ReassocResp from 0c:51:01:e6:b4:d9 (capab=0x1011 status=0 aid=11)
[ 3704.785675] wlan0: associated
[ 3704.869838] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 0c:51:01:e6:b4:d9
[ 3732.202586] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3736.503938] wlan0: disconnect from AP 0c:51:01:e6:b4:d9 for new auth to 24:a0:74:76:bb:8b
[ 3736.520387] wlan0: authenticate with 24:a0:74:76:bb:8b
[ 3736.534859] wlan0: send auth to 24:a0:74:76:bb:8b (try 1/3)
[ 3736.568387] wlan0: authenticated
[ 3736.569947] wlan0: associate with 24:a0:74:76:bb:8b (try 1/3)
[ 3736.571752] wlan0: RX ReassocResp from 24:a0:74:76:bb:8b (capab=0x1011 status=0 aid=4)
[ 3736.586957] wlan0: associated
[ 3736.624763] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 24:a0:74:76:bb:8b
[ 3739.439958] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3739.439983] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3739.735377] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3740.297823] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3741.091986] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3741.219264] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3742.448094] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3743.370628] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3744.291276] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3745.214185] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3746.749087] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3762.725000] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3764.566580] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3765.487639] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3767.492972] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3771.632351] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3786.992080] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3787.921058] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3788.835833] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3791.908362] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3798.973695] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3801.124139] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3802.045731] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3802.882166] wlan0: disconnect from AP 24:a0:74:76:bb:8b for new auth to 34:12:98:08:83:8d
[ 3802.899407] wlan0: authenticate with 34:12:98:08:83:8d
[ 3802.912888] wlan0: send auth to 34:12:98:08:83:8d (try 1/3)
[ 3802.944609] wlan0: authenticated
[ 3802.946619] wlan0: associate with 34:12:98:08:83:8d (try 1/3)
[ 3802.948285] wlan0: RX ReassocResp from 34:12:98:08:83:8d (capab=0x1011 status=0 aid=3)
[ 3802.962571] wlan0: associated
[ 3803.044253] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 34:12:98:08:83:8d
[ 3806.249778] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3807.699011] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3811.539276] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3819.685304] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3836.198352] wlan0: disconnect from AP 34:12:98:08:83:8d for new auth to 0c:51:01:e6:b4:d9
[ 3836.214624] wlan0: authenticate with 0c:51:01:e6:b4:d9
[ 3836.230397] wlan0: send auth to 0c:51:01:e6:b4:d9 (try 1/3)
[ 3836.261900] wlan0: authenticated
[ 3836.263273] wlan0: associate with 0c:51:01:e6:b4:d9 (try 1/3)
[ 3836.265460] wlan0: RX ReassocResp from 0c:51:01:e6:b4:d9 (capab=0x1011 status=0 aid=11)
[ 3836.280628] wlan0: associated
[ 3836.352938] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 0c:51:01:e6:b4:d9
[ 3869.197069] wlan0: disconnect from AP 0c:51:01:e6:b4:d9 for new auth to 24:a0:74:76:bb:8b
[ 3869.212293] wlan0: authenticate with 24:a0:74:76:bb:8b
[ 3869.226842] wlan0: send auth to 24:a0:74:76:bb:8b (try 1/3)
[ 3869.257905] wlan0: authenticated
[ 3869.260220] wlan0: associate with 24:a0:74:76:bb:8b (try 1/3)
[ 3869.261762] wlan0: RX ReassocResp from 24:a0:74:76:bb:8b (capab=0x1011 status=0 aid=4)
[ 3869.280259] wlan0: associated
[ 3869.330210] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 24:a0:74:76:bb:8b
[ 3872.439530] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3872.439537] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3872.439754] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3873.312238] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3873.625361] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3874.547579] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3875.468405] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3876.390170] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3877.618528] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3878.539406] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3879.460598] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3887.756163] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3899.736191] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3909.873954] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3914.180467] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3925.234761] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3927.075517] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3934.142382] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3937.214264] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3943.674103] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3952.575710] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3964.555386] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 3969.039021] wlan0: disconnect from AP 24:a0:74:76:bb:8b for new auth to 0c:51:01:e6:b4:d9
[ 3969.056347] wlan0: authenticate with 0c:51:01:e6:b4:d9
[ 3969.068947] wlan0: send auth to 0c:51:01:e6:b4:d9 (try 1/3)
[ 3969.099342] wlan0: authenticated
[ 3969.099943] wlan0: associate with 0c:51:01:e6:b4:d9 (try 1/3)
[ 3969.101881] wlan0: RX ReassocResp from 0c:51:01:e6:b4:d9 (capab=0x1011 status=0 aid=11)
[ 3969.115817] wlan0: associated
[ 3969.166325] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 0c:51:01:e6:b4:d9
[ 4232.641696] wlan0: disconnect from AP 0c:51:01:e6:b4:d9 for new auth to 34:12:98:08:83:8d
[ 4232.657855] wlan0: authenticate with 34:12:98:08:83:8d
[ 4232.670207] wlan0: send auth to 34:12:98:08:83:8d (try 1/3)
[ 4232.701514] wlan0: authenticated
[ 4232.703298] wlan0: associate with 34:12:98:08:83:8d (try 1/3)
[ 4232.705301] wlan0: RX ReassocResp from 34:12:98:08:83:8d (capab=0x1011 status=0 aid=3)
[ 4232.724226] wlan0: associated
[ 4232.726086] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 34:12:98:08:83:8d
[ 4241.461758] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.353281] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.353610] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.354436] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.434685] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.447902] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.447922] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.448034] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.528706] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4242.674306] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4309.327802] net_ratelimit: 6 callbacks suppressed
[ 4309.327809] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4344.167382] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4370.067817] audit: type=1130 audit(1609027412.701:151): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 4380.106647] audit: type=1131 audit(1609027422.741:152): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 4395.145932] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4395.146200] iwlwifi 0000:01:00.0: Unhandled alg: 0x71b
[ 4494.243436] wlan0: disconnect from AP 34:12:98:08:83:8d for new auth to 0c:51:01:e6:b4:d9
[ 4494.262262] wlan0: authenticate with 0c:51:01:e6:b4:d9
[ 4494.278258] wlan0: send auth to 0c:51:01:e6:b4:d9 (try 1/3)
[ 4494.309779] wlan0: authenticated
[ 4494.313284] wlan0: associate with 0c:51:01:e6:b4:d9 (try 1/3)
[ 4494.314833] wlan0: RX ReassocResp from 0c:51:01:e6:b4:d9 (capab=0x1011 status=0 aid=11)
[ 4494.331561] wlan0: associated
[ 4494.407754] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 0c:51:01:e6:b4:d9
[ 4497.538617] audit: type=1130 audit(1609027540.168:153): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 4501.488535] audit: type=1100 audit(1609027544.118:154): pid=10747 uid=1000 auid=1000 ses=2 msg='op=PAM:unix_chkpwd acct="jsauer" exe="/usr/bin/unix_chkpwd" hostname=? addr=? terminal=? res=success'
[ 4508.108374] audit: type=1131 audit(1609027550.739:155): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 4625.881039] wlan0: disconnect from AP 0c:51:01:e6:b4:d9 for new auth to 34:12:98:08:83:8d
[ 4625.897641] wlan0: authenticate with 34:12:98:08:83:8d
[ 4625.911964] wlan0: send auth to 34:12:98:08:83:8d (try 1/3)
[ 4625.942788] wlan0: authenticated
[ 4625.943189] wlan0: associate with 34:12:98:08:83:8d (try 1/3)
[ 4625.944966] wlan0: RX ReassocResp from 34:12:98:08:83:8d (capab=0x1011 status=0 aid=3)
[ 4625.963022] wlan0: associated
[ 4625.965598] wlan0: Limiting TX power to 17 (17 - 0) dBm as advertised by 34:12:98:08:83:8d
Comment 86 Luis Grisolía 2021-02-26 00:04:56 UTC
Same problem here, the weird thing is that it was working as expected until about 3 days ago, the only difference is that I haven't turned off my laptop since then and it has come out of sleep many times...

Lenovo Thinkpad P1

$uname -a
Linux fedora-p1 5.10.16-200.fc33.x86_64 #1 SMP Sun Feb 14 03:02:32 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

$lspsci -v
00:14.3 Network controller: Intel Corporation Wireless-AC 9560 [Jefferson Peak] (rev 10)
	Subsystem: Intel Corporation Device 0030
	Flags: bus master, fast devsel, latency 0, IRQ 16
	Memory at 604b10c000 (64-bit, non-prefetchable) [size=16K]
	Capabilities: <access denied>
	Kernel driver in use: iwlwifi
	Kernel modules: iwlwifi

$ lsmod | grep iw
iwlmvm                475136  0
mac80211             1081344  1 iwlmvm
iwlwifi               344064  1 iwlmvm
cfg80211              954368  3 iwlmvm,iwlwifi,mac80211

Firmware version 46.4d093a30.0 9000-pu-b0-jf-b0-46.ucode op_mode iwlmvm

Don't know if it's the same version intel web page advertises:
	iwlwifi-9000-pu-b0-jf-b0-34.618819.0.tgz

https://www.intel.com/content/www/us/en/support/articles/000005511/wireless.html

[luisgrisolia@fedora-p1]$ dmesg | grep iwl | more
[    4.360515] iwlwifi 0000:00:14.3: enabling device (0000 -> 0002)
[    4.371831] iwlwifi 0000:00:14.3: WRT: Overriding region id 0
[    4.371833] iwlwifi 0000:00:14.3: WRT: Overriding region id 1
[    4.371834] iwlwifi 0000:00:14.3: WRT: Overriding region id 2
[    4.371835] iwlwifi 0000:00:14.3: WRT: Overriding region id 3
[    4.371836] iwlwifi 0000:00:14.3: WRT: Overriding region id 4
[    4.371836] iwlwifi 0000:00:14.3: WRT: Overriding region id 6
[    4.371837] iwlwifi 0000:00:14.3: WRT: Overriding region id 8
[    4.371838] iwlwifi 0000:00:14.3: WRT: Overriding region id 9
[    4.371839] iwlwifi 0000:00:14.3: WRT: Overriding region id 10
[    4.371840] iwlwifi 0000:00:14.3: WRT: Overriding region id 11
[    4.371840] iwlwifi 0000:00:14.3: WRT: Overriding region id 15
[    4.371841] iwlwifi 0000:00:14.3: WRT: Overriding region id 16
[    4.371842] iwlwifi 0000:00:14.3: WRT: Overriding region id 18
[    4.371843] iwlwifi 0000:00:14.3: WRT: Overriding region id 19
[    4.371844] iwlwifi 0000:00:14.3: WRT: Overriding region id 20
[    4.371844] iwlwifi 0000:00:14.3: WRT: Overriding region id 21
[    4.371845] iwlwifi 0000:00:14.3: WRT: Overriding region id 28
[    4.372124] iwlwifi 0000:00:14.3: loaded firmware version 46.4d093a30.0 9000-pu-b0-jf-b0-46.ucode op_mode iwlmvm
[    4.705822] iwlwifi 0000:00:14.3: Detected Intel(R) Wireless-AC 9560 160MHz, REV=0x318
[    4.761078] iwlwifi 0000:00:14.3: base HW address: 34:13:e8:a3:7a:a5
[    4.826283] ieee80211 phy0: Selected rate control algorithm 'iwl-mvm-rs'
[    4.837799] iwlwifi 0000:00:14.3 wlp0s20f3: renamed from wlan0
[   82.604483] iwlwifi 0000:00:14.3: reached 10 old SN frames from bc:62:d2:01:36:c0 on queue 2, stopping BA session on TID 0
[  314.675262] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b
[ 1825.484118] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b
[ 1825.485242] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b
[ 1825.489706] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b
[ 2446.599930] iwlwifi 0000:00:14.3: reached 10 old SN frames from bc:62:d2:01:36:c0 on queue 2, stopping BA session on TID 4
[ 2521.087701] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b
[ 2521.089375] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b


Exiting dmesg after returning from sleep and followed by abrupt disconnect after a few minutes and some browsing:

[57517.567043] PM: suspend exit
[57517.652730] rfkill: input handler disabled
[57517.906571] usb 1-11: usbfs: process 1697 (pcscd) did not claim interface 0 before use
[57519.019557] Bluetooth: hci0: Waiting for firmware download to complete
[57519.020165] Bluetooth: hci0: Firmware loaded in 1479315 usecs
[57519.020280] Bluetooth: hci0: Waiting for device to boot
[57519.034181] Bluetooth: hci0: Device booted in 13680 usecs
[57519.034189] Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-17-16-1.ddc
[57519.036308] Bluetooth: hci0: Applying Intel DDC parameters completed
[57519.039274] Bluetooth: hci0: Firmware revision 0.1 build 168 week 48 2020
[57525.986229] wlp0s20f3: authenticate with bc:62:d2:01:36:c0
[57525.986255] wlp0s20f3: No basic rates, using min rate instead
[57525.988215] wlp0s20f3: send auth to bc:62:d2:01:36:c0 (try 1/3)
[57526.136200] wlp0s20f3: authenticated
[57526.137003] wlp0s20f3: associate with bc:62:d2:01:36:c0 (try 1/3)
[57526.147289] wlp0s20f3: RX AssocResp from bc:62:d2:01:36:c0 (capab=0x411 status=0 aid=2)
[57526.155442] wlp0s20f3: associated
[57526.257661] IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s20f3: link becomes ready
[57551.912357] wlp0s20f3: Connection to AP bc:62:d2:01:36:c0 lost
[57551.975971] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57551.988695] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.001871] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.052179] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.065490] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.067165] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.067180] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.067185] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.069540] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.072712] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.942871] wlp0s20f3: Connection to AP 00:00:00:00:00:00 lost
[57557.366892] wlp0s20f3: authenticate with bc:62:d2:01:36:c0
[57557.366913] wlp0s20f3: No basic rates, using min rate instead
[57557.374767] wlp0s20f3: send auth to bc:62:d2:01:36:c0 (try 1/3)
[57557.434988] wlp0s20f3: authenticated
[57557.435493] wlp0s20f3: associate with bc:62:d2:01:36:c0 (try 1/3)
[57557.444770] wlp0s20f3: RX AssocResp from bc:62:d2:01:36:c0 (capab=0x411 status=0 aid=2)
[57557.446541] wlp0s20f3: associated
[57557.990430] iwlwifi 0000:00:14.3: No beacon heard and the time event is over already...
[57557.990468] wlp0s20f3: Connection to AP bc:62:d2:01:36:c0 lost
[57577.987260] wlp0s20f3: authenticate with bc:62:d2:01:36:c0
[57577.987283] wlp0s20f3: No basic rates, using min rate instead
[57577.994889] wlp0s20f3: send auth to bc:62:d2:01:36:c0 (try 1/3)
[57578.056705] wlp0s20f3: authenticated
[57578.057334] wlp0s20f3: associate with bc:62:d2:01:36:c0 (try 1/3)
[57578.066162] wlp0s20f3: RX AssocResp from bc:62:d2:01:36:c0 (capab=0x411 status=0 aid=2)
[57578.072967] wlp0s20f3: associated
[57578.241991] IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s20f3: link becomes ready
[57694.720440] net_ratelimit: 12 callbacks suppressed
[57694.720443] iwlwifi 0000:00:14.3: Unhandled alg: 0xc040071b

I think you guys should re-open or at least provide more information about this problem.

[57552.072712] iwlwifi 0000:00:14.3: Unhandled alg: 0xc0400707
[57552.942871] wlp0s20f3: Connection to AP 00:00:00:00:00:00 lost

These two lines indicates something interesting, the AP reports an "impossible" mac address and it may suggest AP spoofing, I'm not really sure and have no time for further testing now but I think this bug could lead to security issues.

Thanks for your work, 
Luis Grisolia

Note You need to log in before you can comment on or make changes to this bug.