FT-SAE - invalid sequence causing delay/retransmit

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

When using FT-SAE I am seeing this behavior in hostapd, where its
taking too long to process authentication and the kernel retransmits.
This eventually leads to an ANonce mismatch. I am using IWD as the
supplicant. I tried to pull out the relevant info, but the full log is
attached just in case:

- IWD sends out authentication frame for Fast Transition

- Kernel forwards Authentication frame:
    wlan3: send auth to 12:00:00:00:00:02 (try 1/3)

- Hostapd receives authentication frame:
    FT: Received authentication frame: STA=02:00:00:00:03:00
BSSID=12:00:00:00:00:02 transaction=1
    FT: Possibly invalid sequence number in pull request from
12:00:00:00:00:02
    FT: Invalid sequence number in seq response from 12:00:00:00:00:01
    FT: Invalid sequence number in seq response from 12:00:00:00:00:02
    (This seems to take enough time for the kernel to retransmit during
processing)

- Kernel resends Authentication frame:
    wlan3: send auth to 12:00:00:00:00:02 (try 2/3)

- Hostapd receives authentication retry:
    FT: Received authentication frame: STA=02:00:00:00:03:00
BSSID=12:00:00:00:00:02 transaction=1
    (While processing and doing RRB, kernel retransmits again)
    Processing succceeds and hostapd replies:
    authentication reply: STA=02:00:00:00:03:00 auth_alg=2
auth_transaction=2 resp=0 (IE len=145) (dbg=auth-ft-finish)

- Kernel retransmits for the final time
    wlan3: send auth to 12:00:00:00:00:02 (try 3/3)

- IWD has received the authentication frame, and responds with an
associate.

- Hostapd receives the 3/3 authentication retransmition, and processes.
This causes a new ANonce to be generated. The authentication reply
frame sent is never seen in IWD.

- Hostapd receives associate frame, parses out ANonce and detects a
mismatch since it regenerated a new ANonce after the 3/3 retransmit:
    FT: ANonce mismatch in FTIE

I am guessing the invalid sequence number has something to do with the
delay and retransmit? Another thing I have noticed is (after IWD sends
out associate) hostapd sends out its second auth reply, which is never
received by IWD. Could the kernel be throwing this away since
association already started? If this was received IWD could recover,
and resend the associate frame with the correct ANonce.

FT-PSK and FT-8021x both work fine.

Thanks,
James
src/netdev.c:netdev_fast_transition() 
nl80211: send_frame -> send_frame_cmd
nl80211: Ignored event (cmd=60) for foreign interface (ifindex 4 wdev 0x0)
nl80211: Ignored event (cmd=60) for foreign interface (ifindex 4 wdev 0x0)
src/station.c:station_enter_state() Old State: connected, new state: roaming
src/netdev.c:netdev_mlme_notify() MLME notification 60
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wln0
nl80211: Frame TX status event
wln0: Event TX_STATUS (16) received
MLME notification is missing ifindex attribute
[   23.880190] wlan3: disconnect from AP 12:00:00:00:00:01 for new auth to 12:00:00:00:00:02
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 8 wdev 0x0)[   23.885449] wlan3: authenticate with 12:00:00:00:00:02
[   23.886391] wlan3: send auth to 12:00:00:00:00:02 (try 1/3)

nl80211: Ignored event (cmd=20) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 8 wdev 0x0)
src/netdev.c:netdev_mlme_notify() MLME notification 20
src/netdev.c:netdev_mlme_notify() MLME notification 39
src/netdev.c:netdev_deauthenticate_event() 
RTM_NEWLINK: ifi_index=8 ifname=wlan3 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])
nl80211: Ignored event (cmd=39) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=39) for foreign interface (ifindex 8 wdev 0x0)
src/netdev.c:netdev_mlme_notify() MLME notification 48
nl80211: Ignored event (cmd=39) for foreign interface (ifindex 8 wdev 0x0)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wln1
nl80211: RX frame da=12:00:00:00:00:02 sa=02:00:00:00:03:00 bssid=12:00:00:00:00:02 freq=2417 ssi_signal=-25 fc=0xb0 seq_ctrl=0x120 stype=11 (WLAN_FC_STYPE_AUTH) len=167
src/netdev.c:netdev_disconnect_event() 
src/netdev.c:netdev_mlme_notify() MLME notification 19
wln1: Event RX_MGMT (18) received
mgmt::auth
authentication: STA=02:00:00:00:03:00 auth_alg=2 auth_transaction=1 status_code=0 wep=0 seq_ctrl=0x120
  New STA
ap_sta_add: register ap_handle_timer timeout for 02:00:00:00:03:00 (300 seconds - ap_max_inactivity)
nl80211: sta_remove -> DEL_STATION wln1 02:00:00:00:03:00 --> -2 (No such file or directory)
nl80211: Add STA 02:00:00:00:03:00
  * supported rates - hexdump(len=0): [NULL]
  * capability=0x0
  * aid=1 (UNASSOC_STA workaround)
  * listen_interval=0
  * flags set=0x0 mask=0xa0
src/netdev.c:netdev_mlme_notify() MLME notification 19
MLME notification is missing ifindex attribute


HANDLE AUTH

