Hi,
I am running into an issue with Enterprise authentication with a STA
using hostapd. There is a 20 to 40 second delay because the timer
ap_sta_delayed_1x_auth_fail_cb is being called in the middle of EAP
exchange. I am attaching a log with a sequence of steps.
The sequence of steps are as follows:
1) The STA does an association and the 4 way handshake is successfully
completed. Now the station goes out of AP coverage.
2) STA again associates back to AP and AP sends an EAP Request Id with
ID 116 in line 160 in the attached log.
3) The sends a EAP logoff instead of responding with an EAP response
in line 172. Not sure if this is expected.
4) Hostapd starts a timer ap_sta_delayed_1x_auth_fail_cb for 10ms on
receiving EAP-Logoff in line 179
5) AP sends a new EAP Request ID message with ID 209 line 190
6) Then STA sends EAP Response ID message with ID 116 (previous EAP
exchange before logoff) in line number 202
7) AP discards this EAP Response with ID 116.
8) STA responds with EAP Response ID 209 in line 209
9) AP sends a RADIUS access request to the RADIUS server in line 233
10) AP receives Access Challenge from RADIUS server 269
11) Now in middle of this ap_sta_delayed_1x_auth_fail_cb timer is
triggered at line 286 causing Disconnection of STA
12) Then association is retriggered after deauth.
13) This is causing a delay of 20 to 40 seconds to authenticate.
The timer ap_sta_delayed_1x_auth_fail_cb should be cancelled for the
EAP exchange to go through. This is causing a 20 to 40 second delay in
association. If a new association happens we clear all the disconnect
timers.
Where do we cancel the timer if no new association happens as
explained above. Can you please provide some insights as to where to
call the cancellation of ap_sta_delayed_1x_auth_fail_cb timer.
Thanks & Regards,
Kiran
949428EAP_64B_WLINTERNAL_WL26D1_WLMLO_OT
1710231329.857390: nl80211: Event message available
1710231329.857432: nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for wl1
1710231329.857441: nl80211: Delete station 3a:fa:fa:3e:d7:6b
1710231329.857454: wl1: Event DISASSOC (1) received
1710231329.857468: 1710231329.857469: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.11: disassociated
1710231329.857514: wl1: AP-STA-DISCONNECTED 3a:fa:fa:3e:d7:6b
1710231329.857522: nl80211: Set STA flags - ifname=wl1 addr=3a:fa:fa:3e:d7:6b total_flags=0x8 flags_or=0x8 flags_and=0xfffffff9 authorized=0
1710231329.857620: 1710231329.857622: wl1: STA 3a:fa:fa:3e:d7:6b WPA: event 2 notification
1710231329.857649: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1310e50 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
1710231329.857662: nl80211: DEL_KEY
1710231329.857669: addr=3a:fa:fa:3e:d7:6b
1710231329.857676: pairwise key
1710231329.857841: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state DISCONNECTED
1710231329.857853: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state INITIALIZE
1710231329.857875: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1310e50 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
1710231329.857886: nl80211: DEL_KEY
1710231329.857893: addr=3a:fa:fa:3e:d7:6b
1710231329.857899: pairwise key
1710231329.858013: nl80211: Set STA flags - ifname=wl1 addr=3a:fa:fa:3e:d7:6b total_flags=0x8 flags_or=0x8 flags_and=0xfffffff9 authorized=0
1710231329.858048: hostapd_ht_operation_update current operation mode=0x0
1710231329.858055: hostapd_ht_operation_update new operation mode=0x0 changes=0
1710231329.858061: ap_free_sta: cancel ap_handle_timer for 3a:fa:fa:3e:d7:6b
1710231329.858072: EAP: Server state machine removed
1710231340.277590: nl80211: Event message available
1710231340.277664: nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wl1
1710231340.277674: nl80211: MLME event 59 (NL80211_CMD_FRAME) on wl1(d8:21:da:37:52:bb) A1=d8:21:da:37:52:bb A2=a0:2d:13:52:47:e8
1710231340.277687: nl80211: MLME event frame - hexdump(len=68): d0 00 00 00 d8 21 da 37 52 bb a0 2d 13 52 47 e8 d8 21 da 37 52 bb 00 00 04 09 50 6f 9a 1a 01 0d 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231340.277725: nl80211: Frame event
1710231340.277732: nl80211: RX frame da=d8:21:da:37:52:bb sa=a0:2d:13:52:47:e8 bssid=d8:21:da:37:52:bb freq=5220 ssi_signal=0 fc=0xd0 seq_ctrl=0x0 stype=13 (WLAN_FC_STYPE_ACTION) len=68
1710231340.277751: wl1: Event RX_MGMT (18) received
1710231340.277761: mgmt::action
1710231340.277765: RX_ACTION category 4 action 9 sa a0:2d:13:52:47:e8 da d8:21:da:37:52:bb len 68 freq 5220
1710231340.277776: DPP: Received DPP Public Action frame crypto suite 1 type 13 from a0:2d:13:52:47:e8 freq=5220
1710231340.277784: DPP: Received message attributes - hexdump(len=36): 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231340.277805: DPP: Attribute ID 1002 len 32
1710231340.277816: wl1: DPP-RX src=a0:2d:13:52:47:e8 freq=5220 type=13
1710231340.277823: DPP: Presence Announcement from a0:2d:13:52:47:e8
1710231340.277830: DPP: Responder Bootstrapping Key Hash - hexdump(len=32): c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231340.277868: wl1: DPP-CHIRP-RX id=-1 src=a0:2d:13:52:47:e8 freq=5220 hash=c8cd82148a034bab2ccc8f04215bc25ff82dcb0cd41ad954c14091df66bb2216
1710231340.277874: DPP: No matching bootstrapping information found
1710231344.108115: nl80211: Event message available
1710231344.108183: nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wl1
1710231344.108194: nl80211: MLME event 59 (NL80211_CMD_FRAME) on wl1(d8:21:da:37:52:bb) A1=d8:21:da:37:52:bb A2=a0:2d:13:52:47:e8
1710231344.108207: nl80211: MLME event frame - hexdump(len=68): d0 00 00 00 d8 21 da 37 52 bb a0 2d 13 52 47 e8 d8 21 da 37 52 bb 00 00 04 09 50 6f 9a 1a 01 0d 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231344.108245: nl80211: Frame event
1710231344.108252: nl80211: RX frame da=d8:21:da:37:52:bb sa=a0:2d:13:52:47:e8 bssid=d8:21:da:37:52:bb freq=5180 ssi_signal=0 fc=0xd0 seq_ctrl=0x0 stype=13 (WLAN_FC_STYPE_ACTION) len=68
1710231344.108271: wl1: Event RX_MGMT (18) received
1710231344.108281: mgmt::action
1710231344.108285: RX_ACTION category 4 action 9 sa a0:2d:13:52:47:e8 da d8:21:da:37:52:bb len 68 freq 5180
1710231344.108296: DPP: Received DPP Public Action frame crypto suite 1 type 13 from a0:2d:13:52:47:e8 freq=5180
1710231344.108304: DPP: Received message attributes - hexdump(len=36): 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231344.108325: DPP: Attribute ID 1002 len 32
1710231344.108336: wl1: DPP-RX src=a0:2d:13:52:47:e8 freq=5180 type=13
1710231344.108342: DPP: Presence Announcement from a0:2d:13:52:47:e8
1710231344.108349: DPP: Responder Bootstrapping Key Hash - hexdump(len=32): c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231344.108387: wl1: DPP-CHIRP-RX id=-1 src=a0:2d:13:52:47:e8 freq=5180 hash=c8cd82148a034bab2ccc8f04215bc25ff82dcb0cd41ad954c14091df66bb2216
1710231344.108394: DPP: No matching bootstrapping information found
=== mark: phone disconnect ====
1710231353.975439: nl80211: Event message available
1710231353.975485: nl80211: Ignored event 60 (NL80211_CMD_FRAME_TX_STATUS) for foreign interface (ifindex 19 wdev 0x0)
1710231360.398229: nl80211: Event message available
1710231360.398296: nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wl1
1710231360.398306: nl80211: MLME event 59 (NL80211_CMD_FRAME) on wl1(d8:21:da:37:52:bb) A1=d8:21:da:37:52:bb A2=a0:2d:13:52:47:e8
1710231360.398320: nl80211: MLME event frame - hexdump(len=68): d0 00 00 00 d8 21 da 37 52 bb a0 2d 13 52 47 e8 d8 21 da 37 52 bb 00 00 04 09 50 6f 9a 1a 01 0d 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231360.398357: nl80211: Frame event
1710231360.398363: nl80211: RX frame da=d8:21:da:37:52:bb sa=a0:2d:13:52:47:e8 bssid=d8:21:da:37:52:bb freq=5220 ssi_signal=0 fc=0xd0 seq_ctrl=0x0 stype=13 (WLAN_FC_STYPE_ACTION) len=68
1710231360.398382: wl1: Event RX_MGMT (18) received
1710231360.398392: mgmt::action
1710231360.398396: RX_ACTION category 4 action 9 sa a0:2d:13:52:47:e8 da d8:21:da:37:52:bb len 68 freq 5220
1710231360.398407: DPP: Received DPP Public Action frame crypto suite 1 type 13 from a0:2d:13:52:47:e8 freq=5220
1710231360.398415: DPP: Received message attributes - hexdump(len=36): 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231360.398437: DPP: Attribute ID 1002 len 32
1710231360.398447: wl1: DPP-RX src=a0:2d:13:52:47:e8 freq=5220 type=13
1710231360.398454: DPP: Presence Announcement from a0:2d:13:52:47:e8
1710231360.398461: DPP: Responder Bootstrapping Key Hash - hexdump(len=32): c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231360.398499: wl1: DPP-CHIRP-RX id=-1 src=a0:2d:13:52:47:e8 freq=5220 hash=c8cd82148a034bab2ccc8f04215bc25ff82dcb0cd41ad954c14091df66bb2216
1710231360.398506: DPP: No matching bootstrapping information found
1710231364.180706: nl80211: Event message available
1710231364.180773: nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wl1
1710231364.180784: nl80211: MLME event 59 (NL80211_CMD_FRAME) on wl1(d8:21:da:37:52:bb) A1=d8:21:da:37:52:bb A2=a0:2d:13:52:47:e8
1710231364.180797: nl80211: MLME event frame - hexdump(len=68): d0 00 00 00 d8 21 da 37 52 bb a0 2d 13 52 47 e8 d8 21 da 37 52 bb 00 00 04 09 50 6f 9a 1a 01 0d 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231364.180834: nl80211: Frame event
1710231364.180841: nl80211: RX frame da=d8:21:da:37:52:bb sa=a0:2d:13:52:47:e8 bssid=d8:21:da:37:52:bb freq=5180 ssi_signal=0 fc=0xd0 seq_ctrl=0x0 stype=13 (WLAN_FC_STYPE_ACTION) len=68
1710231364.180860: wl1: Event RX_MGMT (18) received
1710231364.180869: mgmt::action
1710231364.180874: RX_ACTION category 4 action 9 sa a0:2d:13:52:47:e8 da d8:21:da:37:52:bb len 68 freq 5180
1710231364.180885: DPP: Received DPP Public Action frame crypto suite 1 type 13 from a0:2d:13:52:47:e8 freq=5180
1710231364.180893: DPP: Received message attributes - hexdump(len=36): 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231364.180914: DPP: Attribute ID 1002 len 32
1710231364.180925: wl1: DPP-RX src=a0:2d:13:52:47:e8 freq=5180 type=13
1710231364.180931: DPP: Presence Announcement from a0:2d:13:52:47:e8
1710231364.180938: DPP: Responder Bootstrapping Key Hash - hexdump(len=32): c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231364.180976: wl1: DPP-CHIRP-RX id=-1 src=a0:2d:13:52:47:e8 freq=5180 hash=c8cd82148a034bab2ccc8f04215bc25ff82dcb0cd41ad954c14091df66bb2216
1710231364.180983: DPP: No matching bootstrapping information found
1710231369.602147: nl80211: Event message available
1710231369.602212: nl80211: BSS Event 59 (NL80211_CMD_FRAME) received for wl1
1710231369.602223: nl80211: MLME event 59 (NL80211_CMD_FRAME) on wl1(d8:21:da:37:52:bb) A1=d8:21:da:37:52:bb A2=a0:2d:13:52:47:e8
1710231369.602235: nl80211: MLME event frame - hexdump(len=68): d0 00 00 00 d8 21 da 37 52 bb a0 2d 13 52 47 e8 d8 21 da 37 52 bb 00 00 04 09 50 6f 9a 1a 01 0d 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231369.602272: nl80211: Frame event
1710231369.602279: nl80211: RX frame da=d8:21:da:37:52:bb sa=a0:2d:13:52:47:e8 bssid=d8:21:da:37:52:bb freq=5200 ssi_signal=0 fc=0xd0 seq_ctrl=0x0 stype=13 (WLAN_FC_STYPE_ACTION) len=68
1710231369.602297: wl1: Event RX_MGMT (18) received
1710231369.602307: mgmt::action
1710231369.602311: RX_ACTION category 4 action 9 sa a0:2d:13:52:47:e8 da d8:21:da:37:52:bb len 68 freq 5200
1710231369.602322: DPP: Received DPP Public Action frame crypto suite 1 type 13 from a0:2d:13:52:47:e8 freq=5200
1710231369.602331: DPP: Received message attributes - hexdump(len=36): 02 10 20 00 c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231369.602352: DPP: Attribute ID 1002 len 32
1710231369.602362: wl1: DPP-RX src=a0:2d:13:52:47:e8 freq=5200 type=13
1710231369.602369: DPP: Presence Announcement from a0:2d:13:52:47:e8
1710231369.602375: DPP: Responder Bootstrapping Key Hash - hexdump(len=32): c8 cd 82 14 8a 03 4b ab 2c cc 8f 04 21 5b c2 5f f8 2d cb 0c d4 1a d9 54 c1 40 91 df 66 bb 22 16
1710231369.602414: wl1: DPP-CHIRP-RX id=-1 src=a0:2d:13:52:47:e8 freq=5200 hash=c8cd82148a034bab2ccc8f04215bc25ff82dcb0cd41ad954c14091df66bb2216
1710231369.602420: DPP: No matching bootstrapping information found
1710231371.070906: nl80211: Event message available
1710231371.070975: nl80211: Drv Event 19 (NL80211_CMD_NEW_STATION) received for wl1
1710231371.070985: nl80211: New station 3a:fa:fa:3e:d7:6b
1710231371.070994: nl80211: Assoc Req IEs - hexdump(len=210): 00 12 41 31 2d 42 4d 32 5f 63 61 72 6c 5f 72 61 64 69 75 73 01 08 8c 12 98 24 b0 48 60 6c 21 02 f9 15 24 0a 24 04 34 04 64 0c 95 04 a5 01 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 01 8c 00 46 05 71 08 01 00 00 2d 1a 6f 00 1b ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 7f 0b 00 00 08 00 00 00 00 40 00 00 20 6b 07 0f ff ff ff ff ff ff bf 0c 32 70 81 0f fa ff 00 00 fa ff 00 00 ff 1c 23 01 08 08 00 00 80 44 30 02 00 1d 00 9f 08 00 0c 00 fa ff fa ff 39 1c c7 71 1c 07 dd 0b 00 17 f2 0a 00 01 04 00 00 00 00 dd 05 00 90 4c 04 07 dd 0a 00 10 18 02 00 00 10 00 00 02 dd 07 00 50 f2 02 00 01 00
1710231371.071101: wl1: Event ASSOC (0) received
1710231371.071119: 1710231371.071120: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.11: associated
1710231371.071165: STA included RSN IE in (Re)AssocReq
1710231371.071173: New STA
1710231371.071237: ap_sta_add: register ap_handle_timer timeout for 3a:fa:fa:3e:d7:6b (300 seconds - ap_max_inactivity)
1710231371.071266: nl80211: Set STA flags - ifname=wl1 addr=3a:fa:fa:3e:d7:6b total_flags=0x68 flags_or=0x8 flags_and=0xfffffff9 authorized=0
1710231371.071489: 1710231371.071491: wl1: STA 3a:fa:fa:3e:d7:6b WPA: event 1 notification
1710231371.071523: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1317220 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
1710231371.071564: nl80211: DEL_KEY
1710231371.071574: addr=3a:fa:fa:3e:d7:6b
1710231371.071582: pairwise key
1710231371.071773: 1710231371.071775: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: start authentication
1710231371.071789: EAP: Server state machine created
1710231371.071800: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state IDLE
1710231371.071809: IEEE 802.1X: 3a:fa:fa:3e:d7:6b CTRL_DIR entering state FORCE_BOTH
1710231371.071876: 1710231371.071878: wl1: STA 3a:fa:fa:3e:d7:6b WPA: start authentication
1710231371.071886: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state INITIALIZE
1710231371.071912: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1317220 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
1710231371.071924: nl80211: DEL_KEY
1710231371.071934: addr=3a:fa:fa:3e:d7:6b
1710231371.071941: pairwise key
1710231371.072101: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK_GROUP entering state IDLE
1710231371.072112: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state AUTHENTICATION
1710231371.072122: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state AUTHENTICATION2
1710231371.072131: Get randomness: len=32 entropy=16
1710231371.072216: WPA: Assign ANonce - hexdump(len=32): d3 f6 30 9d 1b 88 f9 57 6c 36 44 cb 6f 5c 19 6b 6d 45 9e a5 e2 25 c0 e3 01 92 a1 73 15 96 81 35
1710231371.072240: wl1: hostapd_new_assoc_sta: reschedule ap_handle_timer timeout for 3a:fa:fa:3e:d7:6b (300 seconds - ap_max_inactivity)
1710231371.072276: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state DISCONNECTED
1710231371.072287: nl80211: Set STA flags - ifname=wl1 addr=3a:fa:fa:3e:d7:6b total_flags=0x68 flags_or=0x0 flags_and=0xfffffffe authorized=0
1710231371.072528: 1710231371.072530: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: unauthorizing port
1710231371.072546: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state RESTART
1710231371.072555: EAP: EAP entering state INITIALIZE
1710231371.072566: wl1: CTRL-EVENT-EAP-STARTED 3a:fa:fa:3e:d7:6b
1710231371.072573: EAP: EAP entering state SELECT_ACTION
1710231371.072583: EAP: getDecision: no identity known yet -> CONTINUE
1710231371.072590: EAP: EAP entering state PROPOSE_METHOD
1710231371.072596: EAP: getNextMethod: vendor 0 type 1
1710231371.072606: wl1: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1
1710231371.072614: EAP: EAP entering state METHOD_REQUEST
1710231371.072621: EAP: building EAP-Request: Identifier 116
1710231371.072630: EAP: EAP entering state SEND_REQUEST
1710231371.072638: EAP: EAP entering state IDLE
1710231371.072644: EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
1710231371.072651: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state CONNECTING
1710231371.072659: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state AUTHENTICATING
1710231371.072668: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state REQUEST
1710231371.072681: 1710231371.072682: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: Sending EAP Packet (identifier 116)
1710231371.098731: wl1: Event EAPOL_RX (23) received
1710231371.098760: IEEE 802.1X: 22 bytes from 3a:fa:fa:3e:d7:6b
1710231371.098769: IEEE 802.1X: version=1 type=2 length=0
1710231371.098776: ignoring 18 extra octets after IEEE 802.1X packet
1710231371.098790: 1710231371.098791: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: received EAPOL-Logoff from STA
1710231371.098812: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state ABORTING
1710231371.098822: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state INITIALIZE
1710231371.098835: 1710231371.098836: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: aborting authentication
1710231371.098846: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state DISCONNECTED
1710231371.098857: nl80211: Set STA flags - ifname=wl1 addr=3a:fa:fa:3e:d7:6b total_flags=0x68 flags_or=0x0 flags_and=0xfffffffe authorized=0
1710231371.099781: 1710231371.099784: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: unauthorizing port
1710231371.099802: wl1: IEEE 802.1X: Force disconnection of 3a:fa:fa:3e:d7:6b after EAP-Failure in 10 ms
1710231371.099813: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state IDLE
1710231371.099823: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state RESTART
1710231371.099834: EAP: EAP entering state INITIALIZE
1710231371.099845: wl1: CTRL-EVENT-EAP-STARTED 3a:fa:fa:3e:d7:6b
1710231371.099853: EAP: EAP entering state SELECT_ACTION
1710231371.099860: EAP: getDecision: no identity known yet -> CONTINUE
1710231371.099867: EAP: EAP entering state PROPOSE_METHOD
1710231371.099873: EAP: getNextMethod: vendor 0 type 1
1710231371.099883: wl1: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=1
1710231371.099890: EAP: EAP entering state METHOD_REQUEST
1710231371.099898: EAP: building EAP-Request: Identifier 209
1710231371.099906: EAP: EAP entering state SEND_REQUEST
1710231371.099913: EAP: EAP entering state IDLE
1710231371.099920: EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
1710231371.099927: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state CONNECTING
1710231371.099936: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state AUTHENTICATING
1710231371.099944: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state REQUEST
1710231371.099957: 1710231371.099958: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: Sending EAP Packet (identifier 209)
1710231371.100025: wl1: Event EAPOL_RX (23) received
1710231371.100033: IEEE 802.1X: 28 bytes from 3a:fa:fa:3e:d7:6b
1710231371.100040: IEEE 802.1X: version=1 type=0 length=10
1710231371.100047: ignoring 14 extra octets after IEEE 802.1X packet
1710231371.100054: EAP: code=2 (response) identifier=116 length=10
1710231371.100068: 1710231371.100069: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: received EAP packet (code=2 id=116 len=10) from STA: EAP Response-Identity (1)
1710231371.100101: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state RESPONSE
1710231371.100110: EAP: EAP entering state RECEIVED
1710231371.100116: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=116 respMethod=1 respVendor=0 respVendorMethod=0
1710231371.100124: EAP: RECEIVED->DISCARD: rxResp=1 respId=116 currentId=209 respMethod=1 currentMethod=1
1710231371.100132: EAP: EAP entering state DISCARD
1710231371.100138: EAP: EAP entering state IDLE
1710231371.100142: EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
1710231371.100148: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state IGNORE
1710231371.104080: wl1: Event EAPOL_RX (23) received
1710231371.104104: IEEE 802.1X: 28 bytes from 3a:fa:fa:3e:d7:6b
1710231371.104113: IEEE 802.1X: version=1 type=0 length=10
1710231371.104120: ignoring 14 extra octets after IEEE 802.1X packet
1710231371.104128: EAP: code=2 (response) identifier=209 length=10
1710231371.104144: 1710231371.104146: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: received EAP packet (code=2 id=209 len=10) from STA: EAP Response-Identity (1)
1710231371.104168: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state RESPONSE
1710231371.104181: EAP: EAP entering state RECEIVED
1710231371.104188: EAP: parseEapResp: rxResp=1 rxInitiate=0 respId=209 respMethod=1 respVendor=0 respVendorMethod=0
1710231371.104196: EAP: EAP entering state INTEGRITY_CHECK
1710231371.104203: EAP: EAP entering state METHOD_RESPONSE
1710231371.104211: EAP-Identity: Peer identity - hexdump_ascii(len=5):
73 74 65 76 65 steve
1710231371.104232: EAP: EAP entering state SELECT_ACTION
1710231371.104238: EAP: getDecision: -> PASSTHROUGH
1710231371.104245: EAP: EAP entering state INITIALIZE_PASSTHROUGH
1710231371.104251: EAP: EAP entering state AAA_REQUEST
1710231371.104258: EAP: EAP entering state AAA_IDLE
1710231371.104271: 1710231371.104272: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: STA identity 'steve'
1710231371.104279: Encapsulating EAP message into a RADIUS packet
1710231371.104406: 1710231371.104408: wl1: RADIUS Sending RADIUS message to authentication server
1710231371.104416: RADIUS message: code=1 (Access-Request) identifier=7 length=222
1710231371.104425: Attribute 1 (User-Name) length=7
1710231371.104432: Value: 'steve'
1710231371.104438: Attribute 4 (NAS-IP-Address) length=6
1710231371.104446: Value: 127.0.0.1
1710231371.104451: Attribute 30 (Called-Station-Id) length=38
1710231371.104458: Value: 'D8-21-DA-37-52-BB:A1-BM2_carl_radius'
1710231371.104465: Attribute 61 (NAS-Port-Type) length=6
1710231371.104471: Value: 19
1710231371.104476: Attribute 6 (Service-Type) length=6
1710231371.104482: Value: 2
1710231371.104488: Attribute 31 (Calling-Station-Id) length=19
1710231371.104494: Value: '3A-FA-FA-3E-D7-6B'
1710231371.104500: Attribute 77 (Connect-Info) length=24
1710231371.104506: Value: 'CONNECT 24Mbps 802.11a'
1710231371.104512: Attribute 44 (Acct-Session-Id) length=18
1710231371.104518: Value: '63253FFA0DC89B79'
1710231371.104524: Attribute 50 (Acct-Multi-Session-Id) length=18
1710231371.104530: Value: '8E0B33663AB3BCE2'
1710231371.104549: Attribute 186 (WLAN-Pairwise-Cipher) length=6
1710231371.104558: Value: 000fac04
1710231371.104563: Attribute 187 (WLAN-Group-Cipher) length=6
1710231371.104571: Value: 000fac04
1710231371.104577: Attribute 188 (WLAN-AKM-Suite) length=6
1710231371.104584: Value: 000fac01
1710231371.104590: Attribute 189 (WLAN-Group-Mgmt-Pairwise-Cipher) length=6
1710231371.104598: Value: 000fac06
1710231371.104604: Attribute 12 (Framed-MTU) length=6
1710231371.104609: Value: 1400
1710231371.104613: Attribute 79 (EAP-Message) length=12
1710231371.104624: Value: 02d1000a017374657665
1710231371.104629: Attribute 80 (Message-Authenticator) length=18
1710231371.104641: Value: ed35f0c579139d6a8e4f0e6669f044bf
1710231371.104691: 1710231371.104692: wl1: RADIUS Next RADIUS client retransmit in 2 seconds
1710231371.105685: 1710231371.105687: wl1: RADIUS Received 64 bytes from RADIUS server
1710231371.105704: 1710231371.105705: wl1: RADIUS Received RADIUS message
1710231371.105711: RADIUS message: code=11 (Access-Challenge) identifier=7 length=64
1710231371.105718: Attribute 79 (EAP-Message) length=8
1710231371.105726: Value: 01d200061520
1710231371.105731: Attribute 80 (Message-Authenticator) length=18
1710231371.105742: Value: fbb0cb50cae0d0ce2cf78ab8f02ad0bf
1710231371.105747: Attribute 24 (State) length=18
1710231371.105757: Value: eb05ace4ebd7b9f1e1c34836b1b1f654
1710231371.105768: 1710231371.105770: wl1: STA 3a:fa:fa:3e:d7:6b RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
1710231371.105796: RADIUS packet matching with station 3a:fa:fa:3e:d7:6b
1710231371.105814: 1710231371.105815: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: decapsulated EAP packet (code=1 id=210 len=6) from RADIUS server: EAP-Request-unknown (21)
1710231371.105833: EAP: EAP entering state AAA_RESPONSE
1710231371.105840: EAP: getId: id=210
1710231371.105845: EAP: EAP entering state SEND_REQUEST2
1710231371.105850: EAP: EAP entering state IDLE2
1710231371.105855: EAP: retransmit timeout 3 seconds (from dynamic back off; retransCount=0)
1710231371.105862: IEEE 802.1X: 3a:fa:fa:3e:d7:6b BE_AUTH entering state REQUEST
1710231371.105875: 1710231371.105876: wl1: STA 3a:fa:fa:3e:d7:6b IEEE 802.1X: Sending EAP Packet (identifier 210)
1710231371.109904: wl1: IEEE 802.1X: Scheduled disconnection of 3a:fa:fa:3e:d7:6b after EAP-Failure
1710231371.109923: wl1: ap_sta_disconnect STA 3a:fa:fa:3e:d7:6b reason=23
1710231371.110621: nl80211: sta_remove -> DEL_STATION wl1 3a:fa:fa:3e:d7:6b --> 0 (Success)
1710231371.110638: nl80211: Set STA flags - ifname=wl1 addr=3a:fa:fa:3e:d7:6b total_flags=0x8 flags_or=0x8 flags_and=0xfffffff9 authorized=0
1710231371.110720: 1710231371.110721: wl1: STA 3a:fa:fa:3e:d7:6b WPA: event 3 notification
1710231371.110765: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1317220 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
1710231371.110778: nl80211: DEL_KEY
1710231371.110786: addr=3a:fa:fa:3e:d7:6b
1710231371.110793: pairwise key
1710231371.120208: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state DISCONNECTED
1710231371.120250: WPA: 3a:fa:fa:3e:d7:6b WPA_PTK entering state INITIALIZE
1710231371.120314: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1317220 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
1710231371.120338: nl80211: DEL_KEY
1710231371.120363: addr=3a:fa:fa:3e:d7:6b
1710231371.120383: pairwise key
1710231371.120626: wl1: ap_sta_disconnect: reschedule ap_handle_timer timeout for 3a:fa:fa:3e:d7:6b (5 seconds - AP_MAX_INACTIVITY_AFTER_DEAUTH)
1710231371.120672: IEEE 802.1X: 3a:fa:fa:3e:d7:6b AUTH_PAE entering state INITIALIZE
1710231371.120695: EAP: EAP entering state DISABLED
1710231371.120728: wl1: Deauthentication callback for STA 3a:fa:fa:3e:d7:6b
1710231371.120746: wl1: Removing STA 3a:fa:fa:3e:d7:6b from kernel driver
1710231371.121020: nl80211: sta_remove -> DEL_STATION wl1 3a:fa:fa:3e:d7:6b --> 0 (Success)
1710231371.121052: 1710231371.121054: wl1: STA 3a:fa:fa:3e:d7:6b MLME: MLME-DEAUTHENTICATE.indication(3a:fa:fa:3e:d7:6b, 23)
1710231371.121077: 1710231371.121078: wl1: STA 3a:fa:fa:3e:d7:6b MLME: MLME-DELETEKEYS.request(3a:fa:fa:3e:d7:6b)
1710231371.121111: wpa_driver_nl80211_set_key: ifindex=18 (wl1) alg=0 addr=0x1317220 key_idx=0 set_tx=1 seq_len=0 key_len=0 key_flag=0x20
_______________________________________________
Hostap mailing list
Hostap@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/hostap
