cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
6655
Views
3
Helpful
13
Replies

Problem with clients connecting to wlan WPA2-AES

its-neteng
Level 1
Level 1

Hello All,

We started seeing a lot of complaints coming from clients campus wide stating that they are not able to connect to our secure wirless lan.  The behavior is the device will try to connect several times then come back with a can not connect error.  We are seeing this with a variety of different client types; phones, iPads, laptops, etc.  Below is the controller debug of a client that cannot connect.  Have a look for me and let me know if you see anything that stands out. 

(WiSM-slot4-1) >*apfLbsTask: Aug 23 14:40:45.486: 7c:61:93:a4:ab:63 Copy MobilityData LOCP status:0, anchorip:0x0

*osapiBsnTimer: Aug 23 14:41:09.480: 7c:61:93:a4:ab:63 802.1x 'txWhen' Timer expired for station 7c:61:93:a4:ab:63 and for message = M0

*dot1xMsgTask: Aug 23 14:41:09.486: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 14:41:09.486: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 3)

*dot1xMsgTask: Aug 23 14:41:09.486: 7c:61:93:a4:ab:63 Sending 802.11 EAPOL message  to mobile 7c:61:93:a4:ab:63 WLAN 1, AP WLAN 1

*dot1xMsgTask: Aug 23 14:41:09.487: 00000000: 02 00 00 35 01 03 00 35  01 00 6e 65 74 77 6f 72  ...5...5..networ

*dot1xMsgTask: Aug 23 14:41:09.487: 00000010: 6b 69 64 3d 75 6e 66 2d  73 65 63 75 72 65 2c 6e  kid=unf-secure,n

*dot1xMsgTask: Aug 23 14:41:09.487: 00000020: 61 73 69 64 3d 57 69 53  4d 2d 53 2d 34 2d 31 2c  asid=WiSM-S-4-1,

*dot1xMsgTask: Aug 23 14:41:09.487: 00000030: 70 6f 72 74 69 64 3d 32  39                       portid=29

*dot1xMsgTask: Aug 23 14:41:09.487: 7c:61:93:a4:ab:63 Reached Max EAP-Identity Request retries (3) for STA 7c:61:93:a4:ab:63

*dot1xMsgTask: Aug 23 14:41:09.488: 7c:61:93:a4:ab:63 Sent Deauthenticate to mobile on BSSID fc:fb:fb:d8:96:40 slot 0(caller 1x_auth_pae.c:3057)

*dot1xMsgTask: Aug 23 14:41:09.488: 7c:61:93:a4:ab:63 Scheduling deletion of Mobile Station:  (callerId: 6) in 10 seconds

*dot1xMsgTask: Aug 23 14:41:09.488: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Disconnected state

*dot1xMsgTask: Aug 23 14:41:09.489: 7c:61:93:a4:ab:63 Not sending EAP-Failure for STA 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 Association received from mobile on AP fc:fb:fb:d8:96:40

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller                                apf_policy.c:1626)

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 Applying site-specific IPv6 override for station 7c:61:93:a4:ab:63 - vapId 1, site 'default-                               group', interface 'unf-wireless'

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 Applying IPv6 Interface Policy for station 7c:61:93:a4:ab:63 - vlan 108, interface id 9, int                               erface 'unf-wireless'

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 STA - rates (8): 18 150 24 36 48 72 96 108 0 0 0 0 0 0 0 0

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 Processing RSN IE type 48, length 20 for mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 14:41:12.624: 7c:61:93:a4:ab:63 Received RSN IE with 0 PMKIDs from mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) DHCP Not required on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1for this c                               lient

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb                               :d8:96:40 from Associated to Associated

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 Sending Assoc Response to station on BSSID fc:fb:fb:d8:96:40 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_0: Aug 23 14:41:12.625: 7c:61:93:a4:ab:63 apfProcessAssocReq (apf_80211.c:5237) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:f                               b:fb:d8:96:40 from Associated to Associated

*dot1xMsgTask: Aug 23 14:41:12.627: 7c:61:93:a4:ab:63 Station 7c:61:93:a4:ab:63 setting dot1x reauth timeout = 0

*dot1xMsgTask: Aug 23 14:41:12.628: 7c:61:93:a4:ab:63 Stopping reauth timeout for 7c:61:93:a4:ab:63

*dot1xMsgTask: Aug 23 14:41:12.628: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 14:41:12.628: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 1)

*dot1xMsgTask: Aug 23 14:41:12.628: 7c:61:93:a4:ab:63 Sending 802.11 EAPOL message  to mobile 7c:61:93:a4:ab:63 WLAN 1, AP WLAN 1

*dot1xMsgTask: Aug 23 14:41:12.628: 00000000: 02 00 00 35 01 01 00 35  01 00 6e 65 74 77 6f 72  ...5...5..networ

*dot1xMsgTask: Aug 23 14:41:12.636: 00000010: 6b 69 64 3d 75 6e 66 2d  73 65 63 75 72 65 2c 6e  kid=unf-secure,n

*dot1xMsgTask: Aug 23 14:41:12.636: 00000020: 61 73 69 64 3d 57 69 53  4d 2d 53 2d 34 2d 31 2c  asid=WiSM-S-4-1,

*dot1xMsgTask: Aug 23 14:41:12.636: 00000030: 70 6f 72 74 69 64 3d 32  39                       portid=29

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.547: 7c:61:93:a4:ab:63 Received 802.11 EAPOL message (len 4) from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.547: 00000000: 01 01 00 00                                       ....

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 7c:61:93:a4:ab:63 Received EAPOL START from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 2)

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 7c:61:93:a4:ab:63 Sending 802.11 EAPOL message  to mobile 7c:61:93:a4:ab:63 WLAN 1, AP WLAN 1

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 00000000: 02 00 00 35 01 02 00 35  01 00 6e 65 74 77 6f 72  ...5...5..networ

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 00000010: 6b 69 64 3d 75 6e 66 2d  73 65 63 75 72 65 2c 6e  kid=unf-secure,n

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 00000020: 61 73 69 64 3d 57 69 53  4d 2d 53 2d 34 2d 31 2c  asid=WiSM-S-4-1,

*Dot1x_NW_MsgTask_0: Aug 23 14:41:13.548: 00000030: 70 6f 72 74 69 64 3d 32  39                       portid=29

*apfLbsTask: Aug 23 14:41:17.492: 7c:61:93:a4:ab:63 Copy AP LOCP - mode:0 slotId:0, apMac 0xfc:fb:fb:d8:96:40

*apfLbsTask: Aug 23 14:41:17.492: 7c:61:93:a4:ab:63 Copy WLAN LOCP EssIndex:1 aid:1 ssid:unf-secure

*apfLbsTask: Aug 23 14:41:17.493: 7c:61:93:a4:ab:63 Copy Security LOCP ecypher:0x0 ptype:0x2, p:0x1, eaptype:0x6 w:0x1 aalg:0x0, PMState: 8021X_REQD

*apfLbsTask: Aug 23 14:41:17.493: 7c:61:93:a4:ab:63 Copy 802.11 LOCP a:0x0 b:0x0 c:0x0 d:0x0 e:0x1 protocol2:0x6 statuscode 0, reasoncode 1, status 3

(WiSM-slot4-1) >

(WiSM-slot4-1) >

(WiSM-slot4-1) >*apfLbsTask: Aug 23 14:41:17.493: 7c:61:93:a4:ab:63 Copy MobilityData LOCP status:0, anchorip:0x0

*apfMsConnTask_0: Aug 23 14:41:24.635: 7c:61:93:a4:ab:63 Association received from mobile on AP fc:fb:fb:d8:96:40

*apfMsConnTask_0: Aug 23 14:41:24.635: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller                                apf_policy.c:1626)

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Applying site-specific IPv6 override for station 7c:61:93:a4:ab:63 - vapId 1, site 'default-                               group', interface 'unf-wireless'

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Applying IPv6 Interface Policy for station 7c:61:93:a4:ab:63 - vlan 108, interface id 9, int                               erface 'unf-wireless'

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 STA - rates (8): 18 150 24 36 48 72 96 108 0 0 0 0 0 0 0 0

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Processing RSN IE type 48, length 20 for mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Received RSN IE with 0 PMKIDs from mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) DHCP Not required on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1for this c                               lient

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb                               :d8:96:40 from Associated to Associated

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 Sending Assoc Response to station on BSSID fc:fb:fb:d8:96:40 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_0: Aug 23 14:41:24.636: 7c:61:93:a4:ab:63 apfProcessAssocReq (apf_80211.c:5237) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:f                               b:fb:d8:96:40 from Associated to Associated

*dot1xMsgTask: Aug 23 14:41:24.638: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 14:41:24.639: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 1)

*dot1xMsgTask: Aug 23 14:41:24.639: 7c:61:93:a4:ab:63 Sending 802.11 EAPOL message  to mobile 7c:61:93:a4:ab:63 WLAN 1, AP WLAN 1

*dot1xMsgTask: Aug 23 14:41:24.639: 00000000: 02 00 00 35 01 01 00 35  01 00 6e 65 74 77 6f 72  ...5...5..networ

*dot1xMsgTask: Aug 23 14:41:24.639: 00000010: 6b 69 64 3d 75 6e 66 2d  73 65 63 75 72 65 2c 6e  kid=unf-secure,n

*dot1xMsgTask: Aug 23 14:41:24.639: 00000020: 61 73 69 64 3d 57 69 53  4d 2d 53 2d 34 2d 31 2c  asid=WiSM-S-4-1,

(WiSM-slot4-1) >*dot1xMsgTask: Aug 23 14:41:24.639: 00000030: 70 6f 72 74 69 64 3d 32  39                       portid=29

*apfLbsTask: Aug 23 14:41:25.486: 7c:61:93:a4:ab:63 Copy AP LOCP - mode:0 slotId:0, apMac 0xfc:fb:fb:d8:96:40

*apfLbsTask: Aug 23 14:41:25.486: 7c:61:93:a4:ab:63 Copy WLAN LOCP EssIndex:1 aid:1 ssid:unf-secure

*apfLbsTask: Aug 23 14:41:25.486: 7c:61:93:a4:ab:63 Copy Security LOCP ecypher:0x0 ptype:0x2, p:0x1, eaptype:0x6 w:0x1 aalg:0x0, PMState: 8021X_REQD

*apfLbsTask: Aug 23 14:41:25.486: 7c:61:93:a4:ab:63 Copy 802.11 LOCP a:0x0 b:0x0 c:0x0 d:0x0 e:0x1 protocol2:0x6 statuscode 0, reasoncode 1, status 3

*apfLbsTask: Aug 23 14:41:25.486: 7c:61:93:a4:ab:63 Copy MobilityData LOCP status:0, anchorip:0x0

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.558: 7c:61:93:a4:ab:63 Received 802.11 EAPOL message (len 4) from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.558: 00000000: 01 01 00 00                                       ....

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.558: 7c:61:93:a4:ab:63 Received EAPOL START from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.558: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.558: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 2)

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.558: 7c:61:93:a4:ab:63 Sending 802.11 EAPOL message  to mobile 7c:61:93:a4:ab:63 WLAN 1, AP WLAN 1

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.559: 00000000: 02 00 00 35 01 02 00 35  01 00 6e 65 74 77 6f 72  ...5...5..networ

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.559: 00000010: 6b 69 64 3d 75 6e 66 2d  73 65 63 75 72 65 2c 6e  kid=unf-secure,n

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.559: 00000020: 61 73 69 64 3d 57 69 53  4d 2d 53 2d 34 2d 31 2c  asid=WiSM-S-4-1,

*Dot1x_NW_MsgTask_0: Aug 23 14:41:25.559: 00000030: 70 6f 72 74 69 64 3d 32  39                       portid=29

*osapiBsnTimer: Aug 23 14:41:55.482: 7c:61:93:a4:ab:63 802.1x 'txWhen' Timer expired for station 7c:61:93:a4:ab:63 and for message = M0

*dot1xMsgTask: Aug 23 14:41:55.489: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 14:41:55.489: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 3)

*dot1xMsgTask: Aug 23 14:41:55.489: 7c:61:93:a4:ab:63 Sending 802.11 EAPOL message  to mobile 7c:61:93:a4:ab:63 WLAN 1, AP WLAN 1

*dot1xMsgTask: Aug 23 14:41:55.489: 00000000: 02 00 00 35 01 03 00 35  01 00 6e 65 74 77 6f 72  ...5...5..networ

*dot1xMsgTask: Aug 23 14:41:55.490: 00000010: 6b 69 64 3d 75 6e 66 2d  73 65 63 75 72 65 2c 6e  kid=unf-secure,n

*dot1xMsgTask: Aug 23 14:41:55.490: 00000020: 61 73 69 64 3d 57 69 53  4d 2d 53 2d 34 2d 31 2c  asid=WiSM-S-4-1,

