Windows 8 clients can't associate to Cisco Unified Wireless

Document

Oct 4, 2012 4:22 PM
Oct 4th, 2012

The problem - Windows 8 clients can't associate to CUWN

Windows 8 wireless clients can encounter a problem when trying to associate to the Cisco Unified Wireless Network.  If the client is using WPA or WPA2 key management with AES encryption, then the pairwise key exchange may fail.  With "debug client" in effect on the Wireless LAN Controller, a message similar to the following is seen:

*dot1xMsgTask: Jun 12 20:23:37.471: 00:11:22:33:44:55 Retransmit failure for
EAPOL-Key M1 to mobile 00:11:22:33:44:55, retransmit count 5, mscb deauth count 0

This is the Cisco bug CSCua29504.  This problem is also documented as Microsoft Support Article ID 2749073.

The solution: upgrade WLC software

This bug is fixed in the following releases of WLC software, which are available to download from Cisco.com now:

7.3.101.0 (release notes)

7.2.111.3 (release notes) (the CSCua29504 fix was lost in 7.2.115.1, but is restored in 7.2.115.2)

7.0.235.3 (release notes)

For more information on Windows 8 and 802.11w

See: Get your Wi-Fi network ready for Windows 8

Average Rating: 5 (6 ratings)

Comments

Amjad Abdullah Sat, 11/10/2012 - 22:22

Thanks Aaron. But we are always afraid with new technology because it almost always has something to contradict with Cisco Wireless. It will be better if we just can try to bring new technologies without having to upgrade or amend anything with the WLC infrastructure, just like other Wireless vendors.

Stepheno1974 Mon, 06/10/2013 - 02:24

We have upgraded our WLAN controller to 7.4.100.0.  However, we are still seeing issues with Windows 8 clients failing to connect.  Do we need to downgrade the controller to 7.3?  We had to upgrade to 7.4 recently due to the introduction of some 2602 AP's across our estate. 

pcroak Mon, 06/10/2013 - 07:31 (reply to Stepheno1974)

Stephen,

This issue is resolved in 7.4 code as well. If you are having other connectivity issues with clients, I would recommend collecting a client debug and opening a TAC case.

-Patrick

chriscmurray@ho... Fri, 09/27/2013 - 13:56

We are also seeing a ton of Windows 8 clients not being able to connect. We are running WISM2 with version 7.4.100.0.   Are Windows 8 issues resolved in 7.4.100.0? Or are there newly discovered WIndows 8 problems?

Aaron Leonard Fri, 09/27/2013 - 14:55 (reply to chriscmurray@ho...)

Chris,

This specific issue - CSCua29504 - is definitely resolved in 7.4.100.0 - so I would expect that your Windows 8 clients are hitting some other issue.

If your Win8 clients have Intel adapters, then I understand that the just-released 16.1.5 driver greatly improves things.

If you can get the output of 'debug client <MAC>' while a given client is having problems, this would tell us more.

Aaron

chriscmurray@ho... Fri, 10/04/2013 - 11:32

Here is the log:

=~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2013.10.04 13:56:31 =~=~=~=~=~=~=~=~=~=~=~=

d

*apfMsConnTask_1: Oct 04 17:57:39.223: 9c:4e:36:71:cd:b0 Adding mobile on LWAPP AP 64:d8:14:d0:f1:a0(0)

*apfMsConnTask_1: Oct 04 17:57:39.223: 9c:4e:36:71:cd:b0 Association received from mobile on BSSID 64:d8:14:d0:f1:a0

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 Global 200 Clients are allowed to AP radio

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 Max Client Trap Threshold: 0  cur: 17

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 Rf profile 200 Clients are allowed to AP wlan

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 Assigned interface 'cu-wireless-students-2' from interface group 'cu-wireless-students-group' for the client

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 Applying Interface policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 Re-applying interface policy for client

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 In processSsidIE:4202 setting Central switched to TRUE

