Problem with clients connecting to wlan WPA2-AES

Unanswered Question
Aug 23rd, 2012
User Badges:

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]

  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 3 (1 ratings)
Loading.
Stephen Rodriguez Thu, 08/23/2012 - 12:11
User Badges:
  • Purple, 4500 points or more

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

its-neteng Thu, 08/23/2012 - 12:32
User Badges:

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

its-neteng Thu, 08/23/2012 - 13:05
User Badges:

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

its-neteng Thu, 08/23/2012 - 14:05
User Badges:

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 Mon, 08/27/2012 - 06:27
User Badges:
  • Bronze, 100 points or more

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 Wed, 11/14/2012 - 06:13
User Badges:

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.

etmarcof Wed, 11/28/2012 - 05:47
User Badges:

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

scottplank Thu, 11/29/2012 - 13:37
User Badges:

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

jasonrakers Fri, 11/30/2012 - 04:16
User Badges:

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..

Actions

This Discussion

 

 

Trending Topics: Other Wireless Mobility

client could not be authenticated
Network Analysis Module (NAM) Products
Cisco 6500 nam
reason 440 driver failure
Cisco password cracker
Cisco Wireless mode