*dot1xMsgTask: Aug 23 14:41:55.490: 00000030: 70 6f 72 74 69 64 3d 32  39                       portid=29

*dot1xMsgTask: Aug 23 14:41:55.490: 7c:61:93:a4:ab:63 Reached Max EAP-Identity Request retries (3) for STA 7c:61:93:a4:ab:63

*dot1xMsgTask: Aug 23 14:41:55.491: 7c:61:93:a4:ab:63 Sent Deauthenticate to mobile on BSSID fc:fb:fb:d8:96:40 slot 0(caller 1x_auth_pae.c:3057)

*dot1xMsgTask: Aug 23 14:41:55.491: 7c:61:93:a4:ab:63 Scheduling deletion of Mobile Station:  (callerId: 6) in 10 seconds

*dot1xMsgTask: Aug 23 14:41:55.491: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Disconnected state

*dot1xMsgTask: Aug 23 14:41:55.491: 7c:61:93:a4:ab:63 Not sending EAP-Failure for STA 7c:61:93:a4:ab:63

*osapiBsnTimer: Aug 23 14:42:05.482: 7c:61:93:a4:ab:63 apfMsExpireCallback (apf_ms.c:608) Expiring Mobile!

*apfReceiveTask: Aug 23 14:42:05.482: 7c:61:93:a4:ab:63 apfMsExpireMobileStation (apf_ms.c:5009) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc                               :fb:fb:d8:96:40 from Associated to Disassociated

*apfReceiveTask: Aug 23 14:42:05.482: 7c:61:93:a4:ab:63 Scheduling deletion of Mobile Station:  (callerId: 45) in 10 seconds

*osapiBsnTimer: Aug 23 14:42:15.482: 7c:61:93:a4:ab:63 apfMsExpireCallback (apf_ms.c:608) Expiring Mobile!

*apfReceiveTask: Aug 23 14:42:15.484: 7c:61:93:a4:ab:63 apfMsAssoStateDec

*apfReceiveTask: Aug 23 14:42:15.484: 7c:61:93:a4:ab:63 apfMsExpireMobileStation (apf_ms.c:5139) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc                               :fb:fb:d8:96:40 from Disassociated to Idle

*apfReceiveTask: Aug 23 14:42:15.484: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Deleted mobile LWAPP rule on AP [fc:fb:fb:d8:96:40]

13 Replies 13

Stephen Rodriguez
Cisco Employee
Cisco Employee

Reached Max EAP-Identity Request

The client is not responding to the WLC asking for it's Identity.  Then later sends an EAPOL start message.  You might want to adjust your EAP timers and see if that helps.

https://supportforums.cisco.com/docs/DOC-12110

HTH,
Steve

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

HTH,
Steve

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

Thanks for the quick response Stephen,

Here are our timers prior to the change. 

And here I changed the Identity Request Timers to 5 and 12:

I'll post back and let you know how it goes.  It is strange to me because we have had this system up and functional for many years, now we suddenly have a timer issue..........Any way more to come

Here is the same client after we made the timer changes.

The device still couldn't connect but we got much further:

*apfMsConnTask_0: Aug 23 15:38:39.686: 7c:61:93:a4:ab:63 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_0: Aug 23 15:38:39.686: 7c:61:93:a4:ab:63 Sending Assoc Response to station on BSSID fc:fb:fb:d8:96:40 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_0: Aug 23 15:38:39.686: 7c:61:93:a4:ab:63 apfProcessAssocReq (apf_80211.c:5237) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb:d8:96:40 from Associated to Associated

*dot1xMsgTask: Aug 23 15:38:39.694: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 15:38:39.695: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 1)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:40.069: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Reassociation received from mobile on AP fc:fb:fb:d8:96:40

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1626)

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Applying site-specific IPv6 override for station 7c:61:93:a4:ab:63 - vapId 1, site 'default-group', interface 'unf-wireless'

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Applying IPv6 Interface Policy for station 7c:61:93:a4:ab:63 - vlan 108, interface id 9, interface 'unf-wireless'

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 STA - rates (8): 18 150 24 36 48 72 96 108 0 0 0 0 0 0 0 0

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Processing RSN IE type 48, length 20 for mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Received RSN IE with 0 PMKIDs from mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) DHCP Not required on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1for this client

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb:d8:96:40 from Associated to Associated