*apfMsConnTask_1: Oct 04 17:57:39.224: 9c:4e:36:71:cd:b0 In processSsidIE:4205 apVapId = 1 and Split Acl Id = 65535

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 Applying site-specific Local Bridging override for station 9c:4e:36:71:cd:b0 - vapId 1, site 'standard-services', interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 Applying Local Bridging Interface Policy for station 9c:4e:36:71:cd:b0 - vlan 934, interface id 15, interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 Applying site-specific override for station 9c:4e:36:71:cd:b0 - vapId 1, site 'standard-services', interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 934

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 Re-applying interface policy for client

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 processSsidIE  statusCode is 0 and status is 0

*apfMsConnTask_1: Oct 04 17:57:39.225: 9c:4e:36:71:cd:b0 processSsidIE  ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 STA - rates (8): 139 22 12 18 24 36 48 72 0 0 0 0 0 0 0 0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 suppRates  statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 STA - rates (10): 139 22 12 18 24 36 48 72 96 108 0 0 0 0 0 0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 Processing WPA IE type 221, length 24 for mobile 9c:4e:36:71:cd:b0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 Setting active key cache index 8 ---> 8

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 unsetting PmkIdValidatedByAp

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 0.0.0.0 START (0) Initializing policy

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 64:d8:14:d0:f1:a0 vapId 1 apVapId 1 flex-acl-name:

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 apfMsAssoStateInc

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 apfPemAddUser2 (apf_policy.c:276) Changing state for mobile 9c:4e:36:71:cd:b0 on AP 64:d8:14:d0:f1:a0 from Idle to Associated

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 apfPemAddUser2:session timeout forstation 9c:4e:36:71:cd:b0 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 Sending Assoc Response to station on BSSID 64:d8:14:d0:f1:a0 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_1: Oct 04 17:57:39.226: 9c:4e:36:71:cd:b0 apfProcessAssocReq (apf_80211.c:7391) Changing state for mobile 9c:4e:36:71:cd:b0 on AP 64:d8:14:d0:f1:a0 from Associated to Associated

*dot1xMsgTask: Oct 04 17:57:39.229: 9c:4e:36:71:cd:b0 Station 9c:4e:36:71:cd:b0 setting dot1x reauth timeout = 0

*dot1xMsgTask: Oct 04 17:57:39.229: 9c:4e:36:71:cd:b0 Stopping reauth timeout for 9c:4e:36:71:cd:b0

*dot1xMsgTask: Oct 04 17:57:39.229: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*dot1xMsgTask: Oct 04 17:57:39.229: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 1)

*apfMsConnTask_4: Oct 04 17:57:39.254: Stats update: Non Zero value

*apfMsConnTask_4: Oct 04 17:57:39.254: Stats update: Non Zero value

*Dot1x_NW_MsgTask_0: Oct 04 17:57:39.255: 9c:4e:36:71:cd:b0 Received EAPOL START from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:39.255: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*Dot1x_NW_MsgTask_0: Oct 04 17:57:39.255: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 2)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.352: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.352: 9c:4e:36:71:cd:b0 Received Identity Response (count=2) from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.352: 9c:4e:36:71:cd:b0 EAP State update from Connecting to Authenticating for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.352: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Authenticating state

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.352: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.354: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.354: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=66) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.354: 9c:4e:36:71:cd:b0 WARNING: updated EAP-Identifier 2 ===> 66 for STA 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.354: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 66)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.359: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.359: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 66, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.359: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.361: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.361: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=67) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.361: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 67)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.368: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.368: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 67, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.368: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.370: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.370: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=68) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.370: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 68)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.378: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.378: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 68, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.378: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.402: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.403: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=69) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.403: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 69)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.407: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.407: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 69, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.407: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.408: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.409: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=70) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.409: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 70)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.424: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.424: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 70, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.424: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*apfMsConnTask_7: Oct 04 17:57:52.464: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:52.464: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.469: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.469: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.469: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.469: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.469: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.469: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.470: Stats update: Non Zero value

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.473: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.473: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=71) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.473: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 71)

