Hi All
I'm having problems with iOS devices connecting to an 802.1x network that I'm setting up. The device seems to be getting stuck after Phase 2 of the Key Exchange during auth, and see a Ptk Challenge Failed as the reason for the subsequent deauth.
Reason Timestamp
------ ---------
Ptk Challenge Failed Jul 26 10:55:45
Ptk Challenge Failed Jul 26 10:55:40
Ptk Challenge Failed Jul 26 10:55:35
The user authenticates successfully (at least as far as our auth server is indicating) - however during the key exchange it seems to go awry. I've turned user-debug on for the station, and see this:
Jul 26 10:50:47 :522038: <6137> <NOTI> |dot1x-proc:2| username=myusername MAC=4c:56:9d:01:02:03 IP=0.0.0.0 Result=Successful method=802.1x server=8445VNPS001
Jul 26 10:50:47 :526162: <6137> <DBUG> |dot1x-proc:2| rx_dot1x_radius (651): vid 311
Jul 26 10:50:47 :526158: <6137> <DBUG> |dot1x-proc:2| rx_dot1x_radius (756): rtts user=4c:56:9d:01:02:03 RADIUS ACCEPT result=-1 discard=0 reest=0 keepalive=0 bkoff=0 earlylift=0
Jul 26 10:50:47 :526154: <6137> <DBUG> |dot1x-proc:2| eap_pkt (745): rtts user=4c:56:9d:01:02:03 dot1xctx_auth_type=25 enabled=0 result=-1
Jul 26 10:50:47 :526162: <6137> <DBUG> |dot1x-proc:2| 10:50:47.509087 mac 4c:56:9d:01:02:03 user mac 4c:56:9d:01:02:03 result 0 server 8445VNPS001 eap id 25 session timeut 0
Jul 26 10:50:47 :522044: <5694> <INFO> |authmgr| MAC=4c:56:9d:01:02:03 Station authenticate(start): method=802.1x, role=logon///logon, VLAN=78/78, Derivation=0/0, Value Pair=1, flags=0x8
Jul 26 10:50:47 :522158: <5694> <DBUG> |authmgr| Role Derivation for user N/A-4c:56:9d:01:02:03-myusername N/A station Authenticated with auth type: Unknown auth type.
Jul 26 10:50:47 :522142: <5694> <DBUG> |authmgr| Setting cached role to NULL for user 4c:56:9d:01:02:03".
Jul 26 10:50:47 :522266: <5694> <DBUG> |authmgr| Calling derive_role2 for user 4c:56:9d:01:02:03
Jul 26 10:50:47 :522136: <5694> <DBUG> |authmgr| {L2} guest from profile "MYSSID_aaa_prof" for user 4c:56:9d:01:02:03.
Jul 26 10:50:47 :522127: <5694> <DBUG> |authmgr| {L2} Update role from logon to guest for IP=N/A, MAC=4c:56:9d:01:02:03.
Jul 26 10:50:47 :522049: <5694> <INFO> |authmgr| MAC=4c:56:9d:01:02:03,IP=N/A User role updated, existing Role=logon/none, new Role=guest/none, reason=station Authenticated with auth type: 802.1x
Jul 26 10:50:47 :522128: <5694> <DBUG> |authmgr| download-L2: acl=7/0 role=guest, tunl=0x1003b, PA=0, HA=1, RO=0, VPN=0 L3MOB=0.
Jul 26 10:50:47 :522050: <5694> <INFO> |authmgr| MAC=4c:56:9d:01:02:03,IP=N/A User data downloaded to datapath, new Role=guest/7, bw Contract=0/0, reason=Download driven by user role setting, idle-timeout=300
Jul 26 10:50:47 :522004: <5694> <DBUG> |authmgr| auth_gsm_publish_channels: mac 4c:56:9d:01:02:03 publish_list 3 user VALID macuser VALID ipuser NULL
Jul 26 10:50:47 :522301: <5694> <DBUG> |authmgr| Auth GSM : USER publish for uuid 000c2947f68d000000060ca9 mac 4c:56:9d:01:02:03 name myusername role guest devtype iPad wired 0 authtype 4 subtype 0 encrypt-type 10 conn-port 8448 fwd-mode 0 roam 0 repkey -1
Jul 26 10:50:47 :522287: <5694> <DBUG> |authmgr| Auth GSM : MAC_USER publish for mac 4c:56:9d:01:02:03 bssid 48:4a:e9:00:27:20 vlan 78 type 1 data-ready 0 HA-IP n.a
Jul 26 10:50:47 :522258: <5694> <DBUG> |authmgr| "VDR - Add to history of user user 4c:56:9d:01:02:03 vlan 0 derivation_type Reset Dot1x VLANs index 4.
Jul 26 10:50:47 :522254: <5694> <DBUG> |authmgr| VDR - mac 4c:56:9d:01:02:03 rolename NULL fwdmode 0 derivation_type Dot1x Aruba VSA vp present.
Jul 26 10:50:47 :522254: <5694> <DBUG> |authmgr| VDR - mac 4c:56:9d:01:02:03 rolename NULL fwdmode 0 derivation_type Dot1x MSFT Attributes vp present.
Jul 26 10:50:47 :522254: <5694> <DBUG> |authmgr| VDR - mac 4c:56:9d:01:02:03 rolename NULL fwdmode 0 derivation_type Dot1x Server Rule vp present.
Jul 26 10:50:47 :522259: <5694> <DBUG> |authmgr| "VDR - Do Role Based VLAN Derivation user 4c:56:9d:01:02:03 role guest rolehow ROLE_DERIVATION_DOT1X.
Jul 26 10:50:47 :522254: <5694> <DBUG> |authmgr| VDR - mac 4c:56:9d:01:02:03 rolename guest fwdmode 0 derivation_type User Dot1x Role Contained vp not present.
Jul 26 10:50:47 :522258: <5694> <DBUG> |authmgr| "VDR - Add to history of user user 4c:56:9d:01:02:03 vlan 0 derivation_type Reset Role Based VLANs index 5.
Jul 26 10:50:47 :522161: <5694> <DBUG> |authmgr| Valid Dot1xct, remote:0, assigned:78, default:78, current:78,termstate:0, wired:0, dot1x enabled:1, psk:0 static:0 bssid=48:4a:e9:00:27:20.
Jul 26 10:50:47 :522255: <5694> <DBUG> |authmgr| "VDR - set vlan in user for 4c:56:9d:01:02:03 vlan 78 fwdmode 0 derivation_type Current VLAN updated.
Jul 26 10:50:47 :522258: <5694> <DBUG> |authmgr| "VDR - Add to history of user user 4c:56:9d:01:02:03 vlan 78 derivation_type Current VLAN updated index 6.
Jul 26 10:50:47 :522260: <5694> <DBUG> |authmgr| "VDR - Cur VLAN updated 4c:56:9d:01:02:03 mob 0 inform 1 remote 0 wired 0 defvlan 78 exportedvlan 0 curvlan 78.
Jul 26 10:50:47 :522029: <5694> <INFO> |authmgr| MAC=4c:56:9d:01:02:03 Station authenticate: method=802.1x, role=guest///logon, VLAN=78/78, Derivation=8/1, Value Pair=1
Jul 26 10:50:47 :522142: <5694> <DBUG> |authmgr| Setting cached role to guest for user 4c:56:9d:01:02:03".
Jul 26 10:50:47 :522053: <5694> <DBUG> |authmgr| PMK Cache getting updated for 4c:56:9d:01:02:03, (def, cur, vhow) = (78, 78, 1) with vlan=0 vlanhow=0 essid=MYSSID role=guest rhow=8
Jul 26 10:50:47 :522004: <5694> <DBUG> |authmgr| add_kcache: user nasip (0.0.0.0)
Jul 26 10:50:47 :522004: <5694> <DBUG> |authmgr| add_kcache: kcache present nasip (0.0.0.0) user nasip 0.0.0.0
Jul 26 10:50:47 :524129: <5694> <DBUG> |authmgr| dot1x_gsm_set_keycache(): MAC:4c:56:9d:01:02:03 GSM: Successfully published Key-cache object.
Jul 26 10:50:47 :524134: <5694> <DBUG> |authmgr| dot1x_gsm_set_pmkcache(): MAC:4c:56:9d:01:02:03 BSS:48:4a:e9:00:27:20 GSM: Successfully published PMK-cache object.
Jul 26 10:50:47 :524139: <5694> <DBUG> |authmgr| add_pmkcache():715: MAC:4c:56:9d:01:02:03 BSS:48:4a:e9:00:27:20 Update:
Jul 26 10:50:47 :522004: <5694> <DBUG> |authmgr| 10:50:47.511081 No update sent to STM. Triggering key handshake for user 4c:56:9d:01:02:03
Jul 26 10:50:47 :522004: <5694> <DBUG> |authmgr| send tunnel ID update to dot1x for 4c:56:9d:01:02:03
Jul 26 10:50:47 :522004: <5694> <DBUG> |authmgr| Starting reauth time for user 4c:56:9d:01:02:03
Jul 26 10:50:47 :522004: <6137> <DBUG> |dot1x-proc:2| 10:50:47.511081 Dot1x received tunnel ID update for mac 4c:56:9d:01:02:03
Jul 26 10:50:48 :501102: <5717> <NOTI> |stm| Disassoc from sta: 4c:56:9d:01:02:03: AP 10.224.57.9-48:4a:e9:00:27:20-MYAPNAME Reason STA has left and is disassociated
Jul 26 10:50:48 :501102: <NOTI> |AP MYAPNAME@10.224.57.9 stm| Disassoc from sta: 4c:56:9d:01:02:03: AP 10.224.57.9-48:4a:e9:00:27:20-MYAPNAME Reason STA has left and is disassociated
Jul 26 10:50:48 :522296: <6399> <DBUG> |authmgr| Auth GSM : USER_STA delete event for user 4c:56:9d:01:02:03 age 0 deauth_reason 8
Jul 26 10:50:48 :522036: <6399> <INFO> |authmgr| MAC=4c:56:9d:01:02:03 Station DN: BSSID=48:4a:e9:00:27:20 ESSID=MYSSID VLAN=78 AP-name=MYAPNAME reason=8 at 10:50:48.355082
Jul 26 10:50:48 :522234: <6399> <DBUG> |authmgr| Setting idle timer for user 4c:56:9d:01:02:03 to 300 seconds (idle timeout: 300 ageout: 0).
Jul 26 10:50:48 :522152: <6399> <DBUG> |authmgr| station free: bssid=48:4a:e9:00:27:20, mac=4c:56:9d:01:02:03.
Jul 26 10:50:48 :522244: <6399> <DBUG> |authmgr| MAC=4c:56:9d:01:02:03 Station Deleted Update MMS
Jul 26 10:50:48 :522004: <6399> <DBUG> |authmgr| 4c:56:9d:01:02:03: station datapath entry deleted
Jul 26 10:50:48 :522004: <6137> <DBUG> |dot1x-proc:2| handle_dot1x_abort called
Jul 26 10:50:48 :522004: <6399> <DBUG> |authmgr| mac_station_free: Sta->essid MYSSID mu_mac 4c:56:9d:01:02:03 macuser 0x0x7fc1c01e49f0
Jul 26 10:50:48 :522290: <6399> <DBUG> |authmgr| Auth GSM : MAC_USER delete for mac 4c:56:9d:01:02:03
Jul 26 10:50:48 :522303: <6399> <DBUG> |authmgr| Auth GSM : USER delete for mac 4c:56:9d:01:02:03 uuid 000c2947f68d000000060ca9
Jul 26 10:50:48 :501000: <5717> <DBUG> |stm| Station 4c:56:9d:01:02:03: Clearing state
Jul 26 10:50:48 :501000: <DBUG> |AP MYAPNAME@10.224.57.9 stm| Station 4c:56:9d:01:02:03: Clearing state
I'm running AOS 8.5.0.0 (I note that 8.5.0.1 is out - however couldn't see anything that specifically addressed this). It's a new deployment, so wanted to go straight to the latest code.
I should note that MacOS devices are connecting to this SSID no problems at all as are Windows devices.
Any ideas?