Cisco vWLC DHCP issues

For my setup I have a Cisco vWLC on a VMware vSphere machine, flexconnect enabled and a dhcp server specified. I can get my Win 10 laptop to connect to my test AP, but I can't get a DHCP address. After I'm connected I try an ipconfig /release /renew and I get a "unable to connect to your DHCP server".

The debug output from my laptop in the act of connecting to the AP, requesting DHCP, not getting DHCP, then me running the ipconfig /release /renew is below. Any help is appreciated.

(Cisco Controller) >*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP received op BOOTREPLY (2) (len 334,<management VLAN #>, port 1, encap 0xec03)
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP processing DHCP ACK (5)
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   xid: 0x3bd7043b (1003947067), secs: 0, flags: 0
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   chaddr: b4:ae:2b:ed:2c:9a
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   ciaddr: 0.0.0.0,  yiaddr: <valid wireless VLAN address>
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0
*DHCP Socket Task: Mar 07 11:23:56.650: b4:ae:2b:ed:2c:9a DHCP   server id: <wireless VLAN DHCP address>  rcvd server id: <wireless VLAN DHCP address>
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP received op BOOTREPLY (2) (len 334,<management VLAN #>, port 1, encap 0xec03)
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP processing DHCP ACK (5)
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP   xid: 0x3bd7043b (1003947067), secs: 0, flags: 80
*DHCP Socket Task: Mar 07 11:23:56.655: b4:ae:2b:ed:2c:9a DHCP   chaddr: b4:ae:2b:ed:2c:9a
*DHCP Socket Task: Mar 07 11:23:56.656: b4:ae:2b:ed:2c:9a DHCP   ciaddr: 0.0.0.0,  yiaddr: <valid wireless VLAN address>
*DHCP Socket Task: Mar 07 11:23:56.656: b4:ae:2b:ed:2c:9a DHCP   siaddr: 0.0.0.0,  giaddr: <wireless VLAN interface address>
*DHCP Socket Task: Mar 07 11:23:56.656: b4:ae:2b:ed:2c:9a DHCP   server id: <wireless VLAN DHCP address>  rcvd server id: <wireless VLAN DHCP address>
*apfMsConnTask_3: Mar 07 11:24:04.296: b4:ae:2b:ed:2c:9a Processing assoc-req station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 thread:548c7a0
*apfMsConnTask_3: Mar 07 11:24:04.296: b4:ae:2b:ed:2c:9a Association received from mobile on BSSID 80:e8:6f:1e:da:cf AP AP80e0.1dfe.311b
*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Global 200 Clients are allowed to AP radio

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Max Client Trap Threshold: 0  cur: 1

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a override for default ap group, marking intgrp NULL
*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access <wireless VLAN>

*apfMsConnTask_3: Mar 07 11:24:04.297: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a In processSsidIE:5733 setting Central switched to FALSE
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a Set Clinet MSCB as Central Association Disabled
*apfMsConnTask_3: Mar 07 11:24:04.298: b4:ae:2b:ed:2c:9a Setting the NAS Id to WLAN specific Id '<vWLC system name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying site-specific Local Bridging override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group name>', interface '<wireless interface name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying Local Bridging Interface Policy for station b4:ae:2b:ed:2c:9a - <wireless VLAN>, interface id 5, interface '<wireless interface name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a override from ap group, removing intf group from mscb
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying site-specific override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group name>', interface '<wireless interface name>'
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access <management VLAN #>

*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 07 11:24:04.299: b4:ae:2b:ed:2c:9a Set Clinet Non AP specific apfMsAccessVlan = <wireless VLAN>
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a processSsidIE  statusCode is 0 and status is 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a processSsidIE  ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a STA - rates (8): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a suppRates  statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a STA - rates (12): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 07 11:24:04.300: b4:ae:2b:ed:2c:9a extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1
*apfMsConnTask_3: Mar 07 11:24:04.301: RSNIE in Assoc. Req.: (20)

*apfMsConnTask_3: Mar 07 11:24:04.301:      [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_3: Mar 07 11:24:04.301:      [0016] ac 01 00 00

*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Processing RSN IE type 48, length 20 for mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a RSN Capabilities:  0
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a apfValidateDot11iCapabilities:1286 Received RSNIE with Capabilities with STA MFPC: 0, STA MFPR:0, & AP MFPC:0MFPR:0
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Marking Mobile as non-11w Capable
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Received RSN IE with 0 PMKIDs from mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.301: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a Removing BSSID 80:e8:6f:1e:da:80 from PMKID cache of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a Setting active key cache index 0 ---> 8
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a apfValidateDot11wGroupMgmtCipher:1716, Received NULL 11w Group Mgmt Cipher Suite for STA, hence returning

*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a AID 1 in Assoc Req from flex AP 80:e8:6f:1e:da:80 is same as in mscb b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 07 11:24:04.302: b4:ae:2b:ed:2c:9a apfMsRunStateDec
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a apfMs1xStateDec
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> START (0) Initializing policy
*apfMsConnTask_3: Mar 07 11:24:04.303: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a Encryption policy is set to 0x80000001
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> 8021X_REQD (3) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*apfMsConnTask_3: Mar 07 11:24:04.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a apfPemAddUser2 (apf_policy.c:352) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a apfPemAddUser2:session timeout forstation b4:ae:2b:ed:2c:9a - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Sending assoc-resp with status 0 station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 on apVapId 1
*apfMsConnTask_3: Mar 07 11:24:04.305: b4:ae:2b:ed:2c:9a Sending Assoc Response to station on BSSID 80:e8:6f:1e:da:80 (status 0) ApVapId 1 Slot 0
*apfMsConnTask_3: Mar 07 11:24:04.306: b4:ae:2b:ed:2c:9a apfProcessAssocReq (apf_80211.c:9463) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*spamApTask7: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a Sent 1x initiate message to multi thread task for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a EAP-PARAM Debug - eap-params for Wlan-Id :<wireless VLAN> is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.308: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 1)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a Received EAPOL START from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 2)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.317: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.321: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.321: b4:ae:2b:ed:2c:9a Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.321: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Received Identity Response (count=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Resetting reauth count 1 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a EAP State update from Connecting to Authenticating for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticating state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.323: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=3) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 3)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a Allocating EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.329: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 3, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.334: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=4) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 4)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.336: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 4, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.342: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a WARNING: updated EAP-Identifier 4 ===> 7 for STA b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.469: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 7, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.476: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Processing Access-Accept for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Resetting web IPv4 Flex acl from 65535 to 65535

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Setting re-auth timeout to 1800 seconds, got from WLAN config.
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Station b4:ae:2b:ed:2c:9a setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Creating a PKC PMKID Cache entry for station b4:ae:2b:ed:2c:9a (RSN 2)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.478: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Adding BSSID 80:e8:6f:1e:da:80 to PMKID cache at index 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: New PMKID: (16)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479:      [0000] 25 bc 73 11 75 a0 63 d3 0e 25 1b 37 33 14 57 63

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Disabling re-auth since PMK lifetime can take care of same.
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a PMK: Sending cache delete
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Zeroize AAA Overrides from local for station
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a PMK sent to mobility group
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Sending EAP-Success to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Freeing AAACB from Dot1xCB as AAA auth is done for  mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: Including PMKID in M1  (16)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479:      [0000] 25 bc 73 11 75 a0 63 d3 0e 25 1b 37 33 14 57 63

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Starting key exchange to mobile b4:ae:2b:ed:2c:9a, data packets will be dropped
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Entering Backend Auth Success state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a Received Auth Success while in Authenticating state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.479: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticated state
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTK_START state (message 2) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Dumping RSNIE received in Association request:
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000000: 30 14 01 00 00 0f ac 04  01 00 00 0f ac 04 01 00  0...............
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000010: 00 0f ac 01 00 00                                 ......
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Dumping RSNIE received in EAPOL M2 :
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000000: 01 00 00 0f ac 04 01 00  00 0f ac 04 01 00 00 0f  ................
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: 00000010: ac 01 00 00                                       ....
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a PMK: Sending cache add
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.491: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Freeing EAP Retransmit Bufer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMs1xStateInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMsPeapSimReqSuccessCntInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> L2AUTHCOMPLETE (4) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a apfMsRunStateInc
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Reached PLUMBFASTPATH: from line 6649
*Dot1x_NW_MsgTask_2: Mar 07 11:24:04.496: b4:ae:2b:ed:2c:9a <valid wireless VLAN address> RUN (20) Change state to RUN (20) last state RUN (20)