*apfMsConnTask_0: Aug 23 15:38:41.448: 7c:61:93:a4:ab:63 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_0: Aug 23 15:38:41.449: 7c:61:93:a4:ab:63 Sending Assoc Response to station on BSSID fc:fb:fb:d8:96:40 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_0: Aug 23 15:38:41.449: 7c:61:93:a4:ab:63 apfProcessAssocReq (apf_80211.c:5237) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb:d8:96:40 from Associated to Associated

*dot1xMsgTask: Aug 23 15:38:41.452: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 15:38:41.452: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 1)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:41.457: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*apfLbsTask: Aug 23 15:38:45.615: 7c:61:93:a4:ab:63 Copy AP LOCP - mode:0 slotId:0, apMac 0xfc:fb:fb:d8:96:40

*apfLbsTask: Aug 23 15:38:45.615: 7c:61:93:a4:ab:63 Copy WLAN LOCP EssIndex:1 aid:3 ssid:unf-secure

*apfLbsTask: Aug 23 15:38:45.615: 7c:61:93:a4:ab:63 Copy Security LOCP ecypher:0x0 ptype:0x2, p:0x1, eaptype:0x6 w:0x1 aalg:0x0, PMState: 8021X_REQD

*apfLbsTask: Aug 23 15:38:45.616: 7c:61:93:a4:ab:63 Copy 802.11 LOCP a:0x0 b:0x0 c:0x0 d:0x0 e:0x1 protocol2:0x6 statuscode 0, reasoncode 99, status 3

*apfLbsTask: Aug 23 15:38:45.616: 7c:61:93:a4:ab:63 Copy MobilityData LOCP status:0, anchorip:0x0

*osapiBsnTimer: Aug 23 15:38:46.407: 7c:61:93:a4:ab:63 802.1x 'txWhen' Timer expired for station 7c:61:93:a4:ab:63 and for message = M0

*dot1xMsgTask: Aug 23 15:38:46.407: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 15:38:46.408: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 2)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.410: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.410: 7c:61:93:a4:ab:63 Username entry (unfcsd\n00781057) created for mobile

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.411: 7c:61:93:a4:ab:63 Received Identity Response (count=2) from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.411: 7c:61:93:a4:ab:63 EAP State update from Connecting to Authenticating for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.411: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Authenticating state

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.411: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.416: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.416: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=3) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.416: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 3)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.420: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.420: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 3, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.420: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.422: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.422: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=4) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.422: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 4)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.426: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.426: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 4, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.426: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.427: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.427: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=5) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.427: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 5)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.431: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.431: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 5, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.431: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.432: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.432: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=6) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.432: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 6)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.437: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.437: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 6, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.438: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.439: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.439: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=7) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.439: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 7)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.442: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.442: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 7, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.442: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.444: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.444: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=8) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.444: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 8)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.450: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.450: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 8, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.450: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.452: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.452: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=9) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.452: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 9)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.455: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.455: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 9, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.455: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.456: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.457: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=10) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.457: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 10)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.467: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.467: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 10, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.467: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.469: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.469: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=11) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.469: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 11)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.473: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.473: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 11, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.473: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.475: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.475: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=12) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.475: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 12)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.478: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.478: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 12, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.478: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.480: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.480: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=13) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.480: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 13)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.483: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.483: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 13, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.483: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.485: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.485: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=14) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.485: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 14)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.488: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.489: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 14, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.489: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.490: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.491: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=15) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.491: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 15)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.528: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.528: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 15, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.528: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.538: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.538: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=16) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.538: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 16)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.542: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.542: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 16, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.542: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.543: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.544: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=17) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.544: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 17)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.547: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.547: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 17, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.547: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.548: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.549: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=18) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.549: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 18)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.560: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.561: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 18, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.561: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.564: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.565: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=19) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:38:46.565: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 19)

*osapiBsnTimer: Aug 23 15:39:16.407: 7c:61:93:a4:ab:63 802.1x 'timeoutEvt' Timer expired for station 7c:61:93:a4:ab:63 and for message = M0

*dot1xMsgTask: Aug 23 15:39:16.407: 7c:61:93:a4:ab:63 Retransmit 1 of EAP-Request (length 84) for mobile 7c:61:93:a4:ab:63

*osapiBsnTimer: Aug 23 15:39:46.409: 7c:61:93:a4:ab:63 802.1x 'timeoutEvt' Timer expired for station 7c:61:93:a4:ab:63 and for message = M0

