search

greearb / ath10k-ct

Stand-alone ath10k driver based on Candela Technologies Linux kernel.
111 stars 41 forks source link

QCA9984 IBSS iperf throughput starts at 1 Mbps and goes to 500 Mbps after a rekey #19

Open Arthur-Watt opened 6 years ago

Arthur-Watt commented 6 years ago

driver: ath10k_pci version: 4.14.4-g5e2cc4f firmware-version: 10.4-ct-9984-fW-010-762fdfe

When I start the IBSS throughput test it can get very good data rates (500 Mbps) and these good data rates can continue for a long period of time. Other times when I start the IBSS and run the throughput test the data rates are 1 Mbps, and continue that way for an extended period of time until a rekey is completed. When the rekey is completed the rates jump up to 500 Mbps.

Here is a snapshot of the log showing the throughput rise after the rekey.

Mar 19 14:36:27 iesv06 kernel: [ 734.689012] ath10k_pci 0001:20:00.0: wmi request nop (id 305) Mar 19 14:36:27 iesv06 vsys: [ 3] 501.0-502.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:28 iesv06 vsys: [ 3] 502.0-503.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:29 iesv06 vsys: [ 3] 503.0-504.0 sec 128 KBytes 1.05 Mbits/sec Mar 19 14:36:29 iesv06 kernel: [ 736.705009] ath10k_pci 0001:20:00.0: wmi request nop (id 306) Mar 19 14:36:30 iesv06 vsys: [ 3] 504.0-505.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:31 iesv06 kernel: [ 738.720961] ath10k_pci 0001:20:00.0: wmi request nop (id 307) Mar 19 14:36:31 iesv06 kernel: [ 738.725338] ath10k_pci 0001:20:00.0: wmi pdev get temperature Mar 19 14:36:31 iesv06 kernel: [ 738.725660] ath10k_pci 0001:20:00.0: wmi pdev get temperature Mar 19 14:36:31 iesv06 vsys: [ 3] 505.0-506.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:32 iesv06 vsys: [ 3] 506.0-507.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:33 iesv06 kernel: [ 740.736974] ath10k_pci 0001:20:00.0: wmi request nop (id 308) Mar 19 14:36:34 iesv06 vsys: [ 3] 507.0-508.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:34 iesv06 vsys: [ 3] 508.0-509.0 sec 128 KBytes 1.05 Mbits/sec Mar 19 14:36:35 iesv06 kernel: [ 742.752950] ath10k_pci 0001:20:00.0: wmi request nop (id 309) Mar 19 14:36:36 iesv06 vsys: [ 3] 509.0-510.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:36 iesv06 vsys: [ 3] 510.0-511.0 sec 0.00 Bytes 0.00 bits/sec Mar 19 14:36:36 iesv06 kernel: [ 744.073189] ath10k_pci 0001:20:00.0: wmi pdev get temperature Mar 19 14:36:36 iesv06 kernel: [ 744.073367] ath10k_pci 0001:20:00.0: wmi pdev get temperature Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: l2_packet_receive: src=04:f0:21:38:98:a0 len=131 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: RX EAPOL from 04:f0:21:38:98:a0 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: RX EAPOL - hexdump(len=131): 02 03 00 7f 02 13 82 00 00 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f2 38 28 9f 6d 8f 18 82 30 fb 2a 28 f6 b0 23 9a 00 20 e4 59 5a 07 02 5c 33 e9 92 5a 70 6d 82 db 37 ab fc 77 22 fc ee 33 0c cb 65 7a 3f 19 40 b3 65 1c Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: RSN: IBSS RX EAPOL for Supplicant from 04:f0:21:38:98:a0 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: IEEE 802.1X RX: version=2 type=3 length=127 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: RX EAPOL-Key - hexdump(len=131): 02 03 00 7f 02 13 82 00 00 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f2 38 28 9f 6d 8f 18 82 30 fb 2a 28 f6 b0 23 9a 00 20 e4 59 5a 07 02 5c 33 e9 92 5a 70 6d 82 db 37 ab fc 77 22 fc ee 33 0c cb 65 7a 3f 19 40 b3 65 1c Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: EAPOL-Key type=2 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: key_info 0x1382 (ver=2 keyidx=0 rsvd=0 Group Ack MIC Secure Encr) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: key_length=0 key_data_length=32 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03 Mar 19 14:36:37 iesv06 kernel: [ 744.680963] ath10k_pci 0001:20:00.0: wmi vdev 0 install key peer 04:f0:21:38:98:a0 idx 2 cipher 4 len 16 flags 0x1 Mar 19 14:36:37 iesv06 kernel: [ 744.680982] ath10k_pci 0001:20:00.0: wmi echo value 0x0ba991e9 Mar 19 14:36:37 iesv06 kernel: [ 744.681163] ath10k_pci 0001:20:00.0: wmi event echo value 0x0ba991e9 Mar 19 14:36:37 iesv06 kernel: [ 744.681198] ath10k_pci 0001:20:00.0: wmi vdev id 0x0 set param 33 value 2 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: key_nonce - hexdump(len=32): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: key_mic - hexdump(len=16): f2 38 28 9f 6d 8f 18 82 30 fb 2a 28 f6 b0 23 9a Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: EAPOL-Key MIC using HMAC-SHA1 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: RSN: encrypted key data - hexdump(len=32): e4 59 5a 07 02 5c 33 e9 92 5a 70 6d 82 db 37 ab fc 77 22 fc ee 33 0c cb 65 7a 3f 19 40 b3 65 1c Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: Decrypt Key Data using AES-UNWRAP (KEK length 16) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: decrypted EAPOL-Key key data - hexdump(len=24): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: WPA: RX message 1 of Group Key Handshake from 04:f0:21:38:98:a0 (ver=2) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: RSN: msg 1/2 key data - hexdump(len=24): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: RSN: received GTK in group key handshake - hexdump(len=18): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: Group Key - hexdump(len=16): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: WPA: Installing GTK to the driver (keyidx=2 tx=0 len=16) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: RSC - hexdump(len=6): 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: SUPP: supp_set_key(alg=3 addr=ff:ff:ff:ff:ff:ff key_idx=2 set_tx=0) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: SUPP: set_key - seq - hexdump(len=6): 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: SUPP: set_key - key - hexdump(len=16): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wpa_driver_nl80211_set_key: ifindex=5 (wlan0) alg=3 addr=0x22013f50 key_idx=2 set_tx=0 seq_len=6 key_len=16 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: nl80211: KEY_DATA - hexdump(len=16): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: nl80211: KEY_SEQ - hexdump(len=6): 00 00 00 00 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: addr=04:f0:21:38:98:a0 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: RSN IBSS RX GTK Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: SUPP: supp_alloc_eapol(type=3 data_len=95) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: WPA: Sending EAPOL-Key 2/2 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: Send EAPOL-Key frame to 04:f0:21:38:98:a0 ver=2 mic_len=16 key_mgmt=0x2 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: EAPOL-Key MIC using HMAC-SHA1 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: KCK - hexdump(len=16): [REMOVED] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: Derived Key MIC - hexdump(len=16): 9c 63 51 02 d6 2a 62 8e 53 d0 cf 5d 79 e3 eb e8 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: WPA: TX EAPOL-Key - hexdump(len=99): 02 03 00 5f 02 03 02 00 00 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 9c 63 51 02 d6 2a 62 8e 53 d0 cf 5d 79 e3 eb e8 00 00 Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: SUPP: supp_ether_send(dest=04:f0:21:38:98:a0 proto=0x888e len=99) Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: wlan0: WPA: Group rekeying completed with 04:f0:21:38:98:a0 [GTK=CCMP] Mar 19 14:36:37 iesv06 wpa_supplicant[3334]: SUPP: supp_cancel_auth_timeout Mar 19 14:36:37 iesv06 kernel: [ 744.768923] ath10k_pci 0001:20:00.0: wmi request nop (id 310) Mar 19 14:36:37 iesv06 vsys: [ 3] 511.0-512.0 sec 256 KBytes 2.10 Mbits/sec Mar 19 14:36:37 iesv06 kernel: [ 745.023816] ath10k_pci 0001:20:00.0: wmi event debug mesg len 108 Mar 19 14:36:37 iesv06 kernel: [ 745.023826] ath10k_pci 0001:20:00.0: ath10k_pci ATH10K_DBG_BUFFER: [snip --Ben ] Mar 19 14:36:37 iesv06 vsys: [ 3] 512.0-513.0 sec 7.25 MBytes 60.8 Mbits/sec Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: l2_packet_receive: src=04:f0:21:38:98:a0 len=131 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: RX EAPOL from 04:f0:21:38:98:a0 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: RX EAPOL - hexdump(len=131): 02 03 00 7f 02 13 82 00 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8e ea 80 69 8c d6 d8 ab 0a 9e d7 34 e9 a1 e2 96 00 20 e4 59 5a 07 02 5c 33 e9 92 5a 70 6d 82 db 37 ab fc 77 22 fc ee 33 0c cb 65 7a 3f 19 40 b3 65 1c Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: RSN: IBSS RX EAPOL for Supplicant from 04:f0:21:38:98:a0 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: IEEE 802.1X RX: version=2 type=3 length=127 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: RX EAPOL-Key - hexdump(len=131): 02 03 00 7f 02 13 82 00 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8e ea 80 69 8c d6 d8 ab 0a 9e d7 34 e9 a1 e2 96 00 20 e4 59 5a 07 02 5c 33 e9 92 5a 70 6d 82 db 37 ab fc 77 22 fc ee 33 0c cb 65 7a 3f 19 40 b3 65 1c Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: EAPOL-Key type=2 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: key_info 0x1382 (ver=2 keyidx=0 rsvd=0 Group Ack MIC Secure Encr) Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: key_length=0 key_data_length=32 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: key_nonce - hexdump(len=32): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: key_mic - hexdump(len=16): 8e ea 80 69 8c d6 d8 ab 0a 9e d7 34 e9 a1 e2 96 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: EAPOL-Key MIC using HMAC-SHA1 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: RSN: encrypted key data - hexdump(len=32): e4 59 5a 07 02 5c 33 e9 92 5a 70 6d 82 db 37 ab fc 77 22 fc ee 33 0c cb 65 7a 3f 19 40 b3 65 1c Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: Decrypt Key Data using AES-UNWRAP (KEK length 16) Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: decrypted EAPOL-Key key data - hexdump(len=24): [REMOVED] Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: WPA: RX message 1 of Group Key Handshake from 04:f0:21:38:98:a0 (ver=2) Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: RSN: msg 1/2 key data - hexdump(len=24): [REMOVED] Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED] Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: RSN: received GTK in group key handshake - hexdump(len=18): [REMOVED] Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: WPA: Not reinstalling already in-use GTK to the driver (keyidx=2 tx=0 len=16) Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: SUPP: supp_alloc_eapol(type=3 data_len=95) Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: WPA: Sending EAPOL-Key 2/2 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: Send EAPOL-Key frame to 04:f0:21:38:98:a0 ver=2 mic_len=16 key_mgmt=0x2 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: EAPOL-Key MIC using HMAC-SHA1 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: KCK - hexdump(len=16): [REMOVED] Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: Derived Key MIC - hexdump(len=16): 30 96 f3 1a 2e 6a 7a 0a d1 25 c8 e6 8f a8 f4 ac Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: WPA: TX EAPOL-Key - hexdump(len=99): 02 03 00 5f 02 03 02 00 00 00 00 00 00 00 00 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 30 96 f3 1a 2e 6a 7a 0a d1 25 c8 e6 8f a8 f4 ac 00 00 Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: SUPP: supp_ether_send(dest=04:f0:21:38:98:a0 proto=0x888e len=99) Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: wlan0: WPA: Group rekeying completed with 04:f0:21:38:98:a0 [GTK=CCMP] Mar 19 14:36:38 iesv06 wpa_supplicant[3334]: SUPP: supp_cancel_auth_timeout Mar 19 14:36:38 iesv06 vsys: [ 3] 513.0-514.0 sec 64.5 MBytes 541 Mbits/sec Mar 19 14:36:39 iesv06 kernel: [ 746.784951] ath10k_pci 0001:20:00.0: wmi request nop (id 311) Mar 19 14:36:39 iesv06 vsys: [ 3] 514.0-515.0 sec 59.4 MBytes 498 Mbits/sec Mar 19 14:36:40 iesv06 vsys: [ 3] 515.0-516.0 sec 64.2 MBytes 539 Mbits/sec Mar 19 14:36:41 iesv06 kernel: [ 748.800917] ath10k_pci 0001:20:00.0: wmi request nop (id 312) Mar 19 14:36:41 iesv06 vsys: [ 3] 516.0-517.0 sec 51.9 MBytes 435 Mbits/sec Mar 19 14:36:42 iesv06 kernel: [ 749.422516] ath10k_pci 0001:20:00.0: wmi pdev get temperature Mar 19 14:36:42 iesv06 kernel: [ 749.422765] ath10k_pci 0001:20:00.0: wmi pdev get temperature Mar 19 14:36:42 iesv06 vsys: [ 3] 517.0-518.0 sec 56.0 MBytes 470 Mbits/sec