*DHCP Socket Task: Mar 07 11:24:04.537: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,<management VLAN #>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 07 11:24:04.537: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 07 11:24:04.537: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 07 11:24:08.019: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,<management VLAN #>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 07 11:24:08.019: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 07 11:24:08.019: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
travisryanAsked:
Who is Participating?
I wear a lot of hats...

"The solutions and answers provided on Experts Exchange have been extremely helpful to me over the last few years. I wear a lot of hats - Developer, Database Administrator, Help Desk, etc., so I know a lot of things but not a lot about one thing. Experts Exchange gives me answers from people who do know a lot about one thing, in a easy to use platform." -Todd S.

KmitraCommented:
Make sure the switch port that connects to your CiscovWLC VM is a trunk port and also make sure the VLAN s for your DHCP server and the other network that you are trying to connect your Windows 10 laptop are allowed.
travisryanAuthor Commented:
Here's the port the vWLC is connected to:

interface Port-channel<#>
 switchport trunk encapsulation dot1q
 switchport trunk allowed vlan <wireless VLAN>,<Management VLAN>
 switchport mode trunk
 switchport nonegotiate
KmitraCommented:
So you have more than 1 switch ports connected to your ESXI host using a port channel. And your DHCP server is part of Management Vlan.

Port channel config looks right.
can you tell me if your Controller can ping the DHCP server and all your AP ?
Your Guide to Achieving IT Business Success

The IT Service Excellence Tool Kit has best practices to keep your clients happy and business booming. Inside, you’ll find everything you need to increase client satisfaction and retention, become more competitive, and increase your overall success.

KmitraCommented:
also check your switch port settings that connect you ap. In order accommodate multiple vlan those ports also has to be a trunk port.
travisryanAuthor Commented:
My DHCP server is in the wireless VLAN.

Here's my AP port:

interface GigabitEthernet <#/#/#>
 switchport trunk encapsulation dot1q
 switchport trunk native vlan <management VLAN>
 switchport trunk allowed <wireless VLAN>,<management VLAN>
 switchport mode trunk
 switchport nonegotiate
Craig BeckCommented:
Can you show the FlexConnect VLAN mappings for your AP please?
travisryanAuthor Commented:
Craig, attached is the flexconnect mappings and WLAN settings just in case that helps.
vWLC_FC1.JPG
vWLC_WLAN1.JPG
vWLC_WLAN2.JPG
vWLC_WLAN3.JPG
Craig BeckCommented:
Is the DHCP server on the same VLAN as the WLAN VLAN?
travisryanAuthor Commented:
For right now, yes there is a DHCP server interface in the Wireless VLAN. That's going to change down the road when we'll just use a helper address.
Craig BeckCommented:
When you're using FlexConnect the DHCP packet will fall straight onto the switch from the AP's port.  You don't want to specify the DHCP server at the WLC.  Untick the "DHCP Server" box in the WLAN's Advanced tab and see what happens.

Have you tried with different types of device?

What device is doing DHCP?  What OS, etc?
travisryanAuthor Commented:
I tried it before without the DHCP server box ticked but I'll test it again. I have a WIn 2008 R2 server handing out DHCP.
travisryanAuthor Commented:
When I try to connect after unchecking the DHCP server option below is what I get in the debug. Two things I find interesting 1) The <valid wireless VLAN IP> in the debug below is the IP address this laptop has when I connect it to a regular access point 2) The ip for the DHCP server does pop up in the debug as you'll see.

I still don't get an address and the first few times I ran an ipconfig /renew I saw "an address has not been associated with the network endpoint" but after a few tries it says "cannot contact DHCP server".

Debug:

(Cisco Controller) >*DHCP Socket Task: Mar 09 10:47:45.660: b4:ae:2b:ed:2c:9a DHCP   server id: <wireless VLAN DHCP server>  rcvd server id: <wireless VLAN DHCP server>
*apfMsConnTask_3: Mar 09 10:48:08.242: b4:ae:2b:ed:2c:9a Processing assoc-req station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 thread:548c7a0
*apfMsConnTask_3: Mar 09 10:48:08.243: b4:ae:2b:ed:2c:9a Association received from mobile on BSSID 80:e8:6f:1e:da:cf AP AP80e0.1dfe.311b
*apfMsConnTask_3: Mar 09 10:48:08.250: b4:ae:2b:ed:2c:9a Global 200 Clients are allowed to AP radio

*apfMsConnTask_3: Mar 09 10:48:08.250: b4:ae:2b:ed:2c:9a Max Client Trap Threshold: 0  cur: 1

*apfMsConnTask_3: Mar 09 10:48:08.250: b4:ae:2b:ed:2c:9a Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_3: Mar 09 10:48:08.255: b4:ae:2b:ed:2c:9a override for default ap group, marking intgrp NULL
*apfMsConnTask_3: Mar 09 10:48:08.266: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan <wireless VLAN>

*apfMsConnTask_3: Mar 09 10:48:08.266: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 09 10:48:08.266: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 09 10:48:08.267: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 09 10:48:08.267: b4:ae:2b:ed:2c:9a apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_3: Mar 09 10:48:08.272: b4:ae:2b:ed:2c:9a In processSsidIE:5733 setting Central switched to FALSE
*apfMsConnTask_3: Mar 09 10:48:08.272: b4:ae:2b:ed:2c:9a Set Clinet MSCB as Central Association Disabled
*apfMsConnTask_3: Mar 09 10:48:08.272: b4:ae:2b:ed:2c:9a Setting the NAS Id to WLAN specific Id '<AP name>'
*apfMsConnTask_3: Mar 09 10:48:08.276: b4:ae:2b:ed:2c:9a Applying site-specific Local Bridging override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group>', interface '<Interface name>'
*apfMsConnTask_3: Mar 09 10:48:08.277: b4:ae:2b:ed:2c:9a Applying Local Bridging Interface Policy for station b4:ae:2b:ed:2c:9a - Vlan <wireless VLAN>, interface id 5, interface '<Interface name>'
*apfMsConnTask_3: Mar 09 10:48:08.277: b4:ae:2b:ed:2c:9a override from ap group, removing intf group from mscb
*apfMsConnTask_3: Mar 09 10:48:08.277: b4:ae:2b:ed:2c:9a Applying site-specific override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group>', interface '<Interface name>'
*apfMsConnTask_3: Mar 09 10:48:08.277: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan <Mangement VLAN>

*apfMsConnTask_3: Mar 09 10:48:08.277: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a Set Clinet Non AP specific apfMsAccessVlan = <wireless VLAN>
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a processSsidIE  statusCode is 0 and status is 0
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a processSsidIE  ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a STA - rates (8): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a suppRates  statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_3: Mar 09 10:48:08.278: b4:ae:2b:ed:2c:9a STA - rates (12): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 09 10:48:08.279: b4:ae:2b:ed:2c:9a extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1
*apfMsConnTask_3: Mar 09 10:48:08.287: RSNIE in Assoc. Req.: (20)

*apfMsConnTask_3: Mar 09 10:48:08.289:      [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_3: Mar 09 10:48:08.289:      [0016] ac 01 00 00

*apfMsConnTask_3: Mar 09 10:48:08.289: b4:ae:2b:ed:2c:9a Processing RSN IE type 48, length 20 for mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 09 10:48:08.289: b4:ae:2b:ed:2c:9a Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_3: Mar 09 10:48:08.290: b4:ae:2b:ed:2c:9a RSN Capabilities:  0
*apfMsConnTask_3: Mar 09 10:48:08.292: b4:ae:2b:ed:2c:9a apfValidateDot11iCapabilities:1286 Received RSNIE with Capabilities with STA MFPC: 0, STA MFPR:0, & AP MFPC:0MFPR:0
*apfMsConnTask_3: Mar 09 10:48:08.292: b4:ae:2b:ed:2c:9a Marking Mobile as non-11w Capable
*apfMsConnTask_3: Mar 09 10:48:08.292: b4:ae:2b:ed:2c:9a Received RSN IE with 0 PMKIDs from mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 09 10:48:08.294: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 09 10:48:08.294: b4:ae:2b:ed:2c:9a Removing BSSID 80:e8:6f:1e:da:80 from PMKID cache of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 09 10:48:08.295: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 09 10:48:08.295: b4:ae:2b:ed:2c:9a Setting active key cache index 0 ---> 8
*apfMsConnTask_3: Mar 09 10:48:08.295: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*apfMsConnTask_3: Mar 09 10:48:08.295: b4:ae:2b:ed:2c:9a apfValidateDot11wGroupMgmtCipher:1716, Received NULL 11w Group Mgmt Cipher Suite for STA, hence returning

*apfMsConnTask_3: Mar 09 10:48:08.299: b4:ae:2b:ed:2c:9a AID 1 in Assoc Req from flex AP 80:e8:6f:1e:da:80 is same as in mscb b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 09 10:48:08.299: b4:ae:2b:ed:2c:9a apfMsRunStateDec
*apfMsConnTask_3: Mar 09 10:48:08.299: b4:ae:2b:ed:2c:9a apfMs1xStateDec
*apfMsConnTask_3: Mar 09 10:48:08.301: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Mar 09 10:48:08.304: b4:ae:2b:ed:2c:9a pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_3: Mar 09 10:48:08.304: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> START (0) Initializing policy
*apfMsConnTask_3: Mar 09 10:48:08.305: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_3: Mar 09 10:48:08.307: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_3: Mar 09 10:48:08.307: b4:ae:2b:ed:2c:9a Encryption policy is set to 0x80000001
*apfMsConnTask_3: Mar 09 10:48:08.307: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> 8021X_REQD (3) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*apfMsConnTask_3: Mar 09 10:48:08.307: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*apfMsConnTask_3: Mar 09 10:48:08.308: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*apfMsConnTask_3: Mar 09 10:48:08.308: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*apfMsConnTask_3: Mar 09 10:48:08.309: b4:ae:2b:ed:2c:9a apfPemAddUser2 (apf_policy.c:352) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*apfMsConnTask_3: Mar 09 10:48:08.309: b4:ae:2b:ed:2c:9a apfPemAddUser2:session timeout forstation b4:ae:2b:ed:2c:9a - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0
*apfMsConnTask_3: Mar 09 10:48:08.314: b4:ae:2b:ed:2c:9a Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_3: Mar 09 10:48:08.315: b4:ae:2b:ed:2c:9a Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_3: Mar 09 10:48:08.319: b4:ae:2b:ed:2c:9a Sending assoc-resp with status 0 station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 on apVapId 1
*apfMsConnTask_3: Mar 09 10:48:08.319: b4:ae:2b:ed:2c:9a Sending Assoc Response to station on BSSID 80:e8:6f:1e:da:80 (status 0) ApVapId 1 Slot 0
*apfMsConnTask_3: Mar 09 10:48:08.319: b4:ae:2b:ed:2c:9a apfProcessAssocReq (apf_80211.c:9463) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.324: b4:ae:2b:ed:2c:9a Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.324: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.324: b4:ae:2b:ed:2c:9a Received EAPOL START from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.328: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.328: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 9)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.328: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 1 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:85
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.328: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.328: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 10)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.328: b4:ae:2b:ed:2c:9a reauth_sm state transition 1 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:92
*spamApTask7: Mar 09 10:48:08.330: b4:ae:2b:ed:2c:9a Sent 1x initiate message to multi thread task for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.330: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.330: b4:ae:2b:ed:2c:9a EAP-PARAM Debug - eap-params for Wlan-Id :80 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.330: b4:ae:2b:ed:2c:9a Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.330: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.330: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 1)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.339: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.339: b4:ae:2b:ed:2c:9a Received Identity Response (count=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.339: b4:ae:2b:ed:2c:9a Resetting reauth count 1 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.339: b4:ae:2b:ed:2c:9a EAP State update from Connecting to Authenticating for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.339: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticating state
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.339: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.351: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.351: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=2) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.351: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 2)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.352: b4:ae:2b:ed:2c:9a Allocating EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.358: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.358: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 2, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.358: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.358: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.359: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.359: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=3) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.359: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 3)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.359: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.368: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.368: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 3, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.368: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.368: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.374: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.374: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=6) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.374: b4:ae:2b:ed:2c:9a WARNING: updated EAP-Identifier 3 ===> 6 for STA b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.374: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 6)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.374: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.379: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.379: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 6, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.379: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.379: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.381: b4:ae:2b:ed:2c:9a Processing Access-Accept for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.383: b4:ae:2b:ed:2c:9a Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.383: b4:ae:2b:ed:2c:9a Resetting web IPv4 Flex acl from 65535 to 65535

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.383: b4:ae:2b:ed:2c:9a Setting re-auth timeout to 1800 seconds, got from WLAN config.
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.383: b4:ae:2b:ed:2c:9a Station b4:ae:2b:ed:2c:9a setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a Creating a PKC PMKID Cache entry for station b4:ae:2b:ed:2c:9a (RSN 2)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a Adding BSSID 80:e8:6f:1e:da:80 to PMKID cache at index 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: New PMKID: (16)

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385:      [0000] 44 05 d9 b3 19 28 8c 9f 36 83 95 cb c2 e2 b9 fd

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a Disabling re-auth since PMK lifetime can take care of same.
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a PMK: Sending cache delete
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.385: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.387: b4:ae:2b:ed:2c:9a Zeroize AAA Overrides from local for station
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.387: b4:ae:2b:ed:2c:9a 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.387: b4:ae:2b:ed:2c:9a PMK sent to mobility group
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.387: b4:ae:2b:ed:2c:9a Sending EAP-Success to mobile b4:ae:2b:ed:2c:9a (EAP Id 6)
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.393: b4:ae:2b:ed:2c:9a Freeing AAACB from Dot1xCB as AAA auth is done for  mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.393: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.393: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.397: Including PMKID in M1  (16)

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.401:      [0000] 44 05 d9 b3 19 28 8c 9f 36 83 95 cb c2 e2 b9 fd

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.401: b4:ae:2b:ed:2c:9a Starting key exchange to mobile b4:ae:2b:ed:2c:9a, data packets will be dropped
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.401: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.406: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.407: b4:ae:2b:ed:2c:9a Entering Backend Auth Success state (id=6) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.407: b4:ae:2b:ed:2c:9a Received Auth Success while in Authenticating state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.407: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticated state
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.411: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.414: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.414: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTK_START state (message 2) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.414: b4:ae:2b:ed:2c:9a Dumping RSNIE received in Association request:
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.415: 00000000: 30 14 01 00 00 0f ac 04  01 00 00 0f ac 04 01 00  0...............
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.415: 00000010: 00 0f ac 01 00 00                                 ......
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: b4:ae:2b:ed:2c:9a Dumping RSNIE received in EAPOL M2 :
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: 00000000: 01 00 00 0f ac 04 01 00  00 0f ac 04 01 00 00 0f  ................
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: 00000010: ac 01 00 00                                       ....
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: b4:ae:2b:ed:2c:9a PMK: Sending cache add
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.416: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Freeing EAP Retransmit Bufer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a apfMs1xStateInc
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a apfMsPeapSimReqSuccessCntInc
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> L2AUTHCOMPLETE (4) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a apfMsRunStateInc
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.420: b4:ae:2b:ed:2c:9a <valid wireless VLAN IP> RUN (20) Reached PLUMBFASTPATH: from line 6649
*Dot1x_NW_MsgTask_2: Mar 09 10:48:08.427: b4:ae:2b:ed:2c:9a Accounting NAI-Realm: host/<laptop host name>, from Mscb username : host/<laptop host name>
*DHCP Socket Task: Mar 09 10:48:08.486: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:48:08.486: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:48:08.486: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:48:12.316: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:48:12.316: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:48:12.316: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:48:17.167: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:48:17.167: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:48:17.167: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:48:24.290: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:48:24.290: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:48:24.290: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:48:41.192: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:48:41.192: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:48:41.192: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:49:12.569: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:49:12.569: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:49:12.569: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:49:16.269: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:49:16.269: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:49:16.269: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:49:35.557: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:49:35.558: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:49:35.558: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:49:40.552: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:49:40.552: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:49:40.552: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:49:45.315: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:49:45.315: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:49:45.315: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:49:54.226: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:49:54.227: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:49:54.227: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:50:10.467: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:50:10.467: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:50:10.467: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:50:43.398: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:50:43.398: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:50:43.398: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:50:47.713: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:50:47.713: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:50:47.713: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:50:55.572: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:50:55.572: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:50:55.572: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 09 10:51:11.567: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,Vlan <Mangement VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 09 10:51:11.567: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 09 10:51:11.567: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
travisryanAuthor Commented:
The virtual switch port in vSphere is set up correctly I believe, Promiscuous mode is enabled, MAC address changes are set to Accept and Forged transmits are set to Accept.
Craig BeckCommented:
You're chasing a red herring with the vWLC switchport config.  When the AP is in FlexConnect mode the traffic from the client never goes to the WLC.  The DHCP request will fall straight out of the AP's switchport onto the wired network and will follow exactly the same traffic path as a wired client.  Therefore the test would be to put a switchport on the Wireless VLAN and see if a client can get an IP address on the wire.  If not, it's not the wireless config.
travisryanAuthor Commented:
Craig, I know putting a port on my wireless VLAN then plugging something in will work because I have a few ports already set up that way with my consumer grade APs. I am grasping at straws because I have all of the DHCP debug information but I don't know how to interpret it and can't find a good guide. The only thing I've been able to find is how to turn the debugging on, not interpret it.
travisryanAuthor Commented:
Below is my debug log after specifically enabling dhcp messages and dhcp packet debugging.

The line: *DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00) is concerning to me because it makes think that DHCP is being requested on the MGMT VLAN which it should not be. I've read and it was explained to me that the VLC can be on one vlan and request DHCP from another VLAN.

(Cisco Controller) >debug dhcp message enable

(Cisco Controller) >debug dhcp packet enable

(Cisco Controller) >*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Processing assoc-req station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 thread:548c7a0
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Association received from mobile on BSSID 80:e8:6f:1e:da:40 AP AP80e0.1dfe.311b
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Global 200 Clients are allowed to AP radio

*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Max Client Trap Threshold: 0  cur: 0

*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a override for default ap group, marking intgrp NULL
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access vlan <WLESS VLAN>

*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a In processSsidIE:5733 setting Central switched to FALSE
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Set Clinet MSCB as Central Association Disabled
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Setting the NAS Id to WLAN specific Id '<AP name>'
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Applying site-specific Local Bridging override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group>', interface '<interface name>'
*apfMsConnTask_3: Mar 10 17:01:10.285: b4:ae:2b:ed:2c:9a Applying Local Bridging Interface Policy for station b4:ae:2b:ed:2c:9a - vlan <WLESS VLAN>, interface id 5, interface '<interface name>'
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a override from ap group, removing intf group from mscb
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Applying site-specific override for station b4:ae:2b:ed:2c:9a - vapId 80, site '<AP group>', interface '<interface name>'
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access vlan <MGMT VLAN>

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2399)
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Set Clinet Non AP specific apfMsAccessVlan = <WLESS VLAN>
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a processSsidIE  statusCode is 0 and status is 0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a processSsidIE  ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a STA - rates (8): 2 4 11 22 12 18 24 36 0 0 0 0 0 0 0 0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a suppRates  statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a STA - rates (12): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1
*apfMsConnTask_3: Mar 10 17:01:10.286: RSNIE in Assoc. Req.: (20)

*apfMsConnTask_3: Mar 10 17:01:10.286:      [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_3: Mar 10 17:01:10.286:      [0016] ac 01 00 00

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Processing RSN IE type 48, length 20 for mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a RSN Capabilities:  0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfValidateDot11iCapabilities:1286 Received RSNIE with Capabilities with STA MFPC: 0, STA MFPR:0, & AP MFPC:0MFPR:0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Marking Mobile as non-11w Capable
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Received RSN IE with 0 PMKIDs from mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:8f in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Removing BSSID 80:e8:6f:1e:da:8f from PMKID cache of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Setting active key cache index 0 ---> 8
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfValidateDot11wGroupMgmtCipher:1716, Received NULL 11w Group Mgmt Cipher Suite for STA, hence returning

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Deleted mobile LWAPP rule on AP [80:e8:6f:1e:da:80]
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Updated location for station old AP 80:e8:6f:1e:da:80-1, new AP 80:e8:6f:1e:da:80-0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Updating AID for REAP AP Client 80:e8:6f:1e:da:80 - AID ===> 1
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfMsRunStateDec
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfMs1xStateDec
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> START (0) Initializing policy
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Encryption policy is set to 0x80000001
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> 8021X_REQD (3) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfPemAddUser2 (apf_policy.c:352) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfPemAddUser2:session timeout forstation b4:ae:2b:ed:2c:9a - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Sending assoc-resp with status 0 station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-00 on apVapId 1
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a Sending Assoc Response to station on BSSID 80:e8:6f:1e:da:80 (status 0) ApVapId 1 Slot 0
*apfMsConnTask_3: Mar 10 17:01:10.286: b4:ae:2b:ed:2c:9a apfProcessAssocReq (apf_80211.c:9463) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*spamApTask7: Mar 10 17:01:10.296: b4:ae:2b:ed:2c:9a Sent 1x initiate message to multi thread task for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.296: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.296: b4:ae:2b:ed:2c:9a EAP-PARAM Debug - eap-params for Wlan-Id :80 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.296: b4:ae:2b:ed:2c:9a Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.296: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.296: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 1)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.305: b4:ae:2b:ed:2c:9a Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.305: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.305: b4:ae:2b:ed:2c:9a Received EAPOL START from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.305: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.305: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 2)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.305: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.310: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.310: b4:ae:2b:ed:2c:9a Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.310: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a Received Identity Response (count=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a Resetting reauth count 1 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a EAP State update from Connecting to Authenticating for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticating state
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.312: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.316: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.316: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.316: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=3) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.316: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 3)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.316: b4:ae:2b:ed:2c:9a Allocating EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.316: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.321: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.321: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 3, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.321: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.321: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.321: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.321: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.323: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.323: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.323: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=4) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.323: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 4)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.323: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.323: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.329: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.329: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 4, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.329: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.329: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.329: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.329: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a WARNING: updated EAP-Identifier 4 ===> 7 for STA b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.336: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.342: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.342: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 7, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.342: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.342: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.342: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.342: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Processing Access-Accept for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Resetting web IPv4 Flex acl from 65535 to 65535

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Setting re-auth timeout to 1800 seconds, got from WLAN config.
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Station b4:ae:2b:ed:2c:9a setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Creating a PKC PMKID Cache entry for station b4:ae:2b:ed:2c:9a (RSN 2)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Adding BSSID 80:e8:6f:1e:da:80 to PMKID cache at index 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: New PMKID: (16)

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344:      [0000] e0 d4 f7 3b 06 43 03 d4 d8 50 a7 e1 b5 bd b3 c9

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Disabling re-auth since PMK lifetime can take care of same.
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a PMK: Sending cache delete
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Zeroize AAA Overrides from local for station
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a PMK sent to mobility group
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Sending EAP-Success to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Freeing AAACB from Dot1xCB as AAA auth is done for  mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:80 in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: Including PMKID in M1  (16)

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344:      [0000] e0 d4 f7 3b 06 43 03 d4 d8 50 a7 e1 b5 bd b3 c9

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Starting key exchange to mobile b4:ae:2b:ed:2c:9a, data packets will be dropped
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Entering Backend Auth Success state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a Received Auth Success while in Authenticating state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.344: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticated state
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTK_START state (message 2) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Dumping RSNIE received in Association request:
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: 00000000: 30 14 01 00 00 0f ac 04  01 00 00 0f ac 04 01 00  0...............
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: 00000010: 00 0f ac 01 00 00                                 ......
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Dumping RSNIE received in EAPOL M2 :
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: 00000000: 01 00 00 0f ac 04 01 00  00 0f ac 04 01 00 00 0f  ................
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: 00000010: ac 01 00 00                                       ....
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a PMK: Sending cache add
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.352: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.353: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Freeing EAP Retransmit Bufer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a apfMs1xStateInc
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a apfMsPeapSimReqSuccessCntInc
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> L2AUTHCOMPLETE (4) DHCP required on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1for this client
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId 80 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a apfMsRunStateInc
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a <valid WLESS VLAN IP> RUN (20) Reached PLUMBFASTPATH: from line 6649
*Dot1x_NW_MsgTask_2: Mar 10 17:01:10.362: b4:ae:2b:ed:2c:9a Accounting NAI-Realm: host/<laptop host name>, from Mscb username : host/<laptop host name>
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:01:10.383: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:01:14.250: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:01:19.104: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:01:27.032: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:01:27.033: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:01:43.544: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:02:16.260: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop host name> (len 11)
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
*DHCP Socket Task: Mar 10 17:02:20.885: b4:ae:2b:ed:2c:9a DHCP dropping looped REQUEST from DS (encap type 0xec00)
travisryanAuthor Commented:
At this point I'm going to switch the management interface over to the wireless VLAN to see if that makes a difference. I'm not sure if this is some kind of helper-address type issue and I'd like to eventually have all of my access devices on the management VLAN and not the wireless VLAN but I need to make some progress on this project.
travisryanAuthor Commented:
I was not able to get the management interface changed to the Wireless VLAN. I filled in the holes of flexconnect settings and I'm still at the same point. I can get a laptop to connect to the access point, but I cannot get the controller to talk to the DHCP server.

