5508 wlc with 1140 APs and NPS part 2

flyboy168 · ‎09-18-2013

I ran a debug on the WLC to capture the message when trying to use my wireless client to connect to the AP...

it keeps prompting me with my domain user name/ password.. even tho I know I typed it right... it almost seems like its not authenticating properly with my NPS service ? does it matter if I have multiple NPS service running ? basically I have 3 dhcp servers , 1 in NYC,1 in Chicago, 1 in Miami and I have NPS installed on each dhcp servers.... would this cause a problem ?

I also have 3 domain controllers... one in each site.

so here is the break down of how I had everything connected

NYC - 1 DC, DHCP - NPS , CA server, 2x 5508 WLC , 3x1142 cisco AP

Chicago - 1 DC, DHCP - NPS,

Miami - 1 DC , DHCP - NPS 3x1142 Cisco AP

here is the capture I ran from NYC trying to connect via a laptop... btw I followed the exactly way this guy had configured his WLC and NPS

http://araihan.wordpress.com/2010/04/30/complete-guide-to-build-a-cisco-wireless-infrastructure-using-cisco-wlc-5500-cisco-1142-ap-and-microsoft-radius-server/

here is the debug

(Cisco Controller) >debug client E0:B9:A5:2C:68:6D 18:3D; :A2:20:23:5C

(Cisco Controller) >*apfMsConnTask_4: Sep 18 16:17:14.279: Stats update: Non Zero value

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Adding mobile on LWAPP AP 24:01:c7:ed:48:70(0)

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Association received from mobile on BSSID 24:01:c7:ed:48:72

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Global 200 Clients are allowed to AP radio

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Max Client Trap Threshold: 0 cur: 0

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Rf profile 200 Clients are allowed to AP wlan

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Applying Interface policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c Re-applying interface policy for client

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c In processSsidIE:4202 setting Central switched to TRUE

*apfMsConnTask_7: Sep 18 16:18:17.271: 18:3d:a2:20:23:5c In processSsidIE:4205 apVapId = 3 and Split Acl Id = 65535

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Applying site-specific Local Bridging override for station 18:3d:a2:20:23:5c - vapId 3, site 'CoreSites', interface 'aginternet'

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Applying Local Bridging Interface Policy for station 18:3d:a2:20:23:5c - vlan 232, interface id 13, interface 'aginternet'

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Applying site-specific override for station 18:3d:a2:20:23:5c - vapId 3, site 'CoreSites', interface 'aginternet'

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 232

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Re-applying interface policy for client

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c STA - rates (8): 130 132 139 150 12 18 24 36 0 0 0 0 0 0 0 0

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Processing RSN IE type 48, length 22 for mobile 18:3d:a2:20:23:5c

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Received RSN IE with 0 PMKIDs from mobile 18:3d:a2:20:23:5c

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Setting active key cache index 8 ---> 8

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c unsetting PmkIdValidatedByAp

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c 0.0.0.0 START (0) Initializing policy

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_7: Sep 18 16:18:17.272: 18:3d:a2:20:23:5c Not Using WMM Compliance code qosCap 00

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 24:01:c7:ed:48:70 vapId 3 apVapId 3 flex-acl-name:

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c apfMsAssoStateInc

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c apfPemAddUser2 (apf_policy.c:276) Changing state for mobile 18:3d:a2:20:23:5c on AP 24:01:c7:ed:48:70 from Idle to Associated

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c apfPemAddUser2:session timeout forstation 18:3d:a2:20:23:5c - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c Sending Assoc Response to station on BSSID 24:01:c7:ed:48:72 (status 0) ApVapId 3 Slot 0

*apfMsConnTask_7: Sep 18 16:18:17.273: 18:3d:a2:20:23:5c apfProcessAssocReq (apf_80211.c:7391) Changing state for mobile 18:3d:a2:20:23:5c on AP 24:01:c7:ed:48:70 from Associated to Associated

*dot1xMsgTask: Sep 18 16:18:17.277: 18:3d:a2:20:23:5c Station 18:3d:a2:20:23:5c setting dot1x reauth timeout = 1800

*dot1xMsgTask: Sep 18 16:18:17.277: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Connecting state

*dot1xMsgTask: Sep 18 16:18:17.277: 18:3d:a2:20:23:5c Sending EAP-Request/Identity to mobile 18:3d:a2:20:23:5c (EAP Id 1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.313: 18:3d:a2:20:23:5c Received EAPOL START from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.313: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Connecting state

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.314: 18:3d:a2:20:23:5c Sending EAP-Request/Identity to mobile 18:3d:a2:20:23:5c (EAP Id 2)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.330: 18:3d:a2:20:23:5c Received EAPOL EAPPKT from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.330: 18:3d:a2:20:23:5c Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.339: 18:3d:a2:20:23:5c Received EAPOL EAPPKT from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.339: 18:3d:a2:20:23:5c Received Identity Response (count=2) from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.339: 18:3d:a2:20:23:5c EAP State update from Connecting to Authenticating for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.339: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Authenticating state

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.339: 18:3d:a2:20:23:5c Entering Backend Auth Response state for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.350: 18:3d:a2:20:23:5c Processing Access-Reject for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.350: 18:3d:a2:20:23:5c Removing PMK cache due to EAP-Failure for mobile 18:3d:a2:20:23:5c (EAP Id -1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.350: 18:3d:a2:20:23:5c Sending EAP-Failure to mobile 18:3d:a2:20:23:5c (EAP Id -1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.350: 18:3d:a2:20:23:5c Entering Backend Auth Failure state (id=-1) for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.350: 18:3d:a2:20:23:5c Setting quiet timer for 5 seconds for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.350: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Unknown state

*Dot1x_NW_MsgTask_4: Sep 18 16:18:17.432: 18:3d:a2:20:23:5c Received EAPOL START from mobile 18:3d:a2:20:23:5c

*osapiBsnTimer: Sep 18 16:18:22.308: 18:3d:a2:20:23:5c 802.1x 'quiteWhile' Timer expired for station 18:3d:a2:20:23:5c and for message = M0

*dot1xMsgTask: Sep 18 16:18:22.308: 18:3d:a2:20:23:5c quiet timer completed for mobile 18:3d:a2:20:23:5c

*dot1xMsgTask: Sep 18 16:18:22.308: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Connecting state

*dot1xMsgTask: Sep 18 16:18:22.308: 18:3d:a2:20:23:5c Sending EAP-Request/Identity to mobile 18:3d:a2:20:23:5c (EAP Id 1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.517: 18:3d:a2:20:23:5c Received EAPOL EAPPKT from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.517: 18:3d:a2:20:23:5c Received Identity Response (count=3) from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.517: 18:3d:a2:20:23:5c Reached Max EAP-Identity Request retries (3) for STA 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.520: 18:3d:a2:20:23:5c Sent Deauthenticate to mobile on BSSID 24:01:c7:ed:48:70 slot 0(caller 1x_auth_pae.c:3241)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.520: 18:3d:a2:20:23:5c Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.520: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Disconnected state

*Dot1x_NW_MsgTask_4: Sep 18 16:18:32.520: 18:3d:a2:20:23:5c Not sending EAP-Failure for STA 18:3d:a2:20:23:5c

*apfMsConnTask_7: Sep 18 16:18:32.520: Stats update: Non Zero value

*apfMsConnTask_7: Sep 18 16:18:32.994: Stats update: Non Zero value

*apfMsConnTask_7: Sep 18 16:18:32.998: Stats update: Non Zero value

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Association received from mobile on BSSID 24:01:c7:ed:48:72

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Global 200 Clients are allowed to AP radio

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Max Client Trap Threshold: 0 cur: 1

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Rf profile 200 Clients are allowed to AP wlan

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 232

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Re-applying interface policy for client

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c In processSsidIE:4202 setting Central switched to TRUE

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c In processSsidIE:4205 apVapId = 3 and Split Acl Id = 65535

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Applying site-specific Local Bridging override for station 18:3d:a2:20:23:5c - vapId 3, site 'CoreSites', interface 'aginternet'

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Applying Local Bridging Interface Policy for station 18:3d:a2:20:23:5c - vlan 232, interface id 13, interface 'aginternet'

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Applying site-specific override for station 18:3d:a2:20:23:5c - vapId 3, site 'CoreSites', interface 'aginternet'

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Applying Interface policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 232

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c Re-applying interface policy for client

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2018)

*apfMsConnTask_7: Sep 18 16:18:32.999: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2246)

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c processSsidIE statusCode is 0 and status is 0

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c processSsidIE ssid_done_flag is 0 finish_flag is 0

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c suppRates statusCode is 0 and gotSuppRatesElement is 1

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c Processing RSN IE type 48, length 22 for mobile 18:3d:a2:20:23:5c

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c Received RSN IE with 0 PMKIDs from mobile 18:3d:a2:20:23:5c

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c Setting active key cache index 8 ---> 8

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c unsetting PmkIdValidatedByAp

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c Not Using WMM Compliance code qosCap 00

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 24:01:c7:ed:48:70 vapId 3 apVapId 3 flex-acl-name:

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c apfPemAddUser2 (apf_policy.c:276) Changing state for mobile 18:3d:a2:20:23:5c on AP 24:01:c7:ed:48:70 from Associated to Associated

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c apfPemAddUser2:session timeout forstation 18:3d:a2:20:23:5c - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_7: Sep 18 16:18:33.000: 18:3d:a2:20:23:5c Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_7: Sep 18 16:18:33.001: 18:3d:a2:20:23:5c Sending Assoc Response to station on BSSID 24:01:c7:ed:48:72 (status 0) ApVapId 3 Slot 0

*apfMsConnTask_7: Sep 18 16:18:33.001: 18:3d:a2:20:23:5c apfProcessAssocReq (apf_80211.c:7391) Changing state for mobile 18:3d:a2:20:23:5c on AP 24:01:c7:ed:48:70 from Associated to Associated

*apfMsConnTask_7: Sep 18 16:18:33.003: Stats update: Non Zero value

*dot1xMsgTask: Sep 18 16:18:33.003: 18:3d:a2:20:23:5c Station 18:3d:a2:20:23:5c setting dot1x reauth timeout = 1800

*dot1xMsgTask: Sep 18 16:18:33.003: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Connecting state

*dot1xMsgTask: Sep 18 16:18:33.004: 18:3d:a2:20:23:5c Sending EAP-Request/Identity to mobile 18:3d:a2:20:23:5c (EAP Id 1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:33.102: 18:3d:a2:20:23:5c Received EAPOL START from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:33.102: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Connecting state

*Dot1x_NW_MsgTask_4: Sep 18 16:18:33.102: 18:3d:a2:20:23:5c Sending EAP-Request/Identity to mobile 18:3d:a2:20:23:5c (EAP Id 2)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.930: 18:3d:a2:20:23:5c Received EAPOL EAPPKT from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.930: 18:3d:a2:20:23:5c Received Identity Response (count=2) from mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.930: 18:3d:a2:20:23:5c EAP State update from Connecting to Authenticating for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.930: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Authenticating state

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.930: 18:3d:a2:20:23:5c Entering Backend Auth Response state for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.945: 18:3d:a2:20:23:5c Processing Access-Reject for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.945: 18:3d:a2:20:23:5c Removing PMK cache due to EAP-Failure for mobile 18:3d:a2:20:23:5c (EAP Id -1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.945: 18:3d:a2:20:23:5c Sending EAP-Failure to mobile 18:3d:a2:20:23:5c (EAP Id -1)

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.945: 18:3d:a2:20:23:5c Entering Backend Auth Failure state (id=-1) for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.945: 18:3d:a2:20:23:5c Setting quiet timer for 5 seconds for mobile 18:3d:a2:20:23:5c

*Dot1x_NW_MsgTask_4: Sep 18 16:18:46.945: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Unknown state

*osapiBsnTimer: Sep 18 16:18:51.908: 18:3d:a2:20:23:5c 802.1x 'quiteWhile' Timer expired for station 18:3d:a2:20:23:5c and for message = M0

*dot1xMsgTask: Sep 18 16:18:51.908: 18:3d:a2:20:23:5c quiet timer completed for mobile 18:3d:a2:20:23:5c

*dot1xMsgTask: Sep 18 16:18:51.908: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Connecting state

*dot1xMsgTask: Sep 18 16:18:51.908: 18:3d:a2:20:23:5c Sending EAP-Request/Identity to mobile 18:3d:a2:20:23:5c (EAP Id 1)

*apfMsConnTask_7: Sep 18 16:19:18.562: Stats update: Non Zero value

*osapiBsnTimer: Sep 18 16:19:21.908: 18:3d:a2:20:23:5c 802.1x 'txWhen' Timer expired for station 18:3d:a2:20:23:5c and for message = M0

*dot1xMsgTask: Sep 18 16:19:21.908: 18:3d:a2:20:23:5c Reached Max EAP-Identity Request retries (3) for STA 18:3d:a2:20:23:5c

*dot1xMsgTask: Sep 18 16:19:21.911: 18:3d:a2:20:23:5c Sent Deauthenticate to mobile on BSSID 24:01:c7:ed:48:70 slot 0(caller 1x_auth_pae.c:3241)

*dot1xMsgTask: Sep 18 16:19:21.911: 18:3d:a2:20:23:5c Scheduling deletion of Mobile Station: (callerId: 6) in 10 seconds

*dot1xMsgTask: Sep 18 16:19:21.911: 18:3d:a2:20:23:5c dot1x - moving mobile 18:3d:a2:20:23:5c into Disconnected state

*dot1xMsgTask: Sep 18 16:19:21.911: 18:3d:a2:20:23:5c Not sending EAP-Failure for STA 18:3d:a2:20:23:5c

*osapiBsnTimer: Sep 18 16:19:31.908: 18:3d:a2:20:23:5c apfMsExpireCallback (apf_ms.c:614) Expiring Mobile!

*apfReceiveTask: Sep 18 16:19:31.908: 18:3d:a2:20:23:5c apfMsExpireMobileStation (apf_ms.c:5803) Changing state for mobile 18:3d:a2:20:23:5c on AP 24:01:c7:ed:48:70 from Associated to Disassociated

*apfReceiveTask: Sep 18 16:19:31.909: 18:3d:a2:20:23:5c Scheduling deletion of Mobile Station: (callerId: 45) in 10 seconds

*osapiBsnTimer: Sep 18 16:19:41.908: 18:3d:a2:20:23:5c apfMsExpireCallback (apf_ms.c:614) Expiring Mobile!

*apfReceiveTask: Sep 18 16:19:41.908: 18:3d:a2:20:23:5c apfMsAssoStateDec

*apfReceiveTask: Sep 18 16:19:41.908: 18:3d:a2:20:23:5c apfMsExpireMobileStation (apf_ms.c:5935) Changing state for mobile 18:3d:a2:20:23:5c on AP 24:01:c7:ed:48:70 from Disassociated to Idle

*apfReceiveTask: Sep 18 16:19:41.908: 18:3d:a2:20:23:5c pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.

*apfReceiveTask: Sep 18 16:19:41.909: 18:3d:a2:20:23:5c 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [24:01:c7:ed:48:70]