Anyone has idea why RX confirm mismatch may happen or how to debug? I have the following logs for one instance: Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: wlan1: AUTH: started authentication with SAE peer: b0:67:2f:00:15:65 Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: SAE: own commit-scalar - hexdump(len=32): d2 38 66 5e 1b 8c 84 17 02 c9 65 43 c8 d2 46 53 94 32 81 a3 9e 3c 05 5c 2f 37 b8 3a f1 09 90 b6 Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: SAE: own commit-element(x) - hexdump(len=32): fb 7f fc ee 71 89 90 fc c2 37 a0 90 6a a5 dd d7 ae 90 05 79 41 e2 65 20 4c be 3e 3b 5c 2e 25 e4 Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: SAE: own commit-element(y) - hexdump(len=32): 02 8e 46 e6 22 17 74 b4 4e f1 1e 00 48 b9 09 f8 74 41 89 e0 84 9b ab 69 c5 b6 05 10 e4 60 ed 7e Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: authentication reply: STA=b0:67:2f:00:15:65 auth_alg=3 auth_transaction=1 resp=0 (IE len=98) Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: nl80211: send_mlme - da= b0:67:2f:00:15:65 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7 Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: nl80211: send_mlme -> send_frame Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: nl80211: send_frame - Use bss->freq=5825 Aug 1 20:30:00 daemon.debug wpa_supplicant[2308]: nl80211: send_frame -> send_frame_cmd Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: SAE: Auth SAE retransmit timer for b0:67:2f:00:15:65 (sync=1 state=1) Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: SAE: own commit-scalar - hexdump(len=32): d2 38 66 5e 1b 8c 84 17 02 c9 65 43 c8 d2 46 53 94 32 81 a3 9e 3c 05 5c 2f 37 b8 3a f1 09 90 b6 Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: SAE: own commit-element(x) - hexdump(len=32): fb 7f fc ee 71 89 90 fc c2 37 a0 90 6a a5 dd d7 ae 90 05 79 41 e2 65 20 4c be 3e 3b 5c 2e 25 e4 Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: SAE: own commit-element(y) - hexdump(len=32): 02 8e 46 e6 22 17 74 b4 4e f1 1e 00 48 b9 09 f8 74 41 89 e0 84 9b ab 69 c5 b6 05 10 e4 60 ed 7e Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: authentication reply: STA=b0:67:2f:00:15:65 auth_alg=3 auth_transaction=1 resp=0 (IE len=98) Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: nl80211: send_mlme - da= b0:67:2f:00:15:65 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7 Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: nl80211: send_mlme -> send_frame Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: nl80211: send_frame - Use bss->freq=5825 Aug 1 20:30:02 daemon.debug wpa_supplicant[2308]: nl80211: send_frame -> send_frame_cmd Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: nl80211: RX frame da=b0:67:2f:00:1f:04 sa=b0:67:2f:00:15:65 bssid=b0:67:2f:00:15:65 freq=5825 ssi_signal=-75 fc=0xb0 seq_ctrl=0xec50 stype=11 (WLAN_FC_STYPE_AUTH) len=160 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: wlan1: Event RX_MGMT (19) received Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: mgmt::auth Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: authentication: STA=b0:67:2f:00:15:65 auth_alg=3 auth_transaction=1 status_code=0 wep=0 seq_ctrl=0xec50 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: hostapd_logger: STA b0:67:2f:00:15:65 - start SAE authentication (RX commit, status=0) Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Anti-Clogging Token - hexdump(len=32): f2 04 9a ce a3 83 1e 78 1d 66 98 8a ef f4 ac da e5 33 dd 12 b2 46 fe ed a7 0d a8 eb df 23 74 2d Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Peer commit-scalar - hexdump(len=32): 19 f1 3b 41 3c 28 0e e5 61 2a 85 bc aa c1 b3 9c 26 cd 0a ac 5b 1d 96 8b 20 e5 68 e8 a4 8b 4f 84 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Peer commit-element(x) - hexdump(len=32): 20 35 68 b5 3e ff ab 12 31 26 ab 75 ba 5d b8 16 f3 85 4f 0f 63 cb ef ca 57 42 fd 00 6f 47 e4 a0 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Peer commit-element(y) - hexdump(len=32): 6a bc 71 ae 38 b5 7a 7e df 4f b5 43 a4 36 df a1 34 08 2f 4e 93 b3 26 9e 20 28 a8 b3 f2 8b 21 ba Aug 1 20:30:03 daemon.debug wpa_supplicant[2232]: nl80211: Ignored event (cmd=72) for foreign interface (ifindex 17 wdev 0x0) Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: k - hexdump(len=32): [REMOVED] Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: keyseed - hexdump(len=32): [REMOVED] Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: PMKID - hexdump(len=16): ec 29 a1 9f 57 b4 92 fc 63 f3 eb 00 73 93 f9 ef Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: KCK - hexdump(len=32): [REMOVED] Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: PMK - hexdump(len=32): [REMOVED] Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: authentication reply: STA=b0:67:2f:00:15:65 auth_alg=3 auth_transaction=2 resp=0 (IE len=34) Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: nl80211: send_mlme - da= b0:67:2f:00:15:65 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=7 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: nl80211: send_mlme -> send_frame Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: nl80211: send_frame - Use bss->freq=5825 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: nl80211: send_frame -> send_frame_cmd Aug 1 20:30:03 daemon.err wpa_supplicant[2308]: nl80211: Frame TX command accepted; cookie 0x1ac Aug 1 20:30:03 daemon.err wpa_supplicant[2308]: joshua/num_send_action_cookies: 200 Aug 1 20:30:03 daemon.debug wpa_supplicant[2232]: nl80211: Ignored event (cmd=60) for foreign interface (ifindex 17 wdev 0x0) Aug 1 20:30:03 daemon.err wpa_supplicant[2308]: nl80211: Drop oldest pending send action cookie 0xe4 Aug 1 20:30:03 daemon.err wpa_supplicant[2308]: auth_sae_send_confirm: auth_reply: 0 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: nl80211: RX frame da=b0:67:2f:00:1f:04 sa=b0:67:2f:00:15:65 bssid=b0:67:2f:00:1f:04 freq=5825 ssi_signal=-74 fc=0xb0 seq_ctrl=0xec70 stype=11 (WLAN_FC_STYPE_AUTH) len=64 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: wlan1: Event RX_MGMT (19) received Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: mgmt::auth Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: authentication: STA=b0:67:2f:00:15:65 auth_alg=3 auth_transaction=2 status_code=0 wep=0 seq_ctrl=0xec70 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: hostapd_logger: STA b0:67:2f:00:15:65 - SAE authentication (RX confirm, status=0, state=2) Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: peer-send-confirm 0 Aug 1 20:30:03 daemon.debug wpa_supplicant[2232]: nl80211: Ignored event (cmd=72) for foreign interface (ifindex 17 wdev 0x0) Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Confirm mismatch Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Received confirm - hexdump(len=32): a1 07 63 94 bd 68 e7 dc 2f 86 44 94 0b 5d 99 37 c4 72 67 18 56 1f e5 f3 1d 90 be 5e 4e ab c7 61 Aug 1 20:30:03 daemon.debug wpa_supplicant[2308]: SAE: Calculated verifier - hexdump(len=32): 0d 89 83 37 b9 dc e5 d1 ae 5a 03 c2 28 d9 51 d6 7f 83 f5 1b 88 82 26 f3 ca 46 f5 dc 15 b2 db b9 On Thu, Aug 2, 2018 at 10:29 PM, Naveen Mathiyalagan <naveen.m@xxxxxxxxxxx> wrote: > Increase the SAE retry timeout to 1s and try once. > > > Thanks, > Naveen > > > With Warm Regards, > Naveen M > VVDN Technologies Private Limited, Chennai, > Mobile : +91 8883356187 | Skype : nvn.m7 > > On Fri, Aug 3, 2018 at 10:46 AM, Joshua Zhao <swzhao@xxxxxxxxx> wrote: >> >> Yeah, you're right and thanks for the reply! I later realize I made >> wrong conclusion. >> I looked further and saw lots of timeout happened: >> Aug 1 20:30:43 daemon.debug wpa_supplicant[2358]: wlan1: >> ap_handle_timer: a0:76:2f:00:1f:04 flags=0xe00 timeout_next=0 >> Aug 1 20:30:43 daemon.debug wpa_supplicant[2358]: wlan1: Timeout, >> sending disassociation info to STA a0:76:2f:00:1f:04 >> >> We did increase the SAE timeout from 30ms to 200ms but it didn't help. >> Wonder whether this is triggered by a different timeout. Will dig >> further. >> >> Thanks! >> >> >> On Thu, Aug 2, 2018 at 7:00 PM, Bob Copeland <me@xxxxxxxxxxxxxxx> wrote: >> > On Thu, Aug 02, 2018 at 01:22:59PM -0700, Joshua Zhao wrote: >> >> Hi, >> >> I'm running the open source 11s mesh with QCA Dakota radios. But as we >> >> set up more spaces, say > 4 spaces, mesh authentication starts to >> >> become difficult. As I look into the code, it appears to me that the >> >> SAE state machine is not tracking/identifying the peers? So when the >> >> commit & confirm messages between multiple peers interleave each >> >> other, the state machine either sees ECC/FFC mismatch or keeps >> >> resetting the states. >> >> >> >> Is my observation correct? And is this a known issue? >> > >> > The peers are tracked: this is what the sta parameter in sae_sm_step() >> > is >> > for. What hardware is this? Some devices have limits in terms of the >> > number of peers or keys they can handle. >> > >> > -- >> > Bob Copeland %% https://bobcopeland.com/ >> >> _______________________________________________ >> Hostap mailing list >> Hostap@xxxxxxxxxxxxxxxxxxx >> http://lists.infradead.org/mailman/listinfo/hostap > > _______________________________________________ Hostap mailing list Hostap@xxxxxxxxxxxxxxxxxxx http://lists.infradead.org/mailman/listinfo/hostap
