Cisco WLC 2106 + MS NPS

alex.roth · ‎10-18-2012

Hello ,

We use several Cisco WLC ( 5508/2504) together with the MS NPS /ISA server without problems to login over AD.

Now we installed aother Cisco WLC 2106 ( Version 7.0.235.0) with same configuration as the others only we used an internal

DHCP server from the controller as a DHCP Server.

All seems to be ok but the client ( XP ) can´t connect. The status is connected on the WLC but on the client WLAN overview the status

is still not nonnected. I checked the config on our MS NPS server and I doublechecked the config on our WLC but I don´t find why.

Below is a debug from the 2106 WLC:

(Cisco Controller) >*DHCP Socket Task: Oct 19 03:01:41.831: d4:ae:52:8d:45:21 DHCP options end, len 95, actual 87
*osapiBsnTimer: Oct 19 03:03:23.251: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:03:23.252: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:03:23.252: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 3)
(Cisco Controller) >*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 Association received from mobile on AP ac:a0:16:ca:0f:90
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1633)
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 Applying site-specific IPv6 override for station 00:21:6a:82:e8:b4 - vapId 1, site 'default-group', interface 'wlan'
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 Applying IPv6 Interface Policy for station 00:21:6a:82:e8:b4 - vlan 159, interface id 5, interface 'wlan'
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 STA - rates (8): 140 18 152 36 176 72 96 108 48 72 96 108 0 0 0 0
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 Processing RSN IE type 48, length 22 for mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 Received RSN IE with 0 PMKIDs from mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:03:46.980: 00:21:6a:82:e8:b4 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [ac:a0:16:ca:0a:00]
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 Updated location for station old AP ac:a0:16:ca:0a:00-1, new AP ac:a0:16:ca:0f:90-1
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) DHCP Not required on AP ac:a0:16:ca:0f:90 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP ac:a0:16:ca:0f:90 vapId 1 apVapId 1
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0f:90 from Associated to Associated

*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 Sending Assoc Response to station on BSSID ac:a0:16:ca:0f:90 (status 0) ApVapId 1 Slot 1
*apfMsConnTask_0: Oct 19 03:03:46.981: 00:21:6a:82:e8:b4 apfProcessAssocReq (apf_80211.c:5272) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0f:90 from Associated to Associated

*dot1xMsgTask: Oct 19 03:03:46.984: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:03:46.988: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 1)
*Dot1x_NW_MsgTask_0: Oct 19 03:03:46.993: 00:21:6a:82:e8:b4 Received EAPOL START from mobile 00:21:6a:82:e8:b4
*Dot1x_NW_MsgTask_0: Oct 19 03:03:46.994: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*Dot1x_NW_MsgTask_0: Oct 19 03:03:46.994: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 2)
*osapiBsnTimer: Oct 19 03:04:16.843: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:04:16.843: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:04:16.844: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 3)
*osapiBsnTimer: Oct 19 03:04:46.838: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:04:46.839: 00:21:6a:82:e8:b4 Reached Max EAP-Identity Request retries (3) for STA 00:21:6a:82:e8:b4
*dot1xMsgTask: Oct 19 03:04:46.839: 00:21:6a:82:e8:b4 Sent Deauthenticate to mobile on BSSID ac:a0:16:ca:0f:90 slot 1(caller 1x_auth_pae.c:3091)
*dot1xMsgTask: Oct 19 03:04:46.839: 00:21:6a:82:e8:b4 Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds
*dot1xMsgTask: Oct 19 03:04:46.840: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Disconnected state
*dot1xMsgTask: Oct 19 03:04:46.840: 00:21:6a:82:e8:b4 Not sending EAP-Failure for STA 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:04:47.097: 00:21:6a:82:e8:b4 Association received from mobile on AP ac:a0:16:ca:0a:00
*apfMsConnTask_0: Oct 19 03:04:47.097: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1633)
*apfMsConnTask_0: Oct 19 03:04:47.097: 00:21:6a:82:e8:b4 Applying site-specific IPv6 override for station 00:21:6a:82:e8:b4 - vapId 1, site 'default-group', interface 'wlan'
*apfMsConnTask_0: Oct 19 03:04:47.097: 00:21:6a:82:e8:b4 Applying IPv6 Interface Policy for station 00:21:6a:82:e8:b4 - vlan 159, interface id 5, interface 'wlan'
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 STA - rates (8): 140 18 152 36 176 72 96 108 48 72 96 108 0 0 0 0
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 Processing RSN IE type 48, length 22 for mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 Received RSN IE with 0 PMKIDs from mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [ac:a0:16:ca:0f:90]
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 Updated location for station old AP ac:a0:16:ca:0f:90-1, new AP ac:a0:16:ca:0a:00-1
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) DHCP Not required on AP ac:a0:16:ca:0a:00 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Oct 19 03:04:47.098: 00:21:6a:82:e8:b4 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Oct 19 03:04:47.099: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP ac:a0:16:ca:0a:00 vapId 1 apVapId 1
*apfMsConnTask_0: Oct 19 03:04:47.099: 00:21:6a:82:e8:b4 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0a:00 from Associated to Associated

*apfMsConnTask_0: Oct 19 03:04:47.099: 00:21:6a:82:e8:b4 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Oct 19 03:04:47.099: 00:21:6a:82:e8:b4 Sending Assoc Response to station on BSSID ac:a0:16:ca:0a:00 (status 0) ApVapId 1 Slot 1
*apfMsConnTask_0: Oct 19 03:04:47.099: 00:21:6a:82:e8:b4 apfProcessAssocReq (apf_80211.c:5272) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0a:00 from Associated to Associated

*dot1xMsgTask: Oct 19 03:04:47.102: 00:21:6a:82:e8:b4 Station 00:21:6a:82:e8:b4 setting dot1x reauth timeout = 1800
*dot1xMsgTask: Oct 19 03:04:47.106: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:04:47.106: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 1)
*Dot1x_NW_MsgTask_0: Oct 19 03:04:47.108: 00:21:6a:82:e8:b4 Received EAPOL START from mobile 00:21:6a:82:e8:b4
*Dot1x_NW_MsgTask_0: Oct 19 03:04:47.108: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*Dot1x_NW_MsgTask_0: Oct 19 03:04:47.109: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 2)
*osapiBsnTimer: Oct 19 03:05:17.048: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:05:17.048: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:05:17.048: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 3)
*osapiBsnTimer: Oct 19 03:05:47.043: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:05:47.044: 00:21:6a:82:e8:b4 Reached Max EAP-Identity Request retries (3) for STA 00:21:6a:82:e8:b4
*dot1xMsgTask: Oct 19 03:05:47.044: 00:21:6a:82:e8:b4 Sent Deauthenticate to mobile on BSSID ac:a0:16:ca:0a:00 slot 1(caller 1x_auth_pae.c:3091)
*dot1xMsgTask: Oct 19 03:05:47.045: 00:21:6a:82:e8:b4 Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds
*dot1xMsgTask: Oct 19 03:05:47.045: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Disconnected state
*dot1xMsgTask: Oct 19 03:05:47.045: 00:21:6a:82:e8:b4 Not sending EAP-Failure for STA 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 Association received from mobile on AP ac:a0:16:ca:0f:90
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1633)
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 Applying site-specific IPv6 override for station 00:21:6a:82:e8:b4 - vapId 1, site 'default-group', interface 'wlan'
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 Applying IPv6 Interface Policy for station 00:21:6a:82:e8:b4 - vlan 159, interface id 5, interface 'wlan'
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 STA - rates (8): 140 18 152 36 176 72 96 108 48 72 96 108 0 0 0 0
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 Processing RSN IE type 48, length 22 for mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 Received RSN IE with 0 PMKIDs from mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:05:47.235: 00:21:6a:82:e8:b4 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [ac:a0:16:ca:0a:00]
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 Updated location for station old AP ac:a0:16:ca:0a:00-1, new AP ac:a0:16:ca:0f:90-1
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) DHCP Not required on AP ac:a0:16:ca:0f:90 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP ac:a0:16:ca:0f:90 vapId 1 apVapId 1
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0f:90 from Associated to Associated

*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 Sending Assoc Response to station on BSSID ac:a0:16:ca:0f:90 (status 0) ApVapId 1 Slot 1
*apfMsConnTask_0: Oct 19 03:05:47.236: 00:21:6a:82:e8:b4 apfProcessAssocReq (apf_80211.c:5272) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0f:90 from Associated to Associated

*dot1xMsgTask: Oct 19 03:05:47.243: 00:21:6a:82:e8:b4 Station 00:21:6a:82:e8:b4 setting dot1x reauth timeout = 1800
*dot1xMsgTask: Oct 19 03:05:47.243: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:05:47.243: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 1)
*Dot1x_NW_MsgTask_0: Oct 19 03:05:47.245: 00:21:6a:82:e8:b4 Received EAPOL START from mobile 00:21:6a:82:e8:b4
*Dot1x_NW_MsgTask_0: Oct 19 03:05:47.246: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*Dot1x_NW_MsgTask_0: Oct 19 03:05:47.246: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 2)
*osapiBsnTimer: Oct 19 03:06:17.239: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:06:17.239: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:06:17.240: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 3)
*osapiBsnTimer: Oct 19 03:06:47.234: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:06:47.234: 00:21:6a:82:e8:b4 Reached Max EAP-Identity Request retries (3) for STA 00:21:6a:82:e8:b4
*dot1xMsgTask: Oct 19 03:06:47.235: 00:21:6a:82:e8:b4 Sent Deauthenticate to mobile on BSSID ac:a0:16:ca:0f:90 slot 1(caller 1x_auth_pae.c:3091)
*dot1xMsgTask: Oct 19 03:06:47.235: 00:21:6a:82:e8:b4 Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds
*dot1xMsgTask: Oct 19 03:06:47.235: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Disconnected state
*dot1xMsgTask: Oct 19 03:06:47.235: 00:21:6a:82:e8:b4 Not sending EAP-Failure for STA 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 Association received from mobile on AP ac:a0:16:ca:0f:90
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1633)
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 Applying site-specific IPv6 override for station 00:21:6a:82:e8:b4 - vapId 1, site 'default-group', interface 'wlan'
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 Applying IPv6 Interface Policy for station 00:21:6a:82:e8:b4 - vlan 159, interface id 5, interface 'wlan'
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 STA - rates (8): 140 18 152 36 176 72 96 108 48 72 96 108 0 0 0 0
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 Processing RSN IE type 48, length 22 for mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 Received RSN IE with 0 PMKIDs from mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) DHCP Not required on AP ac:a0:16:ca:0f:90 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Oct 19 03:06:47.454: 00:21:6a:82:e8:b4 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Oct 19 03:06:47.455: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP ac:a0:16:ca:0f:90 vapId 1 apVapId 1
*apfMsConnTask_0: Oct 19 03:06:47.455: 00:21:6a:82:e8:b4 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0f:90 from Associated to Associated

*apfMsConnTask_0: Oct 19 03:06:47.455: 00:21:6a:82:e8:b4 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Oct 19 03:06:47.455: 00:21:6a:82:e8:b4 Sending Assoc Response to station on BSSID ac:a0:16:ca:0f:90 (status 0) ApVapId 1 Slot 1
*apfMsConnTask_0: Oct 19 03:06:47.455: 00:21:6a:82:e8:b4 apfProcessAssocReq (apf_80211.c:5272) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0f:90 from Associated to Associated

*dot1xMsgTask: Oct 19 03:06:47.457: 00:21:6a:82:e8:b4 Station 00:21:6a:82:e8:b4 setting dot1x reauth timeout = 1800
*dot1xMsgTask: Oct 19 03:06:47.461: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:06:47.461: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 1)
*Dot1x_NW_MsgTask_0: Oct 19 03:06:47.463: 00:21:6a:82:e8:b4 Received EAPOL START from mobile 00:21:6a:82:e8:b4
*Dot1x_NW_MsgTask_0: Oct 19 03:06:47.464: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*Dot1x_NW_MsgTask_0: Oct 19 03:06:47.464: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 2)
*osapiBsnTimer: Oct 19 03:07:17.429: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:07:17.430: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:07:17.431: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 3)
*osapiBsnTimer: Oct 19 03:07:47.425: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:07:47.425: 00:21:6a:82:e8:b4 Reached Max EAP-Identity Request retries (3) for STA 00:21:6a:82:e8:b4
*dot1xMsgTask: Oct 19 03:07:47.426: 00:21:6a:82:e8:b4 Sent Deauthenticate to mobile on BSSID ac:a0:16:ca:0f:90 slot 1(caller 1x_auth_pae.c:3091)
*dot1xMsgTask: Oct 19 03:07:47.426: 00:21:6a:82:e8:b4 Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds
*dot1xMsgTask: Oct 19 03:07:47.426: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Disconnected state
*dot1xMsgTask: Oct 19 03:07:47.426: 00:21:6a:82:e8:b4 Not sending EAP-Failure for STA 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 Association received from mobile on AP ac:a0:16:ca:0a:00
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1633)
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 Applying site-specific IPv6 override for station 00:21:6a:82:e8:b4 - vapId 1, site 'default-group', interface 'wlan'
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 Applying IPv6 Interface Policy for station 00:21:6a:82:e8:b4 - vlan 159, interface id 5, interface 'wlan'
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 STA - rates (8): 140 18 152 36 176 72 96 108 48 72 96 108 0 0 0 0
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 Processing RSN IE type 48, length 22 for mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 Received RSN IE with 0 PMKIDs from mobile 00:21:6a:82:e8:b4
*apfMsConnTask_0: Oct 19 03:07:47.671: 00:21:6a:82:e8:b4 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [ac:a0:16:ca:0f:90]
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 Updated location for station old AP ac:a0:16:ca:0f:90-1, new AP ac:a0:16:ca:0a:00-1
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) DHCP Not required on AP ac:a0:16:ca:0a:00 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP ac:a0:16:ca:0a:00 vapId 1 apVapId 1
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0a:00 from Associated to Associated

*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Oct 19 03:07:47.672: 00:21:6a:82:e8:b4 Sending Assoc Response to station on BSSID ac:a0:16:ca:0a:00 (status 0) ApVapId 1 Slot 1
*apfMsConnTask_0: Oct 19 03:07:47.673: 00:21:6a:82:e8:b4 apfProcessAssocReq (apf_80211.c:5272) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0a:00 from Associated to Associated

*dot1xMsgTask: Oct 19 03:07:47.675: 00:21:6a:82:e8:b4 Station 00:21:6a:82:e8:b4 setting dot1x reauth timeout = 1800
*dot1xMsgTask: Oct 19 03:07:47.677: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:07:47.677: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 1)
*Dot1x_NW_MsgTask_0: Oct 19 03:07:47.681: 00:21:6a:82:e8:b4 Received EAPOL START from mobile 00:21:6a:82:e8:b4
*Dot1x_NW_MsgTask_0: Oct 19 03:07:47.681: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*Dot1x_NW_MsgTask_0: Oct 19 03:07:47.681: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 2)

(Cisco Controller) >
(Cisco Controller) >*osapiBsnTimer: Oct 19 03:08:17.620: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:08:17.621: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Connecting state
*dot1xMsgTask: Oct 19 03:08:17.621: 00:21:6a:82:e8:b4 Sending EAP-Request/Identity to mobile 00:21:6a:82:e8:b4 (EAP Id 3)
*osapiBsnTimer: Oct 19 03:08:47.616: 00:21:6a:82:e8:b4 802.1x 'txWhen' Timer expired for station 00:21:6a:82:e8:b4 and for message = M0
*dot1xMsgTask: Oct 19 03:08:47.616: 00:21:6a:82:e8:b4 Reached Max EAP-Identity Request retries (3) for STA 00:21:6a:82:e8:b4
*dot1xMsgTask: Oct 19 03:08:47.617: 00:21:6a:82:e8:b4 Sent Deauthenticate to mobile on BSSID ac:a0:16:ca:0a:00 slot 1(caller 1x_auth_pae.c:3091)
*dot1xMsgTask: Oct 19 03:08:47.617: 00:21:6a:82:e8:b4 Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds
*dot1xMsgTask: Oct 19 03:08:47.617: 00:21:6a:82:e8:b4 dot1x - moving mobile 00:21:6a:82:e8:b4 into Disconnected state
*dot1xMsgTask: Oct 19 03:08:47.617: 00:21:6a:82:e8:b4 Not sending EAP-Failure for STA 00:21:6a:82:e8:b4
*osapiBsnTimer: Oct 19 03:08:57.628: 00:21:6a:82:e8:b4 apfMsExpireCallback (apf_ms.c:609) Expiring Mobile!
*apfReceiveTask: Oct 19 03:08:57.628: 00:21:6a:82:e8:b4 apfMsExpireMobileStation (apf_ms.c:5021) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0a:00 from Associated to Disassociated

*apfReceiveTask: Oct 19 03:08:57.628: 00:21:6a:82:e8:b4 Scheduling deletion of Mobile Station: (callerId: 45) in 10 seconds
*osapiBsnTimer: Oct 19 03:09:07.627: 00:21:6a:82:e8:b4 apfMsExpireCallback (apf_ms.c:609) Expiring Mobile!
*apfReceiveTask: Oct 19 03:09:07.627: 00:21:6a:82:e8:b4 apfMsAssoStateDec
*apfReceiveTask: Oct 19 03:09:07.627: 00:21:6a:82:e8:b4 apfMsExpireMobileStation (apf_ms.c:5151) Changing state for mobile 00:21:6a:82:e8:b4 on AP ac:a0:16:ca:0a:00 from Disassociated to Idle

*apfReceiveTask: Oct 19 03:09:07.627: 00:21:6a:82:e8:b4 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfReceiveTask: Oct 19 03:09:07.627: 00:21:6a:82:e8:b4 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [ac:a0:16:ca:0a:00]
*apfReceiveTask: Oct 19 03:09:07.628: 00:21:6a:82:e8:b4 Deleting mobile on AP ac:a0:16:ca:0a:00(1)

Is seems for me it´s a problem with the NPS server but all other WLCsw working without problems . Only the 2106 not work.

Thanks for help

Stephen Rodriguez · ‎10-18-2012

from the debug, it looks like the client is not responding to the EAP identity request.

Reached Max EAP-Identity Request retries (3) for STA 00:21:6a:82:e8:b4

HTH,
Steve

------------------------------------------------------------------------------------------------
Please remember to rate useful posts, and mark questions as answered

Saravanan Lakshmanan · ‎10-18-2012

does the same client works with other AAA working WLC, if not it could be client side issue, try updating client driver/supplicant. do you see this issue on MACs.

compare the wireless client specification connecting btw 2106 and working WLCs, fix the gap.

alex.roth · ‎10-22-2012

Hello,

Thanks for the help. The problem is solved.

Changed the test client from XP to Win7. Changed WLC AAA server configuration

to another NPS in our network which is working. Now the client working without problems.

Changed back to the AAA NPS server which are not working.

Checked logfile on the NPS server and saw the error messages "to many certificates on this server are installed"

( over 300 hundred ). Removed not required certificates. Now it works.

Alex