08-23-2012 12:06 PM - edited 07-03-2021 10:34 PM
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]
08-23-2012 12:11 PM
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
08-23-2012 12:32 PM
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
08-23-2012 01:05 PM
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
08-23-2012 02:05 PM
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?
08-27-2012 06:27 AM
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.
11-14-2012 06:13 AM
I am having the same issue with my clients. Any other suggestions? i tried fbarboza's suggestions, but no joy.
11-14-2012 06:24 AM
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.
11-28-2012 05:47 AM
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
11-28-2012 05:53 AM
We are on 7.0.235.3 now.
This code version fixes the problem above and a problem with Windows 8 clients.
11-29-2012 01:37 PM
What version of code did you start out on? Also, do you happen to know the bug ID from the Cisco Bug Search Tool?
11-30-2012 04:16 AM
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..
11-30-2012 07:00 AM
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.
11-30-2012 09:55 AM
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
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide