Received-SPF: pass (google.com: domain of linux-wireless+bounces-6396-linux.lists.archive=gmail.com@vger.kernel.org designates 147.75.199.223 as permitted sender) client-ip=147.75.199.223;
Message-ID: <6689d445-af96-47eb-bcb5-eb096a77f084@molgen.mpg.de>
Date: Tue, 16 Apr 2024 14:28:44 +0200
Precedence: bulk
MIME-Version: 1.0
User-Agent: Mozilla Thunderbird
Content-Language: en-US
To: Kalle Valo <kvalo@kernel.org>
Cc: linux-wireless@vger.kernel.org, ath10k@lists.infradead.org,
 linux-kernel@vger.kernel.org
From: Paul Menzel <pmenzel@molgen.mpg.de>
Subject: ath10k: Rekeying PTK for STA 10:06:ed:15:ac:6c but driver can't
 safely do that.
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 8bit

Dear Linux folks,


In a research institution using *eduroam*, I noticed on Dell XPS 13 9360 
with Debian sid/unstable

     $ lspci -nn -s 3a:00.0 -v
     3a:00.0 Network controller [0280]: Qualcomm Atheros QCA6174 
802.11ac Wireless Network Adapter [168c:003e] (rev 32)
         Subsystem: Rivet Networks Killer Wireless-n/a/ac 1535 Wireless 
Network Adapter [1a56:1535]
         Flags: bus master, fast devsel, latency 0, IRQ 137
         Memory at dc000000 (64-bit, non-prefetchable) [size=2M]
         Capabilities: <access denied>
         Kernel driver in use: ath10k_pci
         Kernel modules: ath10k_pci

that the Wireless connection dropped for a short time, and then 
reconnected again. Linux 6.9-rc3+ warns:

     [73861.687754] Rekeying PTK for STA 10:06:ed:15:ac:6c but driver 
can't safely do that.

According to the logs since March 2024, this never happened in other 
environments.

With wpa_supplicant logs:

```
[73862.470842] wpa_supplicant[595]: wlp58s0: CTRL-EVENT-EAP-STARTED EAP 
authentication started
[73862.485995] wpa_supplicant[595]: wlp58s0: 
CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25 -> NAK
[73862.499998] wpa_supplicant[595]: wlp58s0: 
CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=21
[73862.500424] wpa_supplicant[595]: wlp58s0: CTRL-EVENT-EAP-METHOD EAP 
vendor 0 method 21 (TTLS) selected
[…]
[73862.624544] wpa_supplicant[595]: wlp58s0: CTRL-EVENT-EAP-SUCCESS EAP 
authentication completed successfully
[73862.626116] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:17:9b:6c 0
[73862.626436] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:1a:45:8c 0
[73862.626723] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:19:6f:8c 0
[73862.626972] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:19:f1:0c 0
[73862.627211] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:15:ac:63 0
[73862.627435] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:19:82:6c 0
[73862.627699] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:17:9b:63 0
[73862.627911] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:19:f1:03 0
[73862.628245] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:19:6f:83 0
[73862.628451] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:17:de:0c 0
[73862.628645] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-REMOVED 
10:06:ed:15:ac:6c 0
[73862.628863] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:15:ac:6c 0
[73862.668477] wpa_supplicant[595]: wlp58s0: WPA: Key negotiation 
completed with 10:06:ed:15:ac:6c [PTK=CCMP GTK=CCMP]
[73861.687754] kernel: Rekeying PTK for STA 10:06:ed:15:ac:6c but driver 
can't safely do that.
[73864.676479] kernel: wlp58s0: disassociated from 10:06:ed:15:ac:6c 
(Reason: 15=4WAY_HANDSHAKE_TIMEOUT)
[73865.736655] wpa_supplicant[595]: wlp58s0: CTRL-EVENT-DISCONNECTED 
bssid=10:06:ed:15:ac:6c reason=15
[73865.738236] wpa_supplicant[595]: wlp58s0: CTRL-EVENT-REGDOM-CHANGE 
init=CORE type=WORLD
[73865.743914] NetworkManager[37941]: <info>  [1713258751.9001] device 
(wlp58s0): supplicant interface state: completed -> disconnected
[73865.745206] NetworkManager[37941]: <info>  [1713258751.9002] device 
(p2p-dev-wlp58s0): supplicant management interface state: completed -> 
disconnected
[73865.843396] NetworkManager[37941]: <info>  [1713258751.9996] device 
(wlp58s0): supplicant interface state: disconnected -> scanning
[73865.843901] NetworkManager[37941]: <info>  [1713258751.9997] device 
(p2p-dev-wlp58s0): supplicant management interface state: disconnected 
-> scanning
[73866.738215] wpa_supplicant[595]: wlp58s0: CTRL-EVENT-REGDOM-CHANGE 
init=BEACON_HINT type=UNKNOWN
[73870.738803] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:17:9b:6c 0
[73870.757221] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:1a:45:8c 0
[73870.757717] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:15:ac:63 0
[73870.758043] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:17:9b:63 0
[73870.760797] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:19:f1:03 0
[73870.761195] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:19:6f:8c 0
[73870.761530] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:19:6f:83 0
[73870.761817] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:19:f1:0c 0
[73870.762121] wpa_supplicant[595]: wlp58s0: PMKSA-CACHE-ADDED 
10:06:ed:17:de:0c 0
[73870.795881] wpa_supplicant[595]: wlp58s0: SME: Trying to authenticate 
with 10:06:ed:17:9b:6c (SSID='eduroam' freq=5280 MHz)
[73869.865071] kernel: wlp58s0: authenticate with 10:06:ed:17:9b:6c 
(local address=9c:b6:d0:d1:6a:b1)
[73869.865097] kernel: wlp58s0: send auth to 10:06:ed:17:9b:6c (try 1/3)
[73869.866808] kernel: wlp58s0: authenticated
[73870.869552] wpa_supplicant[595]: wlp58s0: Trying to associate with 
10:06:ed:17:9b:6c (SSID='eduroam' freq=5280 MHz)
[73869.916978] kernel: wlp58s0: associate with 10:06:ed:17:9b:6c (try 1/3)
[73869.922533] kernel: wlp58s0: RX AssocResp from 10:06:ed:17:9b:6c 
(capab=0x1111 status=0 aid=4)
[73869.928849] kernel: wlp58s0: associated
[73870.889860] wpa_supplicant[595]: wlp58s0: Associated with 
10:06:ed:17:9b:6c
[73870.890342] wpa_supplicant[595]: wlp58s0: 
CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
```

Could something done about that or is it a hardware limitation?


Kind regards,

Paul