greearb commented 6 years ago

The re-key is for bcast/mcast frames, so when sniffing, possible issues would be ARP not working or something like that.

In past issues with firmware keys, I noticed bugs that would cause on-air frames to be too large or too small. So for instance, if you decoded the frames (or sent known-sized frames and compared on-air sniffs), you would see trailing garbage or truncated frames. I'm not aware of any of those bugs still existing, but it is something to watch for.

I think the first thing to do is to grab a pkt sniff in the problem case and use wireshark to decode it. And, check ARP tables on both sides to see if the system is having ARP issues (and/or sniff the wlanX interface, which should show decoded frames, to make sure it shows ARP request and response properly.

Arthur-Watt commented 6 years ago

Another interesting point is that in this state when I reversed the direction of traffic I got 500 Mbps. Then I went back to the original and also got 500 Mbps???

Cheers Arthur

From: Ben Greear [mailto:notifications@github.com] Sent: 19 March 2018 15:50 To: greearb/ath10k-ct ath10k-ct@noreply.github.com Cc: Arthur Watt arthur.watt@virtuosys.com; Author author@noreply.github.com Subject: Re: [greearb/ath10k-ct] QCA9984 IBSS iperf throughput starts at 1 Mbps and goes to 500 Mbps after a rekey (#19)

The re-key is for bcast/mcast frames, so when sniffing, possible issues would be ARP not working or something like that.

In past issues with firmware keys, I noticed bugs that would cause on-air frames to be too large or too small. So for instance, if you decoded the frames (or sent known-sized frames and compared on-air sniffs), you would see trailing garbage or truncated frames. I'm not aware of any of those bugs still existing, but it is something to watch for.

I think the first thing to do is to grab a pkt sniff in the problem case and use wireshark to decode it. And, check ARP tables on both sides to see if the system is having ARP issues (and/or sniff the wlanX interface, which should show decoded frames, to make sure it shows ARP request and response properly.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHubhttps://github.com/greearb/ath10k-ct/issues/19#issuecomment-374261112, or mute the threadhttps://github.com/notifications/unsubscribe-auth/AjzrskrESpnekJP_yMQIPBQ9Y3u-DGMaks5tf9O0gaJpZM4SwVvk.

greearb commented 6 years ago

Here are my notes from viewing the logs. The re-key is correlated with improved performance, but there was one re-key where performance did not improve, and in the second rekey where it did, performance started improving before the rekey completed. There was a rekey failure during the time it started recovering, not sure why that would be. I do not see anything obviously incorrect in the firmware dbglog messages. So, if you get more logs of this behavior, please email them to me and/or investigate closely to see if the pattern repeats to some degree.

node-1:
Mar 19 14:26:18: connection is established, mcast key set, key-idx 1 Mar 19 14:26:37: Associate and set mcast key, idx 1. Key is cleared and (re)set, key-idx 1 Mar 19 14:28:04: iperf starts, performance is poor Mar 19 14:36:18: Re-key happens, key-idx 2. Performance still poor. Mar 19 14:36:37: Re-key happens again, key-idx 2, iperf performance is good.

node-2: Mar 19 14:26:37: Associate and clear and set mcast. Key id 1

Supplicant logs show this: Not sure why or what this means exactly: ar 19 14:27:37 iesv06 wpa_supplicant[2971]: EAPOL: idleWhile --> 0 Mar 19 14:27:37 iesv06 wpa_supplicant[2971]: EAPOL: disable timer tick Mar 19 14:27:37 iesv06 wpa_supplicant[2971]: EAP: EAP entering state FAILURE Mar 19 14:27:37 iesv06 wpa_supplicant[2971]: wlan0: CTRL-EVENT-EAP-FAILURE EAP authentication failed

.... iperf starts, bandwidth is poor

Mar 19 14:36:18: Re-key happens, key-idx 2. Performance still poor. Mar 19 14:36:37: rekey starts happening Performance starts improving before rekey completes: Mar 19 14:36:37 iesv06 vsys: [ 4] 512.0-513.0 sec 7.25 MBytes 60.9 Mbits/sec Rekey failed due to timeout: Mar 19 14:36:38 iesv06 wpa_supplicant[2971]: AUTH: 04:f0:21:38:98:95 - EAPOL-Key timeout Mar 19 14:36:38: Re-key completes properly, system runs at full speed.

klukonin commented 6 years ago

@greearb This issue can be fixed with beacon_int = 10 too. We had the same issue and now we can't trigger a problem with such low beacon interval.

greearb commented 5 years ago

I've moved development efforts to a new firmware tree that is my patches rebased on top of newer QCA firmware. I'm very curious to know if that helps this problem or not.

Please grab one of the beta images from here: http://www.candelatech.com/ath10k-10.4.php