FT: Received authentication frame: STA=02:00:00:00:03:00 BSSID=12:00:00:00:00:02 transaction=1
FT: Received authentication frame IEs - hexdump(len=137): 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28 36 03 12 34 01 37 5a 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: RSNE - hexdump(len=38): 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: MDE - hexdump(len=3): 12 34 01
FT: FTE - hexdump(len=90): 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: FTE-MIC Control - hexdump(len=2): 00 00
FT: FTE-MIC - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
FT: FTE-ANonce - 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
FT: FTE-SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Parse FTE subelements - hexdump(len=8): 03 06 64 75 6d 6d 79 31
FT: STA R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: Requested PMKR0Name - hexdump(len=16): d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: Derived requested PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: No PMK-R1 available in local cache for the requested PMKR1Name
FT: Send PMK-R1 pull request to remote R0KH address 12:00:00:00:00:01
FT: Send out sequence number request to 12:00:00:00:00:01
FT: Pad message to minimum Ethernet frame length (58 --> 64)
FT(RRB): src_addr=12:00:00:00:00:02 type=4
FT(RRB): plaintext message - hexdump(len=0): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=46): 02 00 10 00 36 a5 8d c3 17 10 83 e7 ab ce 3f 45 d6 ec c5 c2 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02 00 00 02 00 00 00
FT(RRB): encrypted TLVs - hexdump(len=16): 39 4c b6 5b 63 f1 c8 88 68 cf af b9 cd 56 4f 28
FT: RRB-OUI type 4 send to 12:00:00:00:00:01 (len=64)
FT(RRB): src_addr=12:00:00:00:00:02 type=1
FT(RRB): plaintext message - hexdump(len=30): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4 01 00 0c 00 4b 29 06 df e8 e8 9a 18 17 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): encrypted TLVs - hexdump(len=46): 41 1b 9a c7 a5 6e 6d 0a f7 a9 63 16 4c 05 6f 10 5f 36 8e 85 82 35 3e 31 5d f6 35 39 0c 8b 24 e2 bd 8e 25 4d 6b e2 f7 21 2f 92 69 0a a0 bb
FT: RRB-OUI type 1 send to 12:00:00:00:00:01 (len=104)
FT: Callback postponed until response is available
FT: RRB received packet 12:00:00:00:00:02 -> 12:00:00:00:00:01
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:02
FT: RRB-OUI frame - oui_suffix=1
FT: Received PMK-R1 pull
FT: R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: R1KH-ID=12:00:00:00:00:02
FT: nonce - hexdump(len=16): af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4
FT: sequence number - hexdump(len=12): 4b 29 06 df e8 e8 9a 18 17 00 00 00
FT: Possibly invalid sequence number in pull request from 12:00:00:00:00:02
FT(RRB): src_addr=12:00:00:00:00:02 type=1
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=46): 41 1b 9a c7 a5 6e 6d 0a f7 a9 63 16 4c 05 6f 10 5f 36 8e 85 82 35 3e 31 5d f6 35 39 0c 8b 24 e2 bd 8e 25 4d 6b e2 f7 21 2f 92 69 0a a0 bb
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4 01 00 0c 00 4b 29 06 df e8 e8 9a 18 17 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): decrypted TLVs - hexdump(len=30): [REMOVED]
FT: Send out sequence number request to 12:00:00:00:00:02
FT: Pad message to minimum Ethernet frame length (58 --> 64)
FT(RRB): src_addr=12:00:00:00:00:01 type=4
FT(RRB): plaintext message - hexdump(len=0): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=46): 02 00 10 00 cd 04 46 e0 25 6e 71 3a 18 e8 c8 b8 94 a0 b8 9c 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02 00 00 02 00 00 00
FT(RRB): encrypted TLVs - hexdump(len=16): 0d c1 db d7 85 6c c4 ca 32 6f 97 bf a6 b0 2e 19
FT: RRB-OUI type 4 send to 12:00:00:00:00:02 (len=64)
FT: RRB received packet 12:00:00:00:00:02 -> 12:00:00:00:00:01
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:02
FT: RRB-OUI frame - oui_suffix=4
FT: Received sequence number request
FT(RRB): src_addr=12:00:00:00:00:02 type=4
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=16): 39 4c b6 5b 63 f1 c8 88 68 cf af b9 cd 56 4f 28
FT(RRB): authenticated TLVs - hexdump(len=46): 02 00 10 00 36 a5 8d c3 17 10 83 e7 ab ce 3f 45 d6 ec c5 c2 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02 00 00 02 00 00 00
FT(RRB): decrypted TLVs - hexdump(len=0): [REMOVED]
FT: seq request - nonce - hexdump(len=16): 36 a5 8d c3 17 10 83 e7 ab ce 3f 45 d6 ec c5 c2
FT(RRB): src_addr=12:00:00:00:00:01 type=5
FT(RRB): plaintext message - hexdump(len=0): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 36 a5 8d c3 17 10 83 e7 ab ce 3f 45 d6 ec c5 c2 01 00 0c 00 7b 44 14 7d 5b 5e a5 03 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): encrypted TLVs - hexdump(len=16): 74 c2 f1 aa 49 40 7b b7 a0 85 5c 15 38 e9 5d 99
FT: RRB-OUI type 5 send to 12:00:00:00:00:02 (len=74)
nl80211: Ignored event (cmd=48) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=48) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=48) for foreign interface (ifindex 8 wdev 0x0)
FT: RRB received packet 12:00:00:00:00:01 -> 12:00:00:00:00:02
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:01
FT: RRB-OUI frame - oui_suffix=5
FT: Received sequence number response
FT(RRB): src_addr=12:00:00:00:00:01 type=5
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=16): 74 c2 f1 aa 49 40 7b b7 a0 85 5c 15 38 e9 5d 99
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 36 a5 8d c3 17 10 83 e7 ab ce 3f 45 d6 ec c5 c2 01 00 0c 00 7b 44 14 7d 5b 5e a5 03 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): decrypted TLVs - hexdump(len=0): [REMOVED]
FT: seq response - nonce - hexdump(len=16): 36 a5 8d c3 17 10 83 e7 ab ce 3f 45 d6 ec c5 c2
FT: sequence number - hexdump(len=12): 7b 44 14 7d 5b 5e a5 03 18 00 00 00
FT: Invalid sequence number in seq response from 12:00:00:00:00:01
FT: seq response - reset seq number
FT: RRB received packet 12:00:00:00:00:01 -> 12:00:00:00:00:02
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:01
FT: RRB-OUI frame - oui_suffix=4
FT: Received sequence number request
FT(RRB): src_addr=12:00:00:00:00:01 type=4
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED][   24.088552] wlan3: send auth to 12:00:00:00:00:02 (try 2/3)