*apfMsConnTask_7: Oct 04 17:57:52.473: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:52.475: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:57:52.476: Stats update: Non Zero value

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.484: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.484: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 71, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.484: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.486: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.486: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=72) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.486: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 72)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.491: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.491: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 72, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.491: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.493: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.493: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=73) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.493: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 73)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.501: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.501: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 73, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.501: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.523: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.523: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=74) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.523: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 74)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.529: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.529: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 74, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.529: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.530: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.530: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=75) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.530: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 75)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.595: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.595: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 75, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.595: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 Processing Access-Reject for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 Sending EAP-Failure to mobile 9c:4e:36:71:cd:b0 (EAP Id 75)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 Entering Backend Auth Failure state (id=75) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 Setting quiet timer for 5 seconds for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Unknown state

*osapiBsnTimer: Oct 04 17:57:57.431: 9c:4e:36:71:cd:b0 802.1x 'quiteWhile' Timer expired for station 9c:4e:36:71:cd:b0 and for message = M0

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 quiet timer completed for mobile 9c:4e:36:71:cd:b0

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 77)

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 Reached Max EAP-Identity Request retries (3) for STA 9c:4e:36:71:cd:b0

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 Sent Deauthenticate to mobile on BSSID 64:d8:14:d0:f1:a0 slot 0(caller 1x_auth_pae.c:3241)

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 Scheduling deletion of Mobile Station:  (callerId: 6) in 10 seconds

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Disconnected state

*dot1xMsgTask: Oct 04 17:57:57.432: 9c:4e:36:71:cd:b0 Not sending EAP-Failure for STA 9c:4e:36:71:cd:b0

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 Association received from mobile on BSSID 64:d8:14:d0:f1:a0

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 Global 200 Clients are allowed to AP radio

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 Max Client Trap Threshold: 0  cur: 17

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 Rf profile 200 Clients are allowed to AP wlan

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 934

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 Re-applying interface policy for client

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 In processSsidIE:4202 setting Central switched to TRUE

*apfMsConnTask_1: Oct 04 17:57:57.739: 9c:4e:36:71:cd:b0 In processSsidIE:4205 apVapId = 1 and Split Acl Id = 65535

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Applying site-specific Local Bridging override for station 9c:4e:36:71:cd:b0 - vapId 1, site 'standard-services', interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Applying Local Bridging Interface Policy for station 9c:4e:36:71:cd:b0 - vlan 934, interface id 15, interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Applying site-specific override for station 9c:4e:36:71:cd:b0 - vapId 1, site 'standard-services', interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 934

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Re-applying interface policy for client

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 processSsidIE  statusCode is 0 and status is 0

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 processSsidIE  ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 STA - rates (8): 139 22 12 18 24 36 48 72 96 108 0 0 0 0 0 0

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 suppRates  statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 STA - rates (10): 139 22 12 18 24 36 48 72 96 108 0 0 0 0 0 0

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Processing WPA IE type 221, length 24 for mobile 9c:4e:36:71:cd:b0

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Setting active key cache index 8 ---> 8

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 unsetting PmkIdValidatedByAp

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 64:d8:14:d0:f1:a0 vapId 1 apVapId 1 flex-acl-name:

*apfMsConnTask_1: Oct 04 17:57:57.740: 9c:4e:36:71:cd:b0 apfPemAddUser2 (apf_policy.c:276) Changing state for mobile 9c:4e:36:71:cd:b0 on AP 64:d8:14:d0:f1:a0 from Associated to Associated

*apfMsConnTask_1: Oct 04 17:57:57.741: 9c:4e:36:71:cd:b0 apfPemAddUser2:session timeout forstation 9c:4e:36:71:cd:b0 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0

*apfMsConnTask_1: Oct 04 17:57:57.741: 9c:4e:36:71:cd:b0 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_1: Oct 04 17:57:57.741: 9c:4e:36:71:cd:b0 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_1: Oct 04 17:57:57.741: 9c:4e:36:71:cd:b0 Sending Assoc Response to station on BSSID 64:d8:14:d0:f1:a0 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_1: Oct 04 17:57:57.741: 9c:4e:36:71:cd:b0 apfProcessAssocReq (apf_80211.c:7391) Changing state for mobile 9c:4e:36:71:cd:b0 on AP 64:d8:14:d0:f1:a0 from Associated to Associated

*apfMsConnTask_7: Oct 04 17:57:57.742: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.742: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.742: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:57:57.743: Stats update: Non Zero value

*dot1xMsgTask: Oct 04 17:57:57.744: 9c:4e:36:71:cd:b0 Station 9c:4e:36:71:cd:b0 setting dot1x reauth timeout = 0

*dot1xMsgTask: Oct 04 17:57:57.744: 9c:4e:36:71:cd:b0 Stopping reauth timeout for 9c:4e:36:71:cd:b0

*dot1xMsgTask: Oct 04 17:57:57.744: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*dot1xMsgTask: Oct 04 17:57:57.744: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 1)

*Dot1x_NW_MsgTask_0: Oct 04 17:57:57.758: 9c:4e:36:71:cd:b0 Received EAPOL START from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:57.759: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*Dot1x_NW_MsgTask_0: Oct 04 17:57:57.759: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 2)

*apfMsConnTask_7: Oct 04 17:57:57.760: Stats update: Non Zero value

*a

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy AP LOCP - mode:0 slotId:128, apMac 0x64:d8:14:d0:f1:a0

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy WLAN LOCP EssIndex:1 aid:81 ssid:CU-Wireless

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy Security LOCP ecypher:0x1 ptype:0x1, p:0x1, eaptype:0x6 w:0x1 aalg:0x0, PMState: 8021X_REQD

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy 802.11 LOCP a:0x0 b:0x0 c:0x0 d:0x0 e:0x1 protocol2:0x3 statuscode 0, reasoncode 99, status 3

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy CCX LOCP 4

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy e2e LOCP 0x1

*apfLbsTask: Oct 04 17:58:02.642: 9c:4e:36:71:cd:b0 Copy MobilityData LOCP status:0, anchorip:0x0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.630: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.630: 9c:4e:36:71:cd:b0 Received Identity Response (count=2) from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.630: 9c:4e:36:71:cd:b0 EAP State update from Connecting to Authenticating for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.630: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Authenticating state

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.630: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.631: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.632: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=132) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.632: 9c:4e:36:71:cd:b0 WARNING: updated EAP-Identifier 2 ===> 132 for STA 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.632: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 132)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.646: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.646: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 132, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.646: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.648: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.648: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=133) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.648: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 133)

*apfMsConnTask_6: Oct 04 17:58:07.650: Stats update: Non Zero value

*apfMsConnTask_6: Oct 04 17:58:07.651: Stats update: Non Zero value

*apfMsConnTask_6: Oct 04 17:58:07.651: Stats update: Non Zero value

*apfMsConnTask_7: Oct 04 17:58:07.652: Stats update: Non Zero value

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.655: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.655: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 133, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.655: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.656: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.656: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=134) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.656: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 134)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.662: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.662: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 134, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.662: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.664: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.664: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=135) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.664: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 135)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.668: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.668: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 135, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.668: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.670: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.670: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=136) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.670: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 136)

*apfMsConnTask_1: Oct 04 17:58:07.673: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:58:07.673: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:58:07.673: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:58:07.673: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:58:07.673: Stats update: Non Zero value

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.683: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.683: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 136, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.683: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*apfMsConnTask_0: Oct 04 17:58:07.714: Stats update: Non Zero value

*apfMsConnTask_0: Oct 04 17:58:07.715: Stats update: Non Zero value

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.730: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.730: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=137) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.730: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 137)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.739: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.739: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 137, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.739: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.740: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.740: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=138) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.740: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 138)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.745: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.745: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 138, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.745: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.747: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.747: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=139) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.747: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 139)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.755: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.756: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 139, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.756: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.762: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.762: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=140) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.762: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 140)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.767: 9c:4e:36:71:cd:b0 Received EAPOL EAPPKT from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.767: 9c:4e:36:71:cd:b0 Received EAP Response from mobile 9c:4e:36:71:cd:b0 (EAP Id 140, EAP Type 25)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.767: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.769: 9c:4e:36:71:cd:b0 Processing Access-Challenge for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.769: 9c:4e:36:71:cd:b0 Entering Backend Auth Req state (id=141) for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:07.769: 9c:4e:36:71:cd:b0 Sending EAP Request from AAA to mobile 9c:4e:36:71:cd:b0 (EAP Id 141)

*apfMsConnTask_0: Oct 04 17:58:07.789: Stats update: Non Zero value

*apfMsConnTask_1: Oct 04 17:58:13.091: 9c:4e:36:71:cd:b0 Association received from mobile on BSSID 64:d8:14:d0:f1:a0

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Global 200 Clients are allowed to AP radio

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Max Client Trap Threshold: 0  cur: 18

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Rf profile 200 Clients are allowed to AP wlan

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 934

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Re-applying interface policy for client

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 In processSsidIE:4202 setting Central switched to TRUE

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 In processSsidIE:4205 apVapId = 1 and Split Acl Id = 65535

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Applying site-specific Local Bridging override for station 9c:4e:36:71:cd:b0 - vapId 1, site 'standard-services', interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Applying Local Bridging Interface Policy for station 9c:4e:36:71:cd:b0 - vlan 934, interface id 15, interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Applying site-specific override for station 9c:4e:36:71:cd:b0 - vapId 1, site 'standard-services', interface 'cu-wireless-students-2'

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 934

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 Re-applying interface policy for client

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 processSsidIE  statusCode is 0 and status is 0

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 processSsidIE  ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 STA - rates (8): 139 22 12 18 24 36 48 72 96 108 0 0 0 0 0 0

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 suppRates  statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 STA - rates (10): 139 22 12 18 24 36 48 72 96 108 0 0 0 0 0 0

*apfMsConnTask_1: Oct 04 17:58:13.092: 9c:4e:36:71:cd:b0 extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 Processing WPA IE type 221, length 24 for mobile 9c:4e:36:71:cd:b0

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 Setting active key cache index 8 ---> 8

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 unsetting PmkIdValidatedByAp

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 64:d8:14:d0:f1:a0 vapId 1 apVapId 1 flex-acl-name:

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 apfPemAddUser2 (apf_policy.c:276) Changing state for mobile 9c:4e:36:71:cd:b0 on AP 64:d8:14:d0:f1:a0 from Associated to Associated

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 apfPemAddUser2:session timeout forstation 9c:4e:36:71:cd:b0 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 Sending Assoc Response to station on BSSID 64:d8:14:d0:f1:a0 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_1: Oct 04 17:58:13.093: 9c:4e:36:71:cd:b0 apfProcessAssocReq (apf_80211.c:7391) Changing state for mobile 9c:4e:36:71:cd:b0 on AP 64:d8:14:d0:f1:a0 from Associated to Associated

*apfMsConnTask_1: Oct 04 17:58:13.094: Stats update: Non Zero value

*dot1xMsgTask: Oct 04 17:58:13.095: 9c:4e:36:71:cd:b0 Station 9c:4e:36:71:cd:b0 setting dot1x reauth timeout = 0

*dot1xMsgTask: Oct 04 17:58:13.095: 9c:4e:36:71:cd:b0 Stopping reauth timeout for 9c:4e:36:71:cd:b0

*dot1xMsgTask: Oct 04 17:58:13.095: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*dot1xMsgTask: Oct 04 17:58:13.095: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 1)

*Dot1x_NW_MsgTask_0: Oct 04 17:58:13.111: 9c:4e:36:71:cd:b0 Received EAPOL START from mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:58:13.111: 9c:4e:36:71:cd:b0 dot1x - moving mobile 9c:4e:36:71:cd:b0 into Connecting state

*Dot1x_NW_MsgTask_0: Oct 04 17:58:13.111: 9c:4e:36:71:cd:b0 Sending EAP-Request/Identity to mobile 9c:4e:36:71:cd:b0 (EAP Id 2)

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy AP LOCP - mode:0 slotId:128, apMac 0x64:d8:14:d0:f1:a0

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy WLAN LOCP EssIndex:1 aid:81 ssid:CU-Wireless

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy Security LOCP ecypher:0x1 ptype:0x1, p:0x1, eaptype:0x6 w:0x1 aalg:0x0, PMState: 8021X_REQD

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy 802.11 LOCP a:0x0 b:0x0 c:0x0 d:0x0 e:0x1 protocol2:0x3 statuscode 0, reasoncode 99, status 3

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy CCX LOCP 4

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy e2e LOCP 0x1

*apfLbsTask: Oct 04 17:58:18.647: 9c:4e:36:71:cd:b0 Copy MobilityData LOCP status:0, anchorip:0x0

Aaron Leonard Fri, 10/04/2013 - 13:01 (reply to chriscmurray@ho...)

Chris,

Looks like your problem is that your RADIUS server rejected the authentication:

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.595: 9c:4e:36:71:cd:b0 Entering Backend Auth Response state for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 Processing Access-Reject for mobile 9c:4e:36:71:cd:b0

*Dot1x_NW_MsgTask_0: Oct 04 17:57:52.598: 9c:4e:36:71:cd:b0 Sending EAP-Failure to mobile 9c:4e:36:71:cd:b0 (EAP Id 75)

After that, it looks like the client decided that its EAP credentials weren't any good (a reasonable assumption), and stopped responding to our EAP ID REQUESTS.

Check your RADIUS failure logs to find out more.

Aaron

chriscmurray@ho... Fri, 10/04/2013 - 14:49

I checked ACS. This is the log:


Oct 4,13 2:47:42.070 PM

Oct 4,13 2:47:42.046 PM

chrismurray     9c-4e-36-71-cd-b0      

CU-Wireless     PEAP (EAP-MSCHAPv2)    

DMZ1-WISM2_10.30.63.80  10.30.63.80    

           CCSACS01        12308 Client sent Result TLV indicating failure

Oct 4,13 2:47:22.660 PM

Oct 4,13 2:47:22.646 PM

chrismurray     9c-4e-36-71-cd-b0      

CU-Wireless     PEAP (EAP-MSCHAPv2)    

DMZ1-WISM2_10.30.63.80  10.30.63.80    

           CCSACS01        12308 Client sent Result TLV indicating failure

Oct 4,13 2:46:48.850 PM

Oct 4,13 2:46:48.830 PM

chrismurray     9c-4e-36-71-cd-b0      

CU-Wireless     PEAP (EAP-MSCHAPv2)    

DMZ1-WISM2_10.30.63.80  10.30.63.80    

           CCSACS01        12308 Client sent Result TLV indicating failure





Evaluating Group Mapping Policy

15004  Matched rule

11824  EAP-MSCHAP authentication attempt passed

12305  Prepared EAP-Request with another PEAP challenge

11006  Returned RADIUS Access-Challenge

11001  Received RADIUS Access-Request

11018  RADIUS is re-using an existing session

12304  Extracted EAP-Response containing PEAP challenge-response

11810  Extracted EAP-Response for inner method containing MSCHAP challenge-response

11814  Inner EAP-MSCHAP authentication succeeded

11519  Prepared EAP-Success for inner EAP method

12314  PEAP inner method finished successfully

12305  Prepared EAP-Request with another PEAP challenge

11006  Returned RADIUS Access-Challenge

11001  Received RADIUS Access-Request

11018  RADIUS is re-using an existing session

12304  Extracted EAP-Response containing PEAP challenge-response

12308  Client sent Result TLV indicating failure

12307  PEAP authentication failed

11504  Prepared EAP-Failure

11003  Returned RADIUS Access-Reject

________________________________________

Aaron Leonard Fri, 10/04/2013 - 15:15 (reply to chriscmurray@ho...)

"Client sent Result TLV indicating failure"

So there is some point very deep into the EAP negotations where the Windows 8 supplicant and ACS aren't getting along.  This is really nothing that the WLC is invovled with - it's just acting as a gateway, relaying the EAP between the EAPOL packets over the air and the RADIUS packets over the wire.  Next step would be to bring in your Microsoft support and get them talking to the ACS guys.

Best,

Aaron

mike_perry Mon, 01/27/2014 - 06:56

Was this bug re-introduced into 7.6 release??  Having issue with 7.6 release and Windows 8.1 client.

Actions

Login or Register to take actions

This Document

Posted October 4, 2012 at 4:22 PM
Stats:
Comments:13 Avg. Rating:5
Views:92016 Contributors:8
Shares:2
Tags: No tags.

Documents Leaderboard