failed to remove key (0, ce:ce:1e:27:bb:e0) from hardware (-110) (ETIMEDOUT)

[James Prestwood]

Hi Paul,

On 9/4/24 3:45 AM, Paul Menzel wrote:
> Dear Linux folks,
>
>
> Linux 6.11-rc6+ logged the warning below when resuming from ACPI S3 
> (or unloading and loading the `ath10k_core`/`ath10k_pci` modules) 
> having been connected to an AVM network:
>
>     wlp58s0: failed to remove key (0, ce:ce:1e:27:bb:e0) from hardware 
> (-110)
>
> Error code 110 is the value for ETIMEDOUT. I saw James patch [1], and 
> applied it, and the error is still there (as exepected).
My patch won't actually fix the timeout, I just lowered the time that 
ath10k would wait before it continued which fixed some incompatibility 
on the AP side of things. Based on your logs though, it appears you 
already got disconnected before the failure to remove the key...
>
> Can the warning be improved so the user know, which component is at 
> fault?
>
>
> Kind regards,
>
> Paul
>
>
> [1]: 
> https://lore.kernel.org/all/20240814164507.996303-1-prestwoj@gmail.com/
>
> ```
> Sep 04 07:21:38.469669 abreu kernel: Linux version 
> 6.11.0-rc6-00027-ga91d08fcc356 (build at bohemianrhapsody.molgen.mpg.de) 
> (gcc (Debian 14.2.0-4) 14.2.0, GNU ld (GNU Binutils for Debian) 
> 2.43.1) #294 SMP PREEMPT_DYNAMIC Tue Sep  3 23:01:18 CEST 2024
> Sep 04 07:21:38.469718 abreu kernel: Command line: 
> BOOT_IMAGE=/vmlinuz-6.11.0-rc6-00027-ga91d08fcc356 
> root=UUID=32e29882-d94d-4a92-9ee4-4d03002bfa29 ro quiet pci=noaer 
> mem_sleep_default=deep log_buf_len=8M cryptomgr.notests
> […]
> Sep 04 12:34:55.826218 abreu sudo[25874]:  pmenzel : TTY=pts/7 ; 
> PWD=/home/pmenzel ; USER=root ; COMMAND=/usr/sbin/modprobe ath10k_pci
> Sep 04 12:34:55.828046 abreu sudo[25874]: pam_unix(sudo:session): 
> session opened for user root(uid=0) by pmenzel(uid=5272)
> Sep 04 12:34:55.869839 abreu kernel: ath10k_pci 0000:3a:00.0: pci irq 
> msi oper_irq_mode 2 irq_mode 0 reset_mode 0
> Sep 04 12:34:56.005202 abreu sudo[25874]: pam_unix(sudo:session): 
> session closed for user root
> Sep 04 12:34:56.161706 abreu kernel: ath10k_pci 0000:3a:00.0: qca6174 
> hw3.2 target 0x05030000 chip_id 0x00340aff sub 1a56:1535
> Sep 04 12:34:56.162591 abreu kernel: ath10k_pci 0000:3a:00.0: kconfig 
> debug 0 debugfs 0 tracing 0 dfs 0 testmode 0
> Sep 04 12:34:56.163115 abreu kernel: ath10k_pci 0000:3a:00.0: firmware 
> ver WLAN.RM.4.4.1-00309- api 6 features wowlan,ignore-otp,mfp crc32 
> 0793bcf2
> Sep 04 12:34:56.241683 abreu kernel: ath10k_pci 0000:3a:00.0: 
> board_file api 2 bmi_id N/A crc32 d2863f91
> Sep 04 12:34:56.333784 abreu kernel: ath10k_pci 0000:3a:00.0: htt-ver 
> 3.87 wmi-op 4 htt-op 3 cal otp max-sta 32 raw 0 hwcrypto 1
> Sep 04 12:34:56.417649 abreu kernel: ath: EEPROM regdomain: 0x6c
> Sep 04 12:34:56.417919 abreu kernel: ath: EEPROM indicates we should 
> expect a direct regpair map
> Sep 04 12:34:56.418022 abreu kernel: ath: Country alpha2 being used: 00
> Sep 04 12:34:56.418114 abreu kernel: ath: Regpair used: 0x6c
> Sep 04 12:34:56.422440 abreu NetworkManager[610]: <info> 
> [1725446096.4223] device (wlan0): driver supports Access Point (AP) mode
> […]
> Sep 04 12:35:12.042484 abreu wpa_supplicant[618]: wlp58s0: WPA: Group 
> rekeying completed with ce:ce:1e:27:bb:e0 [GTK=CCMP]
> Sep 04 12:35:21.800998 abreu sudo[25953]:  pmenzel : TTY=pts/7 ; 
> PWD=/home/pmenzel ; USER=root ; COMMAND=/usr/sbin/modprobe -r ath10k_pci
> Sep 04 12:35:21.803733 abreu sudo[25953]: pam_unix(sudo:session): 
> session opened for user root(uid=0) by pmenzel(uid=5272)
> Sep 04 12:35:21.881668 abreu kernel: wlp58s0: deauthenticating from 
> ce:ce:1e:27:bb:e0 by local choice (Reason: 3=DEAUTH_LEAVING)
You get deauthenticated here, which then triggers the driver to remove 
the key...
> Sep 04 12:35:22.905717 abreu kernel: ath10k_pci 0000:3a:00.0: failed 
> to install key for vdev 0 peer ce:ce:1e:27:bb:e0: -110
> Sep 04 12:35:22.906604 abreu kernel: wlp58s0: failed to remove key (0, 
> ce:ce:1e:27:bb:e0) from hardware (-110)

And the removal fails. But afaict the removal failure was not the reason 
for the disconnect.

> Sep 04 12:35:22.908927 abreu wpa_supplicant[618]: wlp58s0: 
> CTRL-EVENT-DISCONNECTED bssid=ce:ce:1e:27:bb:e0 reason=3 
> locally_generated=1
> Sep 04 12:35:22.908995 abreu wpa_supplicant[618]: BSSID 
> ce:ce:1e:27:bb:e0 ignore list count incremented to 2, ignoring for 10 
> seconds
> ```