FT(RRB): encrypted TLVs - hexdump(len=16): 0d c1 db d7 85 6c c4 ca 32 6f 97 bf a6 b0 2e 19
FT(RRB): authenticated TLVs - hexdump(len=46): 02 00 10 00 cd 04 46 e0 25 6e 71 3a 18 e8 c8 b8 94 a0 b8 9c 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02 00 00 02 00 00 00
FT(RRB): decrypted TLVs - hexdump(len=0): [REMOVED]
FT: seq request - nonce - hexdump(len=16): cd 04 46 e0 25 6e 71 3a 18 e8 c8 b8 94 a0 b8 9c
FT(RRB): src_addr=12:00:00:00:00:02 type=5
FT(RRB): plaintext message - hexdump(len=0): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 cd 04 46 e0 25 6e 71 3a 18 e8 c8 b8 94 a0 b8 9c 01 00 0c 00 4b 29 06 df e9 e8 9a 18 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): encrypted TLVs - hexdump(len=16): 36 bf 59 bc 09 41 95 cf 89 65 9a e1 b2 99 e8 f9
FT: RRB-OUI type 5 send to 12:00:00:00:00:01 (len=74)
nl80211: Ignored event (cmd=19) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=19) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=19) for foreign interface (ifindex 8 wdev 0x0)
FT: RRB received packet 12:00:00:00:00:02 -> 12:00:00:00:00:01
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:02
FT: RRB-OUI frame - oui_suffix=5
FT: Received sequence number response
FT(RRB): src_addr=12:00:00:00:00:02 type=5
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=16): 36 bf 59 bc 09 41 95 cf 89 65 9a e1 b2 99 e8 f9
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 cd 04 46 e0 25 6e 71 3a 18 e8 c8 b8 94 a0 b8 9c 01 00 0c 00 4b 29 06 df e9 e8 9a 18 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): decrypted TLVs - hexdump(len=0): [REMOVED]
FT: seq response - nonce - hexdump(len=16): cd 04 46 e0 25 6e 71 3a 18 e8 c8 b8 94 a0 b8 9c
FT: sequence number - hexdump(len=12): 4b 29 06 df e9 e8 9a 18 18 00 00 00
FT: Invalid sequence number in seq response from 12:00:00:00:00:02
FT: seq response - reset seq number
FT: Received PMK-R1 pull
FT: R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: R1KH-ID=12:00:00:00:00:02
FT: nonce - hexdump(len=16): af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4
FT: sequence number - hexdump(len=12): 4b 29 06 df e8 e8 9a 18 17 00 00 00
FT(RRB): src_addr=12:00:00:00:00:02 type=1
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=46): 41 1b 9a c7 a5 6e 6d 0a f7 a9 63 16 4c 05 6f 10 5f 36 8e 85 82 35 3e 31 5d f6 35 39 0c 8b 24 e2 bd 8e 25 4d 6b e2 f7 21 2f 92 69 0a a0 bb
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4 01 00 0c 00 4b 29 06 df e8 e8 9a 18 17 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): decrypted TLVs - hexdump(len=30): [REMOVED]
FT: PMKR0Name - hexdump(len=16): d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: S1KH-ID=02:00:00:00:03:00
FT: Derive PMK-R1 using KDF-SHA256
FT: PMK-R0 - hexdump(len=32): [REMOVED]
FT: R1KH-ID - hexdump(len=6): 12 00 00 00 00 02
FT: S1KH-ID: 02:00:00:00:03:00
FT: PMK-R1 - hexdump(len=32): [REMOVED]
FT: PMK-R1 (for peer AP) - hexdump(len=32): [REMOVED]
FT: PMKR1Name (for peer AP) - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT(RRB): src_addr=12:00:00:00:00:01 type=2
FT(RRB): plaintext message - hexdump(len=94): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4 01 00 0c 00 7b 44 14 7d 5c 5e a5 03 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): encrypted TLVs - hexdump(len=110): e8 20 55 5e a1 49 b8 67 ad 01 29 14 6e 32 13 ce f0 65 21 9c 33 4a 99 85 f9 ec 22 19 67 a6 a3 f2 6e 2b f6 22 98 97 f6 5f 1a 12 6e eb 57 95 94 b4 93 42 54 39 17 cc 31 c4 99 12 14 48 85 23 9b 96 a7 a3 d9 a1 40 4c 82 56 3a 61 4f b2 cd 55 f8 1a bb be 94 38 38 49 ea d7 60 51 4d 8f 4d f0 1c 09 e4 66 ec c0 48 39 e1 b0 7e 0f e8 78 21 9a
FT: RRB-OUI type 2 send to 12:00:00:00:00:02 (len=168)
nl80211: Ignored event (cmd=19) for foreign interface (ifindex 5 wdev 0x0)
nl80211: Drv Event 19 (NL80211_CMD_NEW_STATION) received for wln1
nl80211: New station 02:00:00:00:03:00
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wln1
nl80211: RX frame da=12:00:00:00:00:02 sa=02:00:00:00:03:00 bssid=12:00:00:00:00:02 freq=2417 ssi_signal=-25 fc=0xb0 seq_ctrl=0x130 stype=11 (WLAN_FC_STYPE_AUTH) len=167
wln1: Event RX_MGMT (18) received
mgmt::auth
authentication: STA=02:00:00:00:03:00 auth_alg=2 auth_transaction=1 status_code=0 wep=0 seq_ctrl=0x130


HANDLE AUTH

FT: Received authentication frame: STA=02:00:00:00:03:00 BSSID=12:00:00:00:00:02 transaction=1
FT: Received authentication frame IEs - hexdump(len=137): 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28 36 03 12 34 01 37 5a 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: RSNE - hexdump(len=38): 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: MDE - hexdump(len=3): 12 34 01
FT: FTE - hexdump(len=90): 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: FTE-MIC Control - hexdump(len=2): 00 00
FT: FTE-MIC - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
FT: FTE-ANonce - 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
FT: FTE-SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Parse FTE subelements - hexdump(len=8): 03 06 64 75 6d 6d 79 31
FT: STA R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: Requested PMKR0Name - hexdump(len=16): d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: Derived requested PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: No PMK-R1 available in local cache for the requested PMKR1Name
FT: Send PMK-R1 pull request to remote R0KH address 12:00:00:00:00:01
FT(RRB): src_addr=12:00:00:00:00:02 type=1
FT(RRB): plaintext message - hexdump(len=30): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 31 36 0c 69 2d b8 f7 1d 54 ba 62 45 6f f6 88 50 01 00 0c 00 4b 29 06 df ea e8 9a 18 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): encrypted TLVs - hexdump(len=46): 45 80 d5 13 80 7d c1 96 c4 26 1a 19 d1 97 db 4a 34 13 46 ce 9e d5 79 44 d2 56 19 71 c6 99 33 b4 8d 9f 0d e2 76 66 92 73 a3 b0 c1 d6 58 0a
FT: RRB-OUI type 1 send to 12:00:00:00:00:01 (len=104)
FT: Callback postponed until response is available
FT: RRB received packet 12:00:00:00:00:01 -> 12:00:00:00:00:02
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:01
FT: RRB-OUI frame - oui_suffix=2
FT: Received PMK-R1 pull response
FT: nonce - hexdump(len=16): af da 5c f3 b3 44 28 9f 83 88 93 67 17 99 01 a4
FT: Invalid nonce
FT: RRB received packet 12:00:00:00:00:02 -> 12:00:00:00:00:01
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:02
FT: RRB-OUI frame - oui_suffix=1
FT: Received PMK-R1 pull
FT: R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: R1KH-ID=12:00:00:00:00:02
FT: nonce - hexdump(len=16): 31 36 0c 69 2d b8 f7 1d 54 ba 62 45 6f f6 88 50
FT: sequence number - hexdump(len=12): 4b 29 06 df ea e8 9a 18 18 00 00 00
FT(RRB): src_addr=12:00:00:00:00:02 type=1
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=46): 45 80 d5 13 80 7d c1 96 c4 26 1a 19 d1 97 db 4a 34 13 46 ce 9e d5 79 44 d2 56 19 71 c6 99 33 b4 8d 9f 0d e2 76 66 92 73 a3 b0 c1 d6 58 0a
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 31 36 0c 69 2d b8 f7 1d 54 ba 62 45 6f f6 88 50 01 00 0c 00 4b 29 06 df ea e8 9a 18 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): decrypted TLVs - hexdump(len=30): [REMOVED]
FT: PMKR0Name - hexdump(len=16): d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28[   24.296990] wlan3: send auth to 12:00:00:00:00:02 (try 3/3)

FT: S1KH-ID=02:00:00:00:03:00
FT: Derive PMK-R1 using KDF-SHA256
FT: PMK-R0 - hexdump(len=32): [REMOVED]
FT: R1KH-ID - hexdump(len=6): 12 00 00 00 00 02
FT: S1KH-ID: 02:00:00:00:03:00
FT: PMK-R1 - hexdump(len=32): [REMOVED]
FT: PMK-R1 (for peer AP) - hexdump(len=32): [REMOVED]
FT: PMKR1Name (for peer AP) - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT(RRB): src_addr=12:00:00:00:00:01 type=2
FT(RRB): plaintext message - hexdump(len=94): [REMOVED]
FT(RRB): encrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 31 36 0c 69 2d b8 f7 1d 54 ba 62 45 6f f6 88 50 01 00 0c 00 7b 44 14 7d 5d 5e a5 03 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): encrypted TLVs - hexdump(len=110): ae 90 66 11 f3 5c 8f 01 7a 2d 24 21 10 55 99 6c 64 58 cd 4f e2 2d 5a f8 6d 6c 43 3e e9 a4 75 f5 7b 0e d1 79 df bb 8d 40 54 12 2a ee c3 bb 32 02 20 3c d7 47 00 f0 83 a3 83 a4 fa 00 e5 ff 7c 7d c1 a1 58 c9 2c b1 e7 06 36 22 7c 1e bb c5 16 a8 47 be 31 8c 0d f6 d8 9c b5 c8 d5 27 6d c3 2f 09 51 23 cb 89 64 95 5a 12 bf db 86 58 0c 32
FT: RRB-OUI type 2 send to 12:00:00:00:00:02 (len=168)
FT: RRB received packet 12:00:00:00:00:01 -> 12:00:00:00:00:02
FT: RRB-OUI received frame from remote AP 12:00:00:00:00:01
FT: RRB-OUI frame - oui_suffix=2
FT: Received PMK-R1 pull response
FT: nonce - hexdump(len=16): 31 36 0c 69 2d b8 f7 1d 54 ba 62 45 6f f6 88 50
FT: R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: R1KH-ID=12:00:00:00:00:02
FT: sequence number - hexdump(len=12): 7b 44 14 7d 5d 5e a5 03 18 00 00 00
FT(RRB): src_addr=12:00:00:00:00:01 type=2
FT(RRB): decrypt using key - hexdump(len=32): [REMOVED]
FT(RRB): encrypted TLVs - hexdump(len=110): ae 90 66 11 f3 5c 8f 01 7a 2d 24 21 10 55 99 6c 64 58 cd 4f e2 2d 5a f8 6d 6c 43 3e e9 a4 75 f5 7b 0e d1 79 df bb 8d 40 54 12 2a ee c3 bb 32 02 20 3c d7 47 00 f0 83 a3 83 a4 fa 00 e5 ff 7c 7d c1 a1 58 c9 2c b1 e7 06 36 22 7c 1e bb c5 16 a8 47 be 31 8c 0d f6 d8 9c b5 c8 d5 27 6d c3 2f 09 51 23 cb 89 64 95 5a 12 bf db 86 58 0c 32
FT(RRB): authenticated TLVs - hexdump(len=56): 02 00 10 00 31 36 0c 69 2d b8 f7 1d 54 ba 62 45 6f f6 88 50 01 00 0c 00 7b 44 14 7d 5d 5e a5 03 18 00 00 00 04 00 06 00 64 75 6d 6d 79 31 05 00 06 00 12 00 00 00 00 02
FT(RRB): decrypted TLVs - hexdump(len=94): [REMOVED]
FT: S1KH-ID=02:00:00:00:03:00
FT: pairwise - hexdump(len=2): 10 00
FT: PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: PMK-R1 - hexdump(len=32): [REMOVED]
FT: PMK-R1 pull response - expires_in=29945
FT: vlan 0
FT: Identity - hexdump_ascii(len=0):
FT: CUI - hexdump_ascii(len=0):
FT: session_timeout 0
FT: Response to a pending pull request for 02:00:00:00:03:00
FT: Received authentication frame IEs - hexdump(len=137): 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28 36 03 12 34 01 37 5a 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: RSNE - hexdump(len=38): 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: MDE - hexdump(len=3): 12 34 01
FT: FTE - hexdump(len=90): 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: FTE-MIC Control - hexdump(len=2): 00 00
FT: FTE-MIC - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
FT: FTE-ANonce - 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
FT: FTE-SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Parse FTE subelements - hexdump(len=8): 03 06 64 75 6d 6d 79 31
FT: STA R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: Requested PMKR0Name - hexdump(len=16): d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: Derived requested PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: Found PMKR1Name from local cache
FT: Selected PMK-R1 - hexdump(len=32): [REMOVED]
FT: Received SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Generated ANonce - hexdump(len=32): 4b 2d 80 66 d6 f5 8e 40 a4 f9 7e 90 c2 3d 42 d0 5d 7d 5c b7 72 0e 2d 56 aa 09 bb 3f 2b 32 fd 29
FT: Derive PTK using KDF-SHA256
FT: PMK-R1 - hexdump(len=32): [REMOVED]
FT: SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: ANonce - hexdump(len=32): 4b 2d 80 66 d6 f5 8e 40 a4 f9 7e 90 c2 3d 42 d0 5d 7d 5c b7 72 0e 2d 56 aa 09 bb 3f 2b 32 fd 29
FT: BSSID=12:00:00:00:00:02 STA-ADDR=02:00:00:00:03:00
FT: PTK - hexdump(len=48): [REMOVED]
FT: PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: KCK - hexdump(len=16): [REMOVED]
FT: KEK - hexdump(len=16): [REMOVED]
FT: TK - hexdump(len=16): [REMOVED]
FT: PTKName - hexdump(len=16): 7f 5b 00 4d 85 25 5d 1d 69 d3 d2 4d 77 05 10 7c
wpa_driver_nl80211_set_key: ifindex=5 (wln1) alg=3 addr=0x562a84119800 key_idx=0 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   addr=02:00:00:00:03:00
nl80211: set_key failed; err=-2 No such file or directory)
FT: Postponed auth callback result for 02:00:00:00:03:00 - status 0
authentication reply: STA=02:00:00:00:03:00 auth_alg=2 auth_transaction=2 resp=0 (IE len=145) (dbg=auth-ft-finish)
nl80211: send_mlme - da= 02:00:00:00:03:00 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2417
nl80211: send_frame -> send_frame_cmd
[   24.421362] wlan3: authenticated
src/netdev.c:netdev_mlme_notify() MLME notification 60
MLME notification is missing ifindex attribute
src/netdev.c:netdev_mlme_notify() MLME notification 37
src/netdev.c:netdev_authenticate_event() 
wln1: STA 02:00:00:00:03:00 IEEE 802.11: authentication OK (FT)
wln1: STA 02:00:00:00:03:00 MLME: MLME-AUTHENTICATE.indication(02:00:00:00:03:00, FT)
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wln1
nl80211: RX frame da=12:00:00:00:00:02 sa=02:00:00:00:03:00 bssid=12:00:00:00:00:02 freq=2417 ssi_signal=-25 fc=0xb0 seq_ctrl=0x140 stype=11 (WLAN_FC_STYPE_AUTH) len=167
wln1: Event RX_MGMT (18) received
mgmt::auth
authentication: STA=02:00:00:00:03:00 auth_alg=2 auth_transaction=1 status_code=0 wep=0 seq_ctrl=0x140[   24.450926] mac80211_hwsim hwsim3 wlan3: disabling HT as WMM/QoS is not supported by the AP
[   24.452447] mac80211_hwsim hwsim3 wlan3: disabling VHT as WMM/QoS is not supported by the AP