*dot1xMsgTask: Aug 23 15:39:46.410: 7c:61:93:a4:ab:63 Retransmit 2 of EAP-Request (length 84) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:46.423: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:46.423: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 19, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:46.423: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Association received from mobile on AP fc:fb:fb:d8:96:40

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1626)

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Applying site-specific IPv6 override for station 7c:61:93:a4:ab:63 - vapId 1, site 'default-group', interface 'unf-wireless'

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Applying IPv6 Interface Policy for station 7c:61:93:a4:ab:63 - vlan 108, interface id 9, interface 'unf-wireless'

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 STA - rates (8): 18 150 24 36 48 72 96 108 0 0 0 0 0 0 0 0

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Processing RSN IE type 48, length 20 for mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Received RSN IE with 0 PMKIDs from mobile 7c:61:93:a4:ab:63

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Initializing policy

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) DHCP Not required on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1for this client

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Not Using WMM Compliance code qosCap 00

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP fc:fb:fb:d8:96:40 vapId 1 apVapId 1

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb:d8:96:40 from Associated to Associated

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Stopping deletion of Mobile Station: (callerId: 48)

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 Sending Assoc Response to station on BSSID fc:fb:fb:d8:96:40 (status 0) ApVapId 1 Slot 0

*apfMsConnTask_0: Aug 23 15:39:50.072: 7c:61:93:a4:ab:63 apfProcessAssocReq (apf_80211.c:5237) Changing state for mobile 7c:61:93:a4:ab:63 on AP fc:fb:fb:d8:96:40 from Associated to Associated

*dot1xMsgTask: Aug 23 15:39:50.075: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*dot1xMsgTask: Aug 23 15:39:50.075: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 1)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.097: 7c:61:93:a4:ab:63 Received EAPOL START from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.104: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Connecting state

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.105: 7c:61:93:a4:ab:63 Sending EAP-Request/Identity to mobile 7c:61:93:a4:ab:63 (EAP Id 2)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.105: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.105: 7c:61:93:a4:ab:63 Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.113: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.114: 7c:61:93:a4:ab:63 Received Identity Response (count=2) from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.114: 7c:61:93:a4:ab:63 EAP State update from Connecting to Authenticating for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.114: 7c:61:93:a4:ab:63 dot1x - moving mobile 7c:61:93:a4:ab:63 into Authenticating state

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.114: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.119: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.119: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=3) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.119: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 3)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.124: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.124: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 3, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.124: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.125: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.126: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=4) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.126: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 4)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.129: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.129: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 4, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.129: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.130: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.130: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=5) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.130: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 5)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.133: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.133: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 5, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.133: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.134: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.135: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=6) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.135: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 6)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.139: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.139: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 6, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.139: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.140: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.141: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=7) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.141: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 7)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.144: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.144: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 7, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.144: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.152: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.153: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=8) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.153: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 8)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.156: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.156: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 8, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.156: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.157: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.157: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=9) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.157: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 9)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.161: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.161: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 9, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.161: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.162: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.163: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=10) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.163: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 10)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.166: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.166: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 10, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.166: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.167: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.167: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=11) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.167: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 11)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.182: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.182: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 11, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.183: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.191: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.191: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=12) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.191: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 12)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.202: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.203: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 12, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.203: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.205: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.205: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=13) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.213: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 13)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.216: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.217: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 13, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.217: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.219: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.219: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=14) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.219: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 14)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.222: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.223: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 14, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.223: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.224: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.224: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=15) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.225: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 15)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.260: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.260: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 15, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.260: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.274: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.275: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=16) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.275: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 16)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.278: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.278: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 16, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.278: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.279: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.279: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=17) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.280: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 17)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.282: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.282: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 17, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.282: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.284: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.284: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=18) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.284: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 18)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.298: 7c:61:93:a4:ab:63 Received EAPOL EAPPKT from mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.298: 7c:61:93:a4:ab:63 Received EAP Response from mobile 7c:61:93:a4:ab:63 (EAP Id 18, EAP Type 25)

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.298: 7c:61:93:a4:ab:63 Entering Backend Auth Response state for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.301: 7c:61:93:a4:ab:63 Processing Access-Challenge for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.301: 7c:61:93:a4:ab:63 Entering Backend Auth Req state (id=19) for mobile 7c:61:93:a4:ab:63

*Dot1x_NW_MsgTask_0: Aug 23 15:39:50.301: 7c:61:93:a4:ab:63 Sending EAP Request from AAA to mobile 7c:61:93:a4:ab:63 (EAP Id 19)

*apfLbsTask: Aug 23 15:39:57.614: 7c:61:93:a4:ab:63 Copy AP LOCP - mode:0 slotId:0, apMac 0xfc:fb:fb:d8:96:40

*apfLbsTask: Aug 23 15:39:57.614: 7c:61:93:a4:ab:63 Copy WLAN LOCP EssIndex:1 aid:3 ssid:unf-secure

*apfLbsTask: Aug 23 15:39:57.615: 7c:61:93:a4:ab:63 Copy Security LOCP ecypher:0x0 ptype:0x2, p:0x1, eaptype:0x2 w:0x1 aalg:0x0, PMState: 8021X_REQD

*apfLbsTask: Aug 23 15:39:57.615: 7c:61:93:a4:ab:63 Copy 802.11 LOCP a:0x0 b:0x0 c:0x0 d:0x0 e:0x1 protocol2:0x6 statuscode 0, reasoncode 1, status 3

*apfLbsTask: Aug 23 15:39:57.615: 7c:61:93:a4:ab:63 Copy MobilityData LOCP status:0, anchorip:0x0

*osapiBsnTimer: Aug 23 15:40:20.210: 7c:61:93:a4:ab:63 802.1x 'timeoutEvt' Timer expired for station 7c:61:93:a4:ab:63 and for message = M0

*dot1xMsgTask: Aug 23 15:40:20.210: 7c:61:93:a4:ab:63 Retransmit 1 of EAP-Request (length 84) for mobile 7c:61:93:a4:ab:63

We seem to be getting these syslog messages a lot as well.

%APF-1-USER_ADD_FAILED: apf_ms.c:5665 Unable to create username

Error Message %DOT1X-3-USER_LOGIN_DENY: Authentication rejected for user [chars] - user may already be logged in

We allow multiple logins on the same user id.  But since this is a login deny message I would assume it is contributing to our issue with users not being able to connect.

Any suggestions?

fbarboza
Level 4
Level 4

Hi,

As advised before try chaing the EAP timers and the EAPOL timers on the WLC.

config advanced eap identity-request-timeout 120
config advanced eap identity-request-retries 20
config advanced eap request-timeout 120
config advanced eap request-retries 20
config advanced eap eapol-key-timeout 5000
config advanced eap eapol-key-retries 4

Than make sure that under the WLAN you have configured to use only WPA2 + AES, then under the advance tab disable aironet IE, session time out, client exclusion and MFP protection.

Regarding the error:

%APF-1-USER_ADD_FAILED: apf_ms.c:5665 Unable to create username

Error Message %DOT1X-3-USER_LOGIN_DENY: Authentication rejected for user [chars] - user may already be logged in, this i being generated by the radius server doing the authentication that it sees that the current user has is already being used or reached the amount of users using the same user name and password.

jasonrakers
Level 1
Level 1

I am having the same issue with my clients.  Any other suggestions?  i tried fbarboza's suggestions, but no joy.

Solution was to upgrade to the latest version of code for the controllers.

There was a bug in the version of code I was using.  Since we upgraded everything has been going quite well.

There is a new code version out that helps with an issue related to Windows 8 Clients.  I would suggest using this software version if your system supports it.

Hi,

I think i'm having same problem , but in my case some of clients are authenticated.

I'm have seen following error:Retransmitting EAP-ID request to client,retransmission timer expired.

What controller version do you upgrade to?

Thanks

Best Regards

MC

We are on 7.0.235.3 now.

This code version fixes the problem above and a problem with Windows 8 clients.

What version of code did you start out on? Also, do you happen to know the bug ID from the Cisco Bug Search Tool?

There was no bug ID from Cisco.  This was a problem I stated with my TAC engineer when he recommended upgrading to 7.0.235.3 to fix our wireless authentication problems, but there is nothing noting this resovle in the release notes.  We were on 7.0.222, and the new code has resolved our issues - which makes me wonder if we had been having authentication problems ever since we upgraded to 7.0.222 and no one ever reported it..

There is a bug id for this issue.  I am having a contract problem so I can't look it up right now. But if you search using the bug toolkit you will find the Bug.  After I get my contract fixed I'll post the bug id if no one has already.

Here is the info from TAC:

appears to be impact of:

CSCts52226    the WLC refuse the EAP-ID response from the client

customer will upgrade to 7.0.235.0 for fix

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: