Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
Announcements

Welcome to Cisco Support Community. We would love to have your feedback.

For an introduction to the new site, click here. If you'd prefer to explore, try our test area to get started. And see here for current known issues.

802.1X EAP-PEAP Authentication issue

Hi Experts,

I am experiencing an issue where the authentication process for two of my Wireless networks prompts the user to enter their credentials at least two times before letting them onto the network.

The networks in question  are set up identically, here is an overview:

Layer 2 security is WPA & WPA2

WPA - TKIP

WPA2 - AES

Auth Key Management is 802.1X

Radius Servers are microsoft Windows 2008 Network Policy Service (Used to be IAS) - All users are in Active Directory and IAS policy allows access absed on AD group.

This has all worked fine previously and still works fine if you enter the username/password combo at least twice on the initial profile setup. (For info, once the wireless profile is setup, you do not get prompted for credentials again, so this issue is ony during intial setup)

We have recently added another WLAN that uses web auth, pointing to a RADIUS server to. In order to get this going, we changed the "Web Radius Authentication" setting to "CHAP" from "PAP" under the Controller . General config.


This is the only change I can think of that could possibly be relevant.

Would anyone be able to shed any light on why I would be prompted to authenticate twice? Affected clients are Windows 7 and Mac OSX at the mo.


Debugs as follows:

*Oct 11 16:12:10.237: 00:23:12:08:25:28 Adding mobile on LWAPP AP 00:13:5f:fb:0f:40(0)
*Oct 11 16:12:10.237: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 23) in 5 seconds
*Oct 11 16:12:10.237: 00:23:12:08:25:28 apfProcessProbeReq (apf_80211.c:4598) Changing state for mobile 00:23:12:08:25:28 on AP 00:13:5f:fb:0f:40 from Idle to Probe

*Oct 11 16:12:10.237: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:10.238: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:10.247: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:10.247: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:10.247: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:10.388: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.076: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.076: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.076: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.077: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.086: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.086: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.228: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.229: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:11.239: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.296: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.305: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.306: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.306: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.317: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.448: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.449: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.458: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.459: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.600: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:14.610: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.715: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.715: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.715: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.725: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.725: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.725: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.868: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:16.878: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:17.031: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:19.927: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:19.934: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:19.938: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:19.938: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:20.080: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:20.080: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:20.090: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:20.233: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:20.243: 00:23:12:08:25:28 Scheduling deletion of Mobile Station:  (callerId: 24) in 5 seconds
*Oct 11 16:12:24.941: 00:23:12:08:25:28 apfMsExpireCallback (apf_ms.c:417) Expiring Mobile!
*Oct 11 16:12:24.941: 00:23:12:08:25:28 0.0.0.0 START (0) Deleted mobile LWAPP rule on AP [00:13:5f:fb:0f:40]
*Oct 11 16:12:24.941: 00:23:12:08:25:28 Deleting mobile on AP 00:13:5f:fb:0f:40(0)
*Oct 11 16:12:25.219: 00:23:12:08:25:28 Adding mobile on LWAPP AP 00:11:5c:14:6d:d0(0)
*Oct 11 16:12:25.219: 00:23:12:08:25:28 Reassociation received from mobile on AP 00:11:5c:14:6d:d0
*Oct 11 16:12:25.219: 00:23:12:08:25:28 STA - rates (8): 139 150 24 36 48 72 96 108 0 0 0 0 0 0 0 0
*Oct 11 16:12:25.219: 00:23:12:08:25:28 STA - rates (10): 139 150 24 36 48 72 96 108 12 18 0 0 0 0 0 0
*Oct 11 16:12:25.219: 00:23:12:08:25:28 Processing RSN IE type 48, length 20 for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.219: 00:23:12:08:25:28 Received RSN IE with 0 PMKIDs from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.219: 00:23:12:08:25:28 0.0.0.0 START (0) Initializing policy
*Oct 11 16:12:25.219: 00:23:12:08:25:28 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state AUTHCHECK (2)

*Oct 11 16:12:25.219: 00:23:12:08:25:28 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)

*Oct 11 16:12:25.219: 00:23:12:08:25:28 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:11:5c:14:6d:d0 vapId 4 apVapId 4
*Oct 11 16:12:25.220: 00:23:12:08:25:28 apfPemAddUser2 (apf_policy.c:208) Changing state for mobile 00:23:12:08:25:28 on AP 00:11:5c:14:6d:d0 from Idle to Associated

*Oct 11 16:12:25.220: 00:23:12:08:25:28 Stopping deletion of Mobile Station: (callerId: 48)
*Oct 11 16:12:25.220: 00:23:12:08:25:28 Sending Assoc Response to station on BSSID 00:11:5c:14:6d:d0 (status 0)
*Oct 11 16:12:25.220: 00:23:12:08:25:28 apfProcessAssocReq (apf_80211.c:4310) Changing state for mobile 00:23:12:08:25:28 on AP 00:11:5c:14:6d:d0 from Associated to Associated

*Oct 11 16:12:25.223: 00:23:12:08:25:28 Disable re-auth, use PMK lifetime.
*Oct 11 16:12:25.223: 00:23:12:08:25:28 Station 00:23:12:08:25:28 setting dot1x reauth timeout = 7200
*Oct 11 16:12:25.223: 00:23:12:08:25:28 dot1x - moving mobile 00:23:12:08:25:28 into Connecting state
*Oct 11 16:12:25.223: 00:23:12:08:25:28 Sending EAP-Request/Identity to mobile 00:23:12:08:25:28 (EAP Id 1)
*Oct 11 16:12:25.243: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.243: 00:23:12:08:25:28 Received Identity Response (count=1) from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.243: 00:23:12:08:25:28 EAP State update from Connecting to Authenticating for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.243: 00:23:12:08:25:28 dot1x - moving mobile 00:23:12:08:25:28 into Authenticating state
*Oct 11 16:12:25.243: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.250: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.250: 00:23:12:08:25:28 Entering Backend Auth Req state (id=2) for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.251: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 2)
*Oct 11 16:12:25.260: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.262: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 2, EAP Type 25)
*Oct 11 16:12:25.262: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.265: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.265: 00:23:12:08:25:28 Entering Backend Auth Req state (id=3) for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.265: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 3)
*Oct 11 16:12:25.269: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.269: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 3, EAP Type 25)
*Oct 11 16:12:25.269: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.270: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.271: 00:23:12:08:25:28 Entering Backend Auth Req state (id=4) for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.271: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 4)
*Oct 11 16:12:25.274: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.274: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 4, EAP Type 25)
*Oct 11 16:12:25.274: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.275: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.275: 00:23:12:08:25:28 Entering Backend Auth Req state (id=5) for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.275: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 5)
*Oct 11 16:12:25.285: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.286: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 5, EAP Type 25)
*Oct 11 16:12:25.286: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.292: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.292: 00:23:12:08:25:28 Entering Backend Auth Req state (id=6) for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.292: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 6)
*Oct 11 16:12:25.318: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.318: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 6, EAP Type 25)
*Oct 11 16:12:25.318: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.320: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.320: 00:23:12:08:25:28 Entering Backend Auth Req state (id=7) for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.320: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 7)
*Oct 11 16:12:25.321: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:12:25.323: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 7, EAP Type 25)
*Oct 11 16:12:25.323: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.326: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:12:25.326: 00:23:12:08:25:28 Entering Backend Auth Req state (id=8) for mobile 00:23:12:08:25:28

*Oct 11 16:12:25.326: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 8)

At this point, the username and password dialog pops up again.

If credentials are not entered, the following timeout message pops up....

*Oct 11 16:12:53.973: 00:23:12:08:25:28 802.1x 'timeoutEvt' Timer expired for station 00:23:12:08:25:28

If the credentials are re-entered the it continues:


*Oct 11 16:12:53.975: 00:23:12:08:25:28 Retransmit 1 of EAP-Request (length 79) for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.093: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:13:01.093: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 8, EAP Type 25)
*Oct 11 16:13:01.094: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.098: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.098: 00:23:12:08:25:28 Entering Backend Auth Req state (id=9) for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.098: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 9)
*Oct 11 16:13:01.102: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:13:01.102: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 9, EAP Type 25)
*Oct 11 16:13:01.102: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.106: 00:23:12:08:25:28 Processing Access-Challenge for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.106: 00:23:12:08:25:28 Entering Backend Auth Req state (id=10) for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.106: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 10)
*Oct 11 16:13:01.108: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28
*Oct 11 16:13:01.108: 00:23:12:08:25:28 Received EAP Response from mobile 00:23:12:08:25:28 (EAP Id 10, EAP Type 25)
*Oct 11 16:13:01.108: 00:23:12:08:25:28 Entering Backend Auth Response state for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.113: 00:23:12:08:25:28 Processing Access-Accept for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.113: 00:23:12:08:25:28 Setting re-auth timeout to 7200 seconds, got from WLAN config.
*Oct 11 16:13:01.113: 00:23:12:08:25:28 Station 00:23:12:08:25:28 setting dot1x reauth timeout = 7200
*Oct 11 16:13:01.113: 00:23:12:08:25:28 Creating a PKC PMKID Cache entry for station 00:23:12:08:25:28 (RSN 2)
*Oct 11 16:13:01.113: 00:23:12:08:25:28 Adding BSSID 00:11:5c:14:6d:d3 to PMKID cache for station 00:23:12:08:25:28
*Oct 11 16:13:01.113: New PMKID: (16)

*Oct 11 16:13:01.113:      [0000] 15 9e 3d 61 e3 94 bb 82 2b 6f 7e 05 74 49 81 52

*Oct 11 16:13:01.113: 00:23:12:08:25:28 Disabling re-auth since PMK lifetime can take care of same.
*Oct 11 16:13:01.116: 00:23:12:08:25:28 PMK sent to mobility group
*Oct 11 16:13:01.116: 00:23:12:08:25:28 Sending EAP-Success to mobile 00:23:12:08:25:28 (EAP Id 10)
*Oct 11 16:13:01.116: Including PMKID in M1  (16)

*Oct 11 16:13:01.116:      [0000] 15 9e 3d 61 e3 94 bb 82 2b 6f 7e 05 74 49 81 52

*Oct 11 16:13:01.116: 00:23:12:08:25:28 Starting key exchange to mobile 00:23:12:08:25:28, data packets will be dropped
*Oct 11 16:13:01.116: 00:23:12:08:25:28 Sending EAPOL-Key Message to mobile 00:23:12:08:25:28
   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Oct 11 16:13:01.116: 00:23:12:08:25:28 Entering Backend Auth Success state (id=10) for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.116: 00:23:12:08:25:28 Received Auth Success while in Authenticating state for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.116: 00:23:12:08:25:28 dot1x - moving mobile 00:23:12:08:25:28 into Authenticated state
*Oct 11 16:13:01.996: 00:23:12:08:25:28 802.1x 'timeoutEvt' Timer expired for station 00:23:12:08:25:28
*Oct 11 16:13:01.997: 00:23:12:08:25:28 Retransmit 1 of EAPOL-Key M1 (length 121) for mobile 00:23:12:08:25:28
*Oct 11 16:13:01.999: 00:23:12:08:25:28 Received EAPOL-Key from mobile 00:23:12:08:25:28
*Oct 11 16:13:01.999: 00:23:12:08:25:28 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 00:23:12:08:25:28
*Oct 11 16:13:01.999: 00:23:12:08:25:28 Received EAPOL-key in PTK_START state (message 2) from mobile 00:23:12:08:25:28
*Oct 11 16:13:01.999: 00:23:12:08:25:28 Stopping retransmission timer for mobile 00:23:12:08:25:28
*Oct 11 16:13:02.000: 00:23:12:08:25:28 Sending EAPOL-Key Message to mobile 00:23:12:08:25:28
   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.02
*Oct 11 16:13:02.002: 00:23:12:08:25:28 Received EAPOL-Key from mobile 00:23:12:08:25:28
*Oct 11 16:13:02.002: 00:23:12:08:25:28 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 00:23:12:08:25:28
*Oct 11 16:13:02.002: 00:23:12:08:25:28 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:23:12:08:25:28
*Oct 11 16:13:02.002: 00:23:12:08:25:28 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state L2AUTHCOMPLETE (4)

*Oct 11 16:13:02.004: 00:23:12:08:25:28 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:11:5c:14:6d:d0 vapId 4 apVapId 4
*Oct 11 16:13:02.004: 00:23:12:08:25:28 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)

*Oct 11 16:13:02.006: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4391, Adding TMP rule
*Oct 11 16:13:02.007: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
  type = Airespace AP - Learn IP address
  on AP 00:11:5c:14:6d:d0, slot 0, interface = 29, QOS = 0
  ACL Id = 255, Jumbo F
*Oct 11 16:13:02.007: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)
*Oct 11 16:13:02.007: 00:23:12:08:25:28 Stopping retransmission timer for mobile 00:23:12:08:25:28
*Oct 11 16:13:02.010: 00:23:12:08:25:28 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*Oct 11 16:13:02.010: 00:23:12:08:25:28 Sent an XID frame
*Oct 11 16:13:02.283: 00:23:12:08:25:28 DHCP received op BOOTREQUEST (1) (len 308, port 29, encap 0xec03)
*Oct 11 16:13:02.283: 00:23:12:08:25:28 DHCP dropping packet due to ongoing mobility handshake exchange, (siaddr 0.0.0.0,  mobility state = 'apfMsMmQueryRequested'
*Oct 11 16:13:03.906: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*Oct 11 16:13:03.906: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4072, Adding TMP rule
*Oct 11 16:13:03.906: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
  type = Airespace AP - Learn IP address
  on AP 00:11:5c:14:6d:d0, slot 0, interface = 29, QOS = 0
  ACL Id = 255, Jumb
*Oct 11 16:13:03.906: 00:23:12:08:25:28 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)
*Oct 11 16:13:03.909: 00:23:12:08:25:28 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*Oct 11 16:13:03.909: 00:23:12:08:25:28 Sent an XID frame
*Oct 11 16:13:04.879: 00:23:12:08:25:28 DHCP received op BOOTREQUEST (1) (len 308, port 29, encap 0xec03)
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP selecting relay 1 - control block settings:
            dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
            dhcpGateway: 0.0.0.0, dhcpRelay: 0.0.0.0  VLAN: 0
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP selected relay 1 - 172.19.0.50 (local address 172.23.24.2, gateway 172.23.24.1, VLAN 110, port 29)
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP transmitting DHCP REQUEST (3)
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP   op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP   xid: 0x53839a5f (1401133663), secs: 4, flags: 0
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP   chaddr: 00:23:12:08:25:28
*Oct 11 16:13:04.880: 00:23:12:08:25:28 DHCP   ciaddr: 0.0.0.0,  yiaddr: 0.0.0.0
*Oct 11 16:13:04.881: 00:23:12:08:25:28 DHCP   siaddr: 0.0.0.0,  giaddr: 172.23.24.2
*Oct 11 16:13:04.881: 00:23:12:08:25:28 DHCP   requested ip: 172.23.26.53
*Oct 11 16:13:04.881: 00:23:12:08:25:28 DHCP sending REQUEST to 172.23.24.1 (len 350, port 29, vlan 110)
*Oct 11 16:13:04.881: 00:23:12:08:25:28 DHCP selecting relay 2 - control block settings:
            dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
            dhcpGateway: 0.0.0.0, dhcpRelay: 172.23.24.2  VLAN: 110
*Oct 11 16:13:04.881: 00:23:12:08:25:28 DHCP selected relay 2 - 172.19.0.51 (local address 172.23.24.2, gateway 172.23.24.1, VLAN 110, port 29)
*Oct 11 16:13:04.881: 00:23:12:08:25:28 DHCP transmitting DHCP REQUEST (3)
*Oct 11 16:13:04.883: 00:23:12:08:25:28 DHCP   op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 2
*Oct 11 16:13:04.883: 00:23:12:08:25:28 DHCP   xid: 0x53839a5f (1401133663), secs: 4, flags: 0
*Oct 11 16:13:04.883: 00:23:12:08:25:28 DHCP   chaddr: 00:23:12:08:25:28
*Oct 11 16:13:04.883: 00:23:12:08:25:28 DHCP   ciaddr: 0.0.0.0,  yiaddr: 0.0.0.0
*Oct 11 16:13:04.883: 00:23:12:08:25:28 DHCP   siaddr: 0.0.0.0,  giaddr: 172.23.24.2
*Oct 11 16:13:04.883: 00:23:12:08:25:28 DHCP   requested ip: 172.23.26.53
*Oct 11 16:13:04.885: 00:23:12:08:25:28 DHCP sending REQUEST to 172.23.24.1 (len 350, port 29, vlan 110)
*Oct 11 16:13:04.890: 00:23:12:08:25:28 DHCP received op BOOTREPLY (2) (len 327, port 29, encap 0xec00)
*Oct 11 16:13:04.890: 00:23:12:08:25:28 DHCP setting server from ACK (server 172.19.0.50, yiaddr 172.23.26.53)
*Oct 11 16:13:04.890: 00:23:12:08:25:28 172.23.26.53 DHCP_REQD (7) Change state to RUN (20) last state RUN (20)

*Oct 11 16:13:04.890: 00:23:12:08:25:28 172.23.26.53 RUN (20) Reached PLUMBFASTPATH: from line 4856
*Oct 11 16:13:04.891: 00:23:12:08:25:28 172.23.26.53 RUN (20) Replacing Fast Path rule
  type = Airespace AP Client
  on AP 00:11:5c:14:6d:d0, slot 0, interface = 29, QOS = 0
  ACL Id = 255, Jumbo Frames = N
*Oct 11 16:13:04.891: 00:23:12:08:25:28 172.23.26.53 RUN (20) Successfully plumbed mobile rule (ACL ID 255)
*Oct 11 16:13:04.891: 00:23:12:08:25:28 Assigning Address 172.23.26.53 to mobile
*Oct 11 16:13:04.891: 00:23:12:08:25:28 DHCP sending REPLY to STA (len 430, port 29, vlan 0)
*Oct 11 16:13:04.892: 00:23:12:08:25:28 DHCP transmitting DHCP ACK (5)
*Oct 11 16:13:04.892: 00:23:12:08:25:28 DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*Oct 11 16:13:04.892: 00:23:12:08:25:28 DHCP   xid: 0x53839a5f (1401133663), secs: 0, flags: 0
*Oct 11 16:13:04.892: 00:23:12:08:25:28 DHCP   chaddr: 00:23:12:08:25:28
*Oct 11 16:13:04.892: 00:23:12:08:25:28 DHCP   ciaddr: 0.0.0.0,  yiaddr: 172.23.26.53
*Oct 11 16:13:04.894: 00:23:12:08:25:28 DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0
*Oct 11 16:13:04.894: 00:23:12:08:25:28 DHCP   server id: 1.1.1.1  rcvd server id: 172.19.0.50
*Oct 11 16:13:04.898: 00:23:12:08:25:28 172.23.26.53 Added NPU entry of type 1, dtlFlags 0x0
*Oct 11 16:13:04.900: 00:23:12:08:25:28 Sending a gratuitous ARP for 172.23.26.53, VLAN Id 110
*Oct 11 16:13:04.907: 00:23:12:08:25:28 DHCP received op BOOTREPLY (2) (len 327, port 29, encap 0xec00)
*Oct 11 16:13:04.907: 00:23:12:08:25:28 DHCP dropping ACK from 172.19.0.51 (yiaddr: 172.23.26.53)

At this point, the client is connected and everything is working.

1 ACCEPTED SOLUTION

Accepted Solutions
Cisco Employee

Re: 802.1X EAP-PEAP Authentication issue

Hi,

In Windows 7, in your wireless network properties, in the security tab, click on advanced settings, and try to set the authentication mode as "User authentication mode" in the 802.1x tab to see if it helps.

Regards,

bastien

8 REPLIES
Cisco Employee

Re: 802.1X EAP-PEAP Authentication issue

Hi,

It looks like some issue on the client side...

Thelogs presented here are not related with the Web Auth WLAN and it has no impact on the behavior you are seeing.

Looking at the logs:

----------------------------------

*Oct 11 16:12:25.326: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 8)

At this point, the username and password dialog pops up again.

If credentials are not entered, the following timeout message pops up....

*Oct 11 16:12:53.973: 00:23:12:08:25:28 802.1x 'timeoutEvt' Timer expired for station 00:23:12:08:25:28

If the credentials are re-entered the it continues:

*Oct 11 16:12:53.975: 00:23:12:08:25:28 Retransmit 1 of EAP-Request (length 79) for mobile 00:23:12:08:25:28

*Oct 11 16:13:01.093: 00:23:12:08:25:28 Received EAPOL EAPPKT from mobile 00:23:12:08:25:28

===================

This logs show exactly what you describe...

The AAA sends an EAP request asking for the credentials.

The login pops up and the EAP timeout starts decrementing.

If the user does not enter credentials, it will expire and another EAP Request is sent.

If you let the EAP timeout it is expected that you enter credentials twice, if by the time you press enter, the timeout has already expired.

As you say, if you have a profile configured, this should not happen and the authentication should be smooth.

HTH,
Tiago

Re: 802.1X EAP-PEAP Authentication issue

Hi Tiago,

Thanks for th reply - I am just concerned because at the point where I am seeing:

*Oct 11 16:12:25.326: 00:23:12:08:25:28 Sending EAP Request from AAA to mobile 00:23:12:08:25:28 (EAP Id 8)

I have already enetred my username and password combo into the client as a result of the Wireless connection requesting it. So at the point when the above message is logged, I have waited for  a small period of time and am then being prompted to do it again.

I am sure that this never used to be the case, but it is happening on a variety of clients at the moment, this is being noticed as all of the students are now coming back wishing to connect their equipment to the wireless.

At the end of the day, it is not a huge problem because entering credentials twice does make the connection work and from then on the profile is saved and works correctly, it would be nice to get to the bottom of what is causing the issue though!

I may try a few different clients today and see what happens,

Many thanks

Jonathan

Re: 802.1X EAP-PEAP Authentication issue

Just my 2 cents: it could be radius server related. After all, the WLC is just forwarding authentication between IAS and client.

You can give a quick shot with local eap on WLC or freeradius or something, the issue might not show up.

Regards,

Nicolas

Re: 802.1X EAP-PEAP Authentication issue

Hi all,

Just tested again, Windows XP client defintely only gets asked once, as does iPhone. Windows 7 defintely gets asked twice each time.


Wiondering whether there is a setting on the Win 7 & Apple Mac clients that could be causing this...

RADIUS seems to be happy - also, I only see one request come into the RADIUS server each time, so it seems like only one of the two authentication requests is actually going through to RADIUS...

I will keep investigating...

Many thanks

Jonathan

Cisco Employee

Re: 802.1X EAP-PEAP Authentication issue

Hi,

In Windows 7, in your wireless network properties, in the security tab, click on advanced settings, and try to set the authentication mode as "User authentication mode" in the 802.1x tab to see if it helps.

Regards,

bastien

Re: 802.1X EAP-PEAP Authentication issue

Funny you should say that! Just found that setting and am testing as we speak, will let you know what happens...

Many thanks

Jonathan

Re: 802.1X EAP-PEAP Authentication issue

Hi,

Checking the "User authentication only option " in the 802.1X settings has solved this issue.

I compared a debug between a Win 7 client prior to this change and an XP client debug, and you could see the Win 7 Client first attempting to use its machine name:

Oct 12 08:22:41.454: 00:24:d6:49:15:4e Username entry   (host/LAPTOP) created for mobile

LAPTOP is the hostname in this example. the EAP process continues on and fails. Once I had checked the above checkbox for user auth, the debug shows that the correct username is used in the EAP process from the start:

*Oct 12 09:49:22.729: 00:24:d6:49:15:4e Username entry (oohstud) created for mobile

OOHSTUD is the user account in this example.

All goes through without prompting twice now.

Many thanks for all of your help, I'm off to update my documentation!

Cheers

Jonathan

New Member

Had this exact same issue

Had this exact same issue with Windows 7 with the profile already set to "User authentication".  My fix was in the wireless profile, security tab, advanced settings and checking "Enable single sign on for this network" and selecting "Perform immediately after user login". The other SSO settings can be tweaked afterwards. I hope this helps.

4953
Views
8
Helpful
8
Replies