[   24.454147] wlan3: associate with 12:00:00:00:00:02 (try 1/3)


HANDLE AUTH

FT: Received authentication frame: STA=02:00:00:00:03:00 BSSID=12:00:00:00:00:02 transaction=1
FT: Received authentication frame IEs - hexdump(len=137): 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28 36 03 12 34 01 37 5a 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: RSNE - hexdump(len=38): 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: MDE - hexdump(len=3): 12 34 01
FT: FTE - hexdump(len=90): 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 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 03 06 64 75 6d 6d 79 31
FT: FTE-MIC Control - hexdump(len=2): 00 00
FT: FTE-MIC - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
FT: FTE-ANonce - 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
FT: FTE-SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Parse FTE subelements - hexdump(len=8): 03 06 64 75 6d 6d 79 31
FT: STA R0KH-ID - hexdump(len=6): 64 75 6d 6d 79 31
FT: Requested PMKR0Name - hexdump(len=16): d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28
FT: Derived requested PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: Found PMKR1Name from local cache
FT: Selected PMK-R1 - hexdump(len=32): [REMOVED]
FT: Received SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Generated ANonce - hexdump(len=32): 24 b8 ac cc d4 14 3d cb 99 a4 93 bd 32 f7 18 03 55 63 5a a4 ac eb d4 fd 71 f4 25 ed e3 f0 35 43
FT: Derive PTK using KDF-SHA256
FT: PMK-R1 - hexdump(len=32): [REMOVED]
FT: SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: ANonce - hexdump(len=32): 24 b8 ac cc d4 14 3d cb 99 a4 93 bd 32 f7 18 03 55 63 5a a4 ac eb d4 fd 71 f4 25 ed e3 f0 35 43
FT: BSSID=12:00:00:00:00:02 STA-ADDR=02:00:00:00:03:00
FT: PTK - hexdump(len=48): [REMOVED]
FT: PMKR1Name - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: KCK - hexdump(len=16): [REMOVED]
FT: KEK - hexdump(len=16): [REMOVED]
FT: TK - hexdump(len=16): [REMOVED]
FT: PTKName - hexdump(len=16): 7f de fd af 34 5e b6 e8 77 7c b3 aa c3 87 7c 7b
wpa_driver_nl80211_set_key: ifindex=5 (wln1) alg=3 addr=0x562a84119800 key_idx=0 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   addr=02:00:00:00:03:00
nl80211: set_key failed; err=-2 No such file or directory)
FT: FT authentication response: dst=02:00:00:00:03:00 auth_transaction=2 status=0 (SUCCESS)
FT: Response IEs - hexdump(len=145): 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 c1 00 01 00 d5 45 95 37 20 7e c9 84 d5 91 e1 a6 7a 9d c7 28 36 03 12 34 01 37 62 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 24 b8 ac cc d4 14 3d cb 99 a4 93 bd 32 f7 18 03 55 63 5a a4 ac eb d4 fd 71 f4 25 ed e3 f0 35 43 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 01 06 12 00 00 00 00 02 03 06 64 75 6d 6d 79 31
authentication reply: STA=02:00:00:00:03:00 auth_alg=2 auth_transaction=2 resp=0 (IE len=145) (dbg=auth-ft-finish)
nl80211: send_mlme - da= 02:00:00:00:03:00 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xb0 (WLAN_FC_STYPE_AUTH) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2417
nl80211: send_frame -> send_frame_cmd
src/netdev.c:netdev_mlme_notify() MLME notification 60
MLME notification is missing ifindex attribute
wln1: STA 02:00:00:00:03:00 IEEE 802.11: authentication OK (FT)
wln1: STA 02:00:00:00:03:00 MLME: MLME-AUTHENTICATE.indication(02:00:00:00:03:00, FT)
nl80211: Ignored event (cmd=60) for foreign interface (ifindex 5 wdev 0x0)
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wln1
nl80211: Frame TX status event
wln1: Event TX_STATUS (16) received
mgmt::auth cb
nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wln1
nl80211: RX frame da=12:00:00:00:00:02 sa=02:00:00:00:03:00 bssid=12:00:00:00:00:02 freq=2417 ssi_signal=-25 fc=0x20 seq_ctrl=0x150 stype=2 (WLAN_FC_STYPE_REASSOC_REQ) len=203
wln1: Event RX_MGMT (18) received
mgmt::reassoc_req
reassociation request: STA=02:00:00:00:03:00 capab_info=0x431 listen_interval=5 current_ap=12:00:00:00:00:01 seq_ctrl=0x150
RSN IE: STA PMKID - hexdump(len=16): bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
RSN: Derive PMKID using HMAC-SHA-256
RSN: Derived PMKID - hexdump(len=16): e7 bf b5 76 d5 4e 94 11 dc bf 04 e7 a0 4f b3 3f
FT: Reassoc Req IEs - hexdump(len=169): 00 06 54 65 73 74 46 54 01 08 02 04 0b 16 0c 12 18 24 32 04 30 48 60 6c 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48 36 03 12 34 01 37 62 00 03 96 7b d6 aa 63 dd 05 e4 7e 8a 41 84 71 f8 89 f7 4b 2d 80 66 d6 f5 8e 40 a4 f9 7e 90 c2 3d 42 d0 5d 7d 5c b7 72 0e 2d 56 aa 09 bb 3f 2b 32 fd 29 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 01 06 12 00 00 00 00 02 03 06 64 75 6d 6d 79 31
FT: RSNE - hexdump(len=38): 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 80 00 01 00 bf 28 4d 7c d5 ec f5 aa c8 43 09 ef 3a ef 25 48
FT: MDE - hexdump(len=3): 12 34 01
FT: FTE - hexdump(len=98): 00 03 96 7b d6 aa 63 dd 05 e4 7e 8a 41 84 71 f8 89 f7 4b 2d 80 66 d6 f5 8e 40 a4 f9 7e 90 c2 3d 42 d0 5d 7d 5c b7 72 0e 2d 56 aa 09 bb 3f 2b 32 fd 29 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5 01 06 12 00 00 00 00 02 03 06 64 75 6d 6d 79 31
FT: FTE-MIC Control - hexdump(len=2): 00 03
FT: FTE-MIC - hexdump(len=16): 96 7b d6 aa 63 dd 05 e4 7e 8a 41 84 71 f8 89 f7
FT: FTE-ANonce - hexdump(len=32): 4b 2d 80 66 d6 f5 8e 40 a4 f9 7e 90 c2 3d 42 d0 5d 7d 5c b7 72 0e 2d 56 aa 09 bb 3f 2b 32 fd 29
FT: FTE-SNonce - hexdump(len=32): 3f 73 52 3c 4d 37 e8 01 e4 85 14 c6 09 94 6a 63 38 af 1c 89 69 44 cb 90 10 ab b5 c1 09 f1 9b f5
FT: Parse FTE subelements - hexdump(len=16): 01 06 12 00 00 00 00 02 03 06 64 75 6d 6d 79 31
FT: ANonce mismatch in FTIE
FT: Received ANonce - hexdump(len=32): 4b 2d 80 66 d6 f5 8e 40 a4 f9 7e 90 c2 3d 42 d0 5d 7d 5c b7 72 0e 2d 56 aa 09 bb 3f 2b 32 fd 29
FT: Expected ANonce - hexdump(len=32): 24 b8 ac cc d4 14 3d cb 99 a4 93 bd 32 f7 18 03 55 63 5a a4 ac eb d4 fd 71 f4 25 ed e3 f0 35 43
nl80211: send_mlme - da= 02:00:00:00:03:00 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0x30 (WLAN_FC_STYPE_REASSOC_RESP) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2417
nl80211: send_frame -> send_frame_cmd
[   24.604061] wlan3: RX ReassocResp from 12:00:00:00:00:02 (capab=0x1411 status=55 aid=0)
[   24.605467] wlan3: 12:00:00:00:00:02 denied association (code=55)
src/netdev.c:netdev_mlme_notify() MLME notification 60
MLME notification is missing ifindex attribute
src/netdev.c:netdev_mlme_notify() MLME notification 20
nl80211: sta_remove -> DEL_STATION wln1 02:00:00:00:03:00 --> 0 (Success)
src/netdev.c:netdev_mlme_notify() MLME notification 38
src/netdev.c:netdev_associate_event() 
nl80211: Ignored event (cmd=37) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=37) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=37) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=60) for foreign interface (ifindex 5 wdev 0x0)
src/netdev.c:netdev_mlme_notify() MLME notification 46
src/netdev.c:netdev_connect_event() 
src/netdev.c:netdev_mlme_notify() MLME notification 20
MLME notification is missing ifindex attribute
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wln1
nl80211: Frame TX status event
wln1: Event TX_STATUS (16) received
mgmt::auth cb
nl80211: Ignored event (cmd=60) for foreign interface (ifindex 5 wdev 0x0)
nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wln1
nl80211: Frame TX status event
wln1: Event TX_STATUS (16) received
mgmt::reassoc_resp cb
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=38) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=38) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=38) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=46) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=46) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=46) for foreign interface (ifindex 8 wdev 0x0)
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 5 wdev 0x0)
nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for wln1
nl80211: Delete station 02:00:00:00:03:00
src/netdev.c:netdev_mlme_notify() MLME notification 20
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 4 wdev 0x0)
nl80211: Ignored event (cmd=20) for foreign interface (ifindex 4 wdev 0x0)
nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for wln0
[   29.032442] ifconfig (1232) used greatest stack depth: 13320 bytes left
MLME notification is missing ifindex attribute
nl80211: Delete station 02:00:00:00:03:00
src/netdev.c:netdev_mlme_notify() MLME notification 16
MLME notification is missing ifindex attribute
RTM_NEWLINK: ifi_index=4 ifname=wln0 operstate=2 linkmode=0 ifi_family=0 ifi_flags=0x1002 ()
nl80211: Interface down (wln0/wln0)
wln0: Event INTERFACE_DISABLED (26) received
wln0: STA 02:00:00:00:03:00 MLME: MLME-DEAUTHENTICATE.indication(02:00:00:00:03:00, 1)
wln0: STA 02:00:00:00:03:00 MLME: MLME-DELETEKEYS.request(02:00:00:00:03:00)
wpa_driver_nl80211_set_key: ifindex=4 (wln0) alg=0 addr=0x562a8410a5e0 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=02:00:00:00:03:00
nl80211: set_key failed; err=-100 Network is down)
RSN: PTK removal from the driver failed
Removing station 02:00:00:00:03:00
wln0: AP-STA-DISCONNECTED 02:00:00:00:03:00
nl80211: sta_remove -> DEL_STATION wln0 02:00:00:00:03:00 --> -100 (Network is down)
ap_free_sta: cancel ap_handle_timer for 02:00:00:00:03:00
wln0: INTERFACE-DISABLED 
nl80211: Ignored event (cmd=16) for foreign interface (ifindex 4 wdev 0x0)
nl80211: Ignored event (cmd=16) for foreign interface (ifindex 4 wdev 0x0)
nl80211: Drv Event 16 (NL80211_CMD_STOP_AP) received for wln0
wln0: Event INTERFACE_UNAVAILABLE (28) received
Interface wln0 is unavailable -- stopped
l2_packet_receive - recvfrom: Network is down
l2_packet_receive - recvfrom: Network is down
src/netdev.c:netdev_mlme_notify() MLME notification 16
MLME notification is missing ifindex attribute
nl80211: Ignored event (cmd=16) for foreign interface (ifindex 5 wdev 0x0)
nl80211: Drv Event 16 (NL80211_CMD_STOP_AP) received for wln1
wln1: Event INTERFACE_UNAVAILABLE (28) received
Interface wln1 is unavailable -- stopped
RTM_NEWLINK: ifi_index=5 ifname=wln1 operstate=2 linkmode=0 ifi_family=0 ifi_flags=0x1002 ()
nl80211: Interface down (wln1/wln1)
wln1: Event INTERFACE_DISABLED (26) received
wln1: STA 02:00:00:00:03:00 MLME: MLME-DEAUTHENTICATE.indication(02:00:00:00:03:00, 1)
wln1: STA 02:00:00:00:03:00 MLME: MLME-DELETEKEYS.request(02:00:00:00:03:00)
wpa_driver_nl80211_set_key: ifindex=5 (wln1) alg=0 addr=0x562a84119800 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=02:00:00:00:03:00
nl80211: set_key failed; err=-100 Network is down)
RSN: PTK removal from the driver failed
Removing station 02:00:00:00:03:00
nl80211: sta_remove -> DEL_STATION wln1 02:00:00:00:03:00 --> -100 (Network is down)
ap_free_sta: cancel ap_handle_timer for 02:00:00:00:03:00
wln1: INTERFACE-DISABLED 
l2_packet_receive - recvfrom: Network is down
l2_packet_receive - recvfrom: Network is down
src/netdev.c:netdev_mlme_notify() MLME notification 16
MLME notification is missing ifindex attribute
nl80211: Drv Event 16 (NL80211_CMD_STOP_AP) received for wln2
src/wiphy.c:wiphy_regulatory_notify() Regulatory notification 36
wln2: Event INTERFACE_UNAVAILABLE (28) received
Interface wln2 is unavailable -- stopped
RTM_NEWLINK: ifi_index=6 ifname=wln2 operstate=2 linkmode=0 ifi_family=0 ifi_flags=0x1002 ()
nl80211: Interface down (wln2/wln2)
wln2: Event INTERFACE_DISABLED (26) received
wln2: INTERFACE-DISABLED 
nl80211: Ignored event (cmd=36) for foreign interface (ifindex -1 wdev 0x0)
nl80211: Ignored event (cmd=36) for foreign interface (ifindex -1 wdev 0x0)
nl80211: Drv Event 36 (NL80211_CMD_REG_CHANGE) received for wln0
nl80211: Regulatory domain change
 * initiator=0
 * type=1
wln0: Event CHANNEL_LIST_CHANGED (27) received
l2_packet_receive - recvfrom: Network is down
l2_packet_receive - recvfrom: Network is down
RTM_NEWLINK: ifi_index=4 ifname=wln0 operstate=2 linkmode=0 ifi_family=0 ifi_flags=0x1003 ([UP])
nl80211: Interface up (wln0/wln0)
wln0: Event INTERFACE_ENABLED (25) received
wln0: INTERFACE-ENABLED 
wpa_driver_nl80211_set_key: ifindex=4 (wln0) alg=3 addr=0x562a82f37cc0 key_idx=1 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
wpa_driver_nl80211_set_key: ifindex=4 (wln0) alg=4 addr=0x562a82f37cc0 key_idx=4 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
nl80211: Set beacon (beacon_set=0)
nl80211: Beacon head - hexdump(len=57): 80 00 00 00 ff ff ff ff ff ff 12 00 00 00 00 01 12 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 64 00 11 14 00 06 54 65 73 74 46 54 01 08 82 84 8b 96 0c 12 18 24 03 01 01
nl80211: Beacon tail - hexdump(len=57): 2a 01 04 32 04 30 48 60 6c 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 c1 00 36 03 12 34 01 46 05 02 00 00 00 00 3b 02 51 00 7f 08 04 00 40 02 00 00 01 40
nl80211: ifindex=4
nl80211: beacon_int=100
nl80211: beacon_rate=0
nl80211: rate_type=0
nl80211: dtim_period=2
nl80211: ssid=TestFT
  * beacon_int=100
  * dtim_period=2
nl80211: hidden SSID not in use
nl80211: privacy=1
nl80211: auth_algs=0x3
nl80211: wpa_version=0x2
nl80211: key_mgmt_suites=0x800
nl80211: pairwise_ciphers=0x10
nl80211: group_cipher=0x10
nl80211: beacon_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
nl80211: proberesp_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
nl80211: assocresp_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
[   29.225380] IPv6: ADDRCONF(NETDEV_CHANGE): wln0: link becomes ready
nl80211: multicast to unicast disabled on interface wln0
RTM_NEWLINK: ifi_index=4 ifname=wln0 operstate=6 linkmode=0 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK: ifi_index=5 ifname=wln1 operstate=6 linkmode=0 ifi_family=0 ifi_flags=0x1043 ([UP][RUNNING])
nl80211: Interface up (wln1/wln1)
wln1: Event INTERFACE_ENABLED (25) received
wln1: INTERFACE-ENABLED 
wpa_driver_nl80211_set_key: ifindex=5 (wln1) alg=3 addr=0x562a82f37cc0 key_idx=1 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
wpa_driver_nl80211_set_key: ifindex=5 (wln1) alg=4 addr=0x562a82f37cc0 key_idx=4 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
nl80211: Set beacon (beacon_set=0)
nl80211: Beacon head - hexdump(len=57): 80 00 00 00 ff ff ff ff ff ff 12 00 00 00 00 02 12 00 00 00 00 02 00 00 00 00 00 00 00 00 00 00 64 00 11 14 00 06 54 65 73 74 46 54 01 08 82 84 8b 96 0c 12 18 24 03 01 02
nl80211: Beacon tail - hexdump(len=57): 2a 01 04 32 04 30 48 60 6c 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 09 c1 00 36 03 12 34 01 46 05 02 00 00 00 00 3b 02 51 00 7f 08 04 00 40 02 00 00 01 40
nl80211: ifindex=5
nl80211: beacon_int=100
nl80211: beacon_rate=0
nl80211: rate_type=0
nl80211: dtim_period=2
nl80211: ssid=TestFT
  * beacon_int=100
  * dtim_period=2
nl80211: hidden SSID not in use
nl80211: privacy=1
nl80211: auth_algs=0x3
nl80211: wpa_version=0x2
nl80211: key_mgmt_suites=0x800
nl80211: pairwise_ciphers=0x10
nl80211: group_cipher=0x10
nl80211: beacon_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
nl80211: proberesp_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
nl80211: assocresp_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
[   29.283250] IPv6: ADDRCONF(NETDEV_CHANGE): wln1: link becomes ready
nl80211: multicast to unicast disabled on interface wln1
RTM_NEWLINK: ifi_index=5 ifname=wln1 operstate=6 linkmode=0 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK: ifi_index=6 ifname=wln2 operstate=6 linkmode=0 ifi_family=0 ifi_flags=0x1043 ([UP][RUNNING])
nl80211: Interface up (wln2/wln2)
wln2: Event INTERFACE_ENABLED (25) received
wln2: INTERFACE-ENABLED 
wpa_driver_nl80211_set_key: ifindex=6 (wln2) alg=3 addr=0x562a82f37cc0 key_idx=1 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
wpa_driver_nl80211_set_key: ifindex=6 (wln2) alg=4 addr=0x562a82f37cc0 key_idx=4 set_tx=1 seq_len=0 key_len=16
nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
   broadcast key
nl80211: Set beacon (beacon_set=0)
nl80211: Beacon head - hexdump(len=57): 80 00 00 00 ff ff ff ff ff ff 12 00 00 00 00 03 12 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 64 00 11 14 00 06 54 65 73 74 46 54 01 08 82 84 8b 96 0c 12 18 24 03 01 01
nl80211: Beacon tail - hexdump(len=57): 2a 01 04 32 04 30 48 60 6c 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 04 c1 00 36 03 12 34 01 46 05 02 00 00 00 00 3b 02 51 00 7f 08 04 00 40 02 00 00 01 40
src/station.c:station_dbus_disconnect() 
nl80211: ifindex=6
nl80211: beacon_int=100
nl80211: beacon_rate=0
src/station.c:station_fast_transition_cb() 8, result: 5
src/station.c:station_roam_failed() 8
src/station.c:station_disassociated() 8
nl80211: rate_type=0
nl80211: dtim_period=2
nl80211: ssid=TestFT
  * beacon_int=100
  * dtim_period=2
nl80211: hidden SSID not in use
nl80211: privacy=1
nl80211: auth_algs=0x3
src/station.c:station_enter_state() Old State: roaming, new state: disconnected
nl80211: wpa_version=0x2
nl80211: key_mgmt_suites=0x40
nl80211: pairwise_ciphers=0x10
nl80211: group_cipher=0x10
nl80211: beacon_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
nl80211: proberesp_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
nl80211: assocresp_ies - hexdump(len=10): 7f 08 04 00 40 02 00 00 01 40
src/station.c:station_enter_state() Old State: disconnected, new state: disconnecting
[   29.372450] IPv6: ADDRCONF(NETDEV_CHANGE): wln2: link becomes ready
nl80211: multicast to unicast disabled on interface wln2
RTM_NEWLINK: ifi_index=6 ifname=wln2 operstate=6 linkmode=0 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
src/station.c:station_disconnect_cb() 8, success: 1
src/station.c:station_enter_state() Old State: disconnecting, new state: disconnected

_______________________________________________
Hostap mailing list
Hostap@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/hostap

[Index of Archives]     [Linux Wireless]     [Linux Kernel]     [ATH6KL]     [Linux Bluetooth]     [Linux Netdev]     [Kernel Newbies]     [IDE]     [Security]     [Git]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Linux ATA RAID]     [Samba]     [Device Mapper]

  Powered by Linux