Any help at this point is appreciated.
travisryanAuthor Commented:
Here's the debug log after the Flexconnect changes:

*apfMsConnTask_3: Mar 15 16:10:53.759: b4:ae:2b:ed:2c:9a Processing assoc-req station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-01 thread:548c7a0
*apfMsConnTask_3: Mar 15 16:10:53.759: b4:ae:2b:ed:2c:9a Association received from mobile on BSSID 80:e8:6f:1e:da:40 AP AP80e0.1dfe.311b
*apfMsConnTask_3: Mar 15 16:10:53.760: b4:ae:2b:ed:2c:9a Global 200 Clients are allowed to AP radio

*apfMsConnTask_3: Mar 15 16:10:53.760: b4:ae:2b:ed:2c:9a Max Client Trap Threshold: 0  cur: 1

*apfMsConnTask_3: Mar 15 16:10:53.760: b4:ae:2b:ed:2c:9a Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_3: Mar 15 16:10:53.760: b4:ae:2b:ed:2c:9a override for default ap group, marking intgrp NULL
*apfMsConnTask_3: Mar 15 16:10:53.760: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan <WLESS VLAN>

*apfMsConnTask_3: Mar 15 16:10:53.760: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a <valid WLESS IP> RUN (20) Changing IPv4 ACL 'Allow_All' (ACL ID 0) ===> 'Allow_All' (ACL ID 0) --- (caller apf_policy.c:2605)
*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a <valid WLESS IP> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a In processSsidIE:5733 setting Central switched to FALSE
*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a Set Clinet MSCB as Central Association Disabled
*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a Setting the NAS Id to WLAN specific Id '<system name>'
*apfMsConnTask_3: Mar 15 16:10:53.761: b4:ae:2b:ed:2c:9a Applying site-specific Local Bridging override for station b4:ae:2b:ed:2c:9a - vapId <WLESS VLAN>, site '<AP Group>', interface 'management'
*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a Applying Local Bridging Interface Policy for station b4:ae:2b:ed:2c:9a - vlan <MGMT VLAN>, interface id 0, interface 'management'
*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a override from ap group, removing intf group from mscb
*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a Applying site-specific override for station b4:ae:2b:ed:2c:9a - vapId <WLESS VLAN>, site '<AP Group>', interface 'management'
*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a Applying Interface policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access vlan <MGMT VLAN>

*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a Re-applying interface policy for client

*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a <valid WLESS IP> RUN (20) Changing IPv4 ACL 'Allow_All' (ACL ID 0) ===> 'Allow_All' (ACL ID 0) --- (caller apf_policy.c:2605)
*apfMsConnTask_3: Mar 15 16:10:53.762: b4:ae:2b:ed:2c:9a <valid WLESS IP> RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2420)
*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a Set Clinet Non AP specific apfMsAccessVlan = <WLess VLAN>
*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a processSsidIE  statusCode is 0 and status is 0
*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a processSsidIE  ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a STA - rates (8): 12 18 24 36 48 72 96 108 0 0 0 0 0 0 0 0
*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a suppRates  statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_3: Mar 15 16:10:53.763: RSNIE in Assoc. Req.: (20)

*apfMsConnTask_3: Mar 15 16:10:53.763:      [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_3: Mar 15 16:10:53.763:      [0016] ac 01 00 00

*apfMsConnTask_3: Mar 15 16:10:53.763: b4:ae:2b:ed:2c:9a Processing RSN IE type 48, length 20 for mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a RSN Capabilities:  0
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a apfValidateDot11iCapabilities:1286 Received RSNIE with Capabilities with STA MFPC: 0, STA MFPR:0, & AP MFPC:0MFPR:0
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Marking Mobile as non-11w Capable
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Received RSN IE with 0 PMKIDs from mobile b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:8f in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Removing BSSID 80:e8:6f:1e:da:8f from PMKID cache of station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a Setting active key cache index 0 ---> 8
*apfMsConnTask_3: Mar 15 16:10:53.764: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*apfMsConnTask_3: Mar 15 16:10:53.765: b4:ae:2b:ed:2c:9a apfValidateDot11wGroupMgmtCipher:1716, Received NULL 11w Group Mgmt Cipher Suite for STA, hence returning

*apfMsConnTask_3: Mar 15 16:10:53.765: b4:ae:2b:ed:2c:9a AID 1 in Assoc Req from flex AP 80:e8:6f:1e:da:80 is same as in mscb b4:ae:2b:ed:2c:9a
*apfMsConnTask_3: Mar 15 16:10:53.765: b4:ae:2b:ed:2c:9a apfMsRunStateDec
*apfMsConnTask_3: Mar 15 16:10:53.765: b4:ae:2b:ed:2c:9a apfMs1xStateDec
*apfMsConnTask_3: Mar 15 16:10:53.765: b4:ae:2b:ed:2c:9a <valid WLESS IP> RUN (20) Change state to START (0) last state RUN (20)

*apfMsConnTask_3: Mar 15 16:10:53.765: b4:ae:2b:ed:2c:9a pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a <valid WLESS IP> START (0) Initializing policy
*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a <valid WLESS IP> START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a <valid WLESS IP> AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a Encryption policy is set to 0x80000001
*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a <valid WLESS IP> 8021X_REQD (3) DHCP required on AP 80:e8:6f:1e:da:80 vapId <WLESS VLAN> apVapId 1for this client
*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*apfMsConnTask_3: Mar 15 16:10:53.766: b4:ae:2b:ed:2c:9a <valid WLESS IP> 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId <WLESS VLAN> apVapId 1 flex-acl-name:
*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a apfPemAddUser2 (apf_policy.c:352) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a apfPemAddUser2:session timeout forstation b4:ae:2b:ed:2c:9a - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0
*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a Sending assoc-resp with status 0 station:b4:ae:2b:ed:2c:9a AP:80:e8:6f:1e:da:80-01 on apVapId 1
*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a Sending Assoc Response to station on BSSID 80:e8:6f:1e:da:8f (status 0) ApVapId 1 Slot 1
*apfMsConnTask_3: Mar 15 16:10:53.767: b4:ae:2b:ed:2c:9a apfProcessAssocReq (apf_80211.c:9463) Changing state for mobile b4:ae:2b:ed:2c:9a on AP 80:e8:6f:1e:da:80 from Associated to Associated

*spamApTask0: Mar 15 16:10:53.770: b4:ae:2b:ed:2c:9a Sent 1x initiate message to multi thread task for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.770: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.770: b4:ae:2b:ed:2c:9a EAP-PARAM Debug - eap-params for Wlan-Id :80 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.770: b4:ae:2b:ed:2c:9a Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.770: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.770: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 1)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.776: b4:ae:2b:ed:2c:9a Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.776: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.776: b4:ae:2b:ed:2c:9a Received EAPOL START from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.776: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Connecting state
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.776: b4:ae:2b:ed:2c:9a Sending EAP-Request/Identity to mobile b4:ae:2b:ed:2c:9a (EAP Id 2)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.776: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.779: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.779: b4:ae:2b:ed:2c:9a Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.779: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a Received Identity Response (count=1) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a Resetting reauth count 1 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a EAP State update from Connecting to Authenticating for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticating state
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.782: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.786: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.786: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.786: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=3) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.786: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 3)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.786: b4:ae:2b:ed:2c:9a Allocating EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.786: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.788: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.788: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 3, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.789: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.789: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.789: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.789: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.790: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.790: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.790: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=4) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.790: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 4)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.790: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.790: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.794: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.794: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 4, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.794: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.794: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.794: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.794: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a Processing Access-Challenge for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a Entering Backend Auth Req state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a WARNING: updated EAP-Identifier 4 ===> 7 for STA b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a Sending EAP Request from AAA to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.800: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.802: b4:ae:2b:ed:2c:9a Received EAPOL EAPPKT from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.802: b4:ae:2b:ed:2c:9a Received EAP Response from mobile b4:ae:2b:ed:2c:9a (EAP Id 7, EAP Type 25)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.802: b4:ae:2b:ed:2c:9a Resetting reauth count 0 to 0 for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.802: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.802: b4:ae:2b:ed:2c:9a Entering Backend Auth Response state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.802: b4:ae:2b:ed:2c:9a reauth_sm state transition 0 ---> 0 for mobile b4:ae:2b:ed:2c:9a at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Processing Access-Accept for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Resetting web IPv4 acl from 255 to 255

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Resetting web IPv4 Flex acl from 65535 to 65535

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Setting re-auth timeout to 1800 seconds, got from WLAN config.
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Station b4:ae:2b:ed:2c:9a setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Creating a PKC PMKID Cache entry for station b4:ae:2b:ed:2c:9a (RSN 2)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Resetting MSCB PMK Cache Entry 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Adding BSSID 80:e8:6f:1e:da:8f to PMKID cache at index 0 for station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: New PMKID: (16)

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805:      [0000] 1a e7 7d 66 84 7b 52 1d 4d 1f 43 07 34 c0 83 22

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Disabling re-auth since PMK lifetime can take care of same.
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a PMK: Sending cache delete
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Zeroize AAA Overrides from local for station
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a PMK sent to mobility group
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Sending EAP-Success to mobile b4:ae:2b:ed:2c:9a (EAP Id 7)
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Freeing AAACB from Dot1xCB as AAA auth is done for  mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:8f in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Found an cache entry for BSSID 80:e8:6f:1e:da:8f in PMKID cache at index 0 of station b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: Including PMKID in M1  (16)

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805:      [0000] 1a e7 7d 66 84 7b 52 1d 4d 1f 43 07 34 c0 83 22

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Starting key exchange to mobile b4:ae:2b:ed:2c:9a, data packets will be dropped
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Entering Backend Auth Success state (id=7) for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a Received Auth Success while in Authenticating state for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.805: b4:ae:2b:ed:2c:9a dot1x - moving mobile b4:ae:2b:ed:2c:9a into Authenticated state
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTK_START state (message 2) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: b4:ae:2b:ed:2c:9a Dumping RSNIE received in Association request:
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: 00000000: 30 14 01 00 00 0f ac 04  01 00 00 0f ac 04 01 00  0...............
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: 00000010: 00 0f ac 01 00 00                                 ......
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.809: b4:ae:2b:ed:2c:9a Dumping RSNIE received in EAPOL M2 :
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.810: 00000000: 01 00 00 0f ac 04 01 00  00 0f ac 04 01 00 00 0f  ................
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.810: 00000010: ac 01 00 00                                       ....
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.810: b4:ae:2b:ed:2c:9a PMK: Sending cache add
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.810: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.810: b4:ae:2b:ed:2c:9a Sending EAPOL-Key Message to mobile b4:ae:2b:ed:2c:9a
                                                                                                                    state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.810: b4:ae:2b:ed:2c:9a Reusing allocated memory for  EAP Pkt for retransmission to mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Received EAPOL-Key from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Stopping retransmission timer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Freeing EAP Retransmit Bufer for mobile b4:ae:2b:ed:2c:9a
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a apfMs1xStateInc
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a apfMsPeapSimReqSuccessCntInc
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a <valid WLESS IP> 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a <valid WLESS IP> L2AUTHCOMPLETE (4) DHCP required on AP 80:e8:6f:1e:da:80 vapId <WLESS VLAN> apVapId 1for this client
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Sending 11w Flag 0 for Client B4:AE:2B:ED:2C:9A
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a <valid WLESS IP> L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 80:e8:6f:1e:da:80 vapId <WLESS VLAN> apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a apfMsRunStateInc
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a <valid WLESS IP> L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a <valid WLESS IP> RUN (20) Reached PLUMBFASTPATH: from line 6649
*Dot1x_NW_MsgTask_2: Mar 15 16:10:53.812: b4:ae:2b:ed:2c:9a Accounting NAI-Realm: host/<laptop name>, from Mscb username : host/<laptop name>
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP received op BOOTREQUEST (1) (len 308,vlan <MGMT VLAN>, port 1, encap 0xec00)
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP option len (including the magic cookie) 72
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP option: message type = DHCP DISCOVER
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP option: 61 (len 7) - skipping
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP option: hostname = <laptop name> (len 11)
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP option: vendor class id = MSFT 5.0 (len 8)
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP option: 55 (len 13) - skipping
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP options end, len 72, actual 64
*DHCP Socket Task: Mar 15 16:10:53.826: b4:ae:2b:ed:2c:9a DHCP (encap type 0xec00) mstype 0ff:ff:ff:ff:ff:ff
Craig BeckCommented:
Let's review what we have...

FlexConnect AP connected to a trunk port.
Trunk port allows management and Wireless VLANs.
Native VLAN is management.
AP is configured for FlexConnect.
AP has VLAN mappings configured on correct VLANs for the Wireless SSID.
SSID is configured for FlexConnect.
DHCP server is on Wireless VLAN.

That bit right so far?
travisryanAuthor Commented:
All correct
travisryanAuthor Commented:
I've decided to screenshot and sanitize my controller in order to help troubleshoot this issue.
vWLC_16_1MOD.jpg
vWLC_16_2MOD.jpg
vWLC_16_3MOD.jpg
vWLC_16_3-5MOD.jpg
vWLC_16_4MOD.jpg
travisryanAuthor Commented:
travisryanAuthor Commented:
Craig BeckCommented:
On the AP's switchport you have the native VLAN I'D set to the Wireless VLAN?
travisryanAuthor Commented:
Which screenshot are you referring to?
Craig BeckCommented:
16_7
travisryanAuthor Commented:
The native VLAN on Flexconnect AP, I guess it would make sense for it to be on the MGMT VLAN and not the wireless VLAN. It's very confusing what parts of the config need to be set on the VLAN for the APs and what parts of the config need to be set for the VLAN of the IP addresses the APs will hand out.
Craig BeckCommented:
I would put the APs on the WLC's management VLAN.  You can do it either way, but it makes things easier here if the APs are in the same L2 segment as the WLC.  It's not always that simple, but you have the WLC and APs connected to the same switch by the sound of it, so it's ok.

The real issue is putting clients on the same VLAN as the APs.  Again, you could do that, but then there's no point in using FlexConnect's VLAN Tagging option.

So, decide whether you want the APs on the same VLAN as the wireless clients first, then configure to suit.  If you want the clients on the same VLAN, just disable VLAN Support in 16_7 and let everything go out on whatever VLAN is configured on the switchport.  It goes without saying though that if you don't use VLAN Support, the switchport should be configured as an access port rather than a trunk.

Experts Exchange Solution brought to you by

Your issues matter to us.

Facing a tech roadblock? Get the help and guidance you need from experienced professionals who care. Ask your question anytime, anywhere, with no hassle.

Start your 7-day free trial
travisryanAuthor Commented:
I'd like the AP and the WLC on my management VLAN but I need the addresses it hands out to be on the wireless VLAN. What on the screenshots I've posted do you suggest I change?
Craig BeckCommented:
16_7 needs to be your management VLAN.

The switchport needs to have the native VLAN set to the management VLAN.
travisryanAuthor Commented:
I just switched everything over to my mgmt vlan, only setting the DHCP overide to my Wireless VLAN DHCP server because I'm sure where I specify that the addresses I want the AP to hand out are on the Wireless VLAN. (Advanced Tab on the WLAN edit screen).

Also, when I set the switchport to native trunk (mgmt VLAN) vlan, I can't get to my controller any more so I un-applied that change quickly.

Right now I'm fighting to get the SSID to show up, last time I changed the SSID (even after apply the changes and saving the config and rebooting the vWLC) I had to reboot the AP at least once to get it to show up.

Now I've rebooted the AP twice and the SSID still hasn't shown up. And I'm making sure I have the "Broadcast SSID" box checked.
travisryanAuthor Commented:
I had to put the AP in "FlexConnect" mode eventhough I'm trying a config with no FlexConnect. It's very confusing vWLC forces you to use that even when you're not using FlexConnect. Ultimately I want to use FlexConnect but I'm testing the vWLC without FlexConnect to see if configuring the AP without FlexConnect works.
Craig BeckCommented:
If you don't put the AP in FlexConnect mode it won't advertise any SSIDs.

What exactly did you change when the controller became inaccessible? You should only change the AP's port, not the vWLC's.
travisryanAuthor Commented:
Craig, I've been pulled away from this for a while. i got my laptop to connect that day and I got the correct VLAN, but now it won't connect again. When I have time to put eyes on this again I will.
It's more than this solution.Get answers and train to solve all your tech problems - anytime, anywhere.Try it for free Edge Out The Competitionfor your dream job with proven skills and certifications.Get started today Stand Outas the employee with proven skills.Start learning today for free Move Your Career Forwardwith certification training in the latest technologies.Start your trial today
Cisco

From novice to tech pro — start learning today.