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

WLC roaming debug assistance

I'm in a position where I need to prove that a suppliers device doesn't truly roam between APs on a WLC. The device will eventually drop the AP when the signal is low enough and then re-authenticate to a new AP, but it doesn't seamlessly roam.

As far as proving it, on the WLC Client Detail page, the device doesn't support CCX extensions, which, as far as I understand, is probably evidence enough in itself.

I've also logged the device and have only ever seen

xx:xx:xx:xx:xx Association received from mobile on BSSID aa:aa:aa:aa:aa

I've never seen a

xx:xx:xx:xx:xx Reassociation received from mobile on BSSID aa:aa:aa:aa:aa

Is that evidence enough that that device doesn't actually roam?

Is there a more elegant way, in layman's terms, to prove the point?

 

 

6 REPLIES
VIP Purple

Hi,If you go to your WLC CLI

Hi,

If you go to your WLC CLI  get "debug client <Client_MAC_Add>" you will see the full details of client connection flow. That will tells you seamless roaming occur or not. Attach that output onto your next response to see.

Also here is some reference post to understand what it involve in wireless roaming

http://mrncciew.com/2014/09/02/cwsp-802-11-roaming-basics/ 

HTH

Rasika

**** Pls rate all useful responses ****

Community Member

Thanks for your reply. I've

Thanks for your reply. I've already been running debug but what is not clear to me is how to prove that the device is not roaming, it is just losing signal and finding a new device to re-authenticate to.

I've attached the debug from a few days ago.

It should be obvious but 00:80:48:78:50:65 is the device that is not roaming and a4:17:31:25:00:e7 is a laptop that (hopefully) is roaming.

VIP Purple

HiI can see multiple time

Hi

I can see multiple time given client authentication failed. So it is look like given client unable to connect to the network.  See the reference time interval & Access-Reject message for this client.

 

*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 Processing Access-Reject for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 apfMsPeapSimReqFailureCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 PMK: Sending cache delete
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 Removing PMK cache entry for station 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 1 PMK-remove groupcast messages sent 
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 Removing PMK cache due to EAP-Failure for mobile 00:80:48:78:50:65 (EAP Id 167)
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 Sending EAP-Failure to mobile 00:80:48:78:50:65 (EAP Id 167)
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.536: 00:80:48:78:50:65 Entering Backend Auth Failure state (id=167) for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.537: 00:80:48:78:50:65 Setting quiet timer for 5 seconds for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:43:20.537: 00:80:48:78:50:65 dot1x - moving mobile 00:80:48:78:50:65 into Unknown state

.

.

*osapiBsnTimer: Sep 22 10:44:31.404: 00:80:48:78:50:65 802.1x 'timeoutEvt' Timer expired for station 00:80:48:78:50:65 and for message = M0
*dot1xMsgTask: Sep 22 10:44:31.404: 00:80:48:78:50:65 Retransmit 1 of EAP-Request (length 95) for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.418: 00:80:48:78:50:65 Received EAPOL EAPPKT from mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.419: 00:80:48:78:50:65 Received EAP Response from mobile 00:80:48:78:50:65 (EAP Id 231, EAP Type 25)
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.419: 00:80:48:78:50:65 Resetting reauth count 0 to 0 for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.419: 00:80:48:78:50:65 Entering Backend Auth Response state for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 Processing Access-Reject for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 apfMsPeapSimReqFailureCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 1 PMK-remove groupcast messages sent 
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 Removing PMK cache due to EAP-Failure for mobile 00:80:48:78:50:65 (EAP Id 231)
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 Sending EAP-Failure to mobile 00:80:48:78:50:65 (EAP Id 231)
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 Entering Backend Auth Failure state (id=231) for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 Setting quiet timer for 5 seconds for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:44:31.423: 00:80:48:78:50:65 dot1x - moving mobile 00:80:48:78:50:65 into Unknown state

.

.

 

*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.319: 00:80:48:78:50:65 Resetting reauth count 0 to 0 for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.320: 00:80:48:78:50:65 Entering Backend Auth Response state for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Processing Access-Reject for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 apfMsPeapSimReqFailureCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 1 PMK-remove groupcast messages sent 
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Removing PMK cache due to EAP-Failure for mobile 00:80:48:78:50:65 (EAP Id 140)
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Sending EAP-Failure to mobile 00:80:48:78:50:65 (EAP Id 140)
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Entering Backend Auth Failure state (id=140) for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 apfBlacklistMobileStationEntry2 (apf_ms.c:6172) Changing state for mobile 00:80:48:78:50:65 on AP 6c:99:89:77:41:e0 from Associated to Exclusion-list (1)

*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Scheduling deletion of Mobile Station:  (callerId: 44) in 10 seconds
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 10.0.45.201 8021X_REQD (3) Change state to START (0) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 10.0.45.201 START (0) Reached FAILURE: from line 5620
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Scheduling deletion of Mobile Station:  (callerId: 9) in 10 seconds
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Max AAA failure for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 Setting quiet timer for 5 seconds for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:47:28.327: 00:80:48:78:50:65 dot1x - moving mobile 00:80:48:78:50:65 into Unknown state
*osapiBsnTimer: Sep 22 10:47:33.204: 00:80:48:78:50:65 802.1x 'quiteWhile' Timer expired for station 00:80:48:78:50:65 and for message = M0
*osapiBsnTimer: Sep 22 10:47:38.204: 00:80:48:78:50:65 apfMsExpireCallback (apf_ms.c:632) Expiring Mobile!
*apfReceiveTask: Sep 22 10:47:38.204: 00:80:48:78:50:65 Freeing EAP Retransmit Bufer for mobile 00:80:48:78:50:65
*apfReceiveTask: Sep 22 10:47:38.204: 00:80:48:78:50:65 Sent Deauthenticate to mobile on BSSID 6c:99:89:77:41:e0 slot 0(caller apf_ms.c:7065)

..

.

*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.223: 00:80:48:78:50:65 Sending EAP Request from AAA to mobile 00:80:48:78:50:65 (EAP Id 31)
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.223: 00:80:48:78:50:65 Reusing allocated memory for  EAP Pkt for retransmission to mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.233: 00:80:48:78:50:65 Received EAPOL EAPPKT from mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.233: 00:80:48:78:50:65 Received EAP Response from mobile 00:80:48:78:50:65 (EAP Id 31, EAP Type 25)
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.233: 00:80:48:78:50:65 Resetting reauth count 0 to 0 for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.233: 00:80:48:78:50:65 Entering Backend Auth Response state for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.240: 00:80:48:78:50:65 Processing Access-Reject for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.240: 00:80:48:78:50:65 apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.240: 00:80:48:78:50:65 apfMsPeapSimReqFailureCntInc
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.241: 00:80:48:78:50:65 1 PMK-remove groupcast messages sent 
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.241: 00:80:48:78:50:65 Removing PMK cache due to EAP-Failure for mobile 00:80:48:78:50:65 (EAP Id 31)
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.241: 00:80:48:78:50:65 Sending EAP-Failure to mobile 00:80:48:78:50:65 (EAP Id 31)
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.241: 00:80:48:78:50:65 Entering Backend Auth Failure state (id=31) for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.241: 00:80:48:78:50:65 Setting quiet timer for 5 seconds for mobile 00:80:48:78:50:65
*Dot1x_NW_MsgTask_5: Sep 22 10:52:47.241: 00:80:48:78:50:65 dot1x - moving mobile 00:80:48:78:50:65 into Unknown state

Also few times client forced to go to START status from RUN status with below reasoning. Make sure you disable management frame protection (802.11w) on this WLAN. Also if this is FlexConnect deployment, make sure you use FlexConnect Group if you required to support Opportunistic Key Caching (kind of fast roaming)

 

*apfMsConnTask_7: Sep 22 11:02:23.723: 00:80:48:78:50:65 apfValidateDot11wGroupMgmtCipher:1552, Received NULL 11w Group Mgmt Cipher Suite for STA, hence returning

*apfMsConnTask_7: Sep 22 11:02:23.723: 00:80:48:78:50:65 AID 1 in Assoc Req from flex AP 68:86:a7:29:cf:60 is same as in mscb 00:80:48:78:50:65
*apfMsConnTask_7: Sep 22 11:02:23.723: 00:80:48:78:50:65 apfMsRunStateDec
*apfMsConnTask_7: Sep 22 11:02:23.723: 00:80:48:78:50:65 apfMs1xStateDec
*apfMsConnTask_7: Sep 22 11:02:23.723: 00:80:48:78:50:65 10.0.45.201 RUN (20) Change state to START (0) last state RUN (20)

HTH

Rasika

**** Pls rate all useful responses ****

Community Member

 Thanks for having a look at

 Thanks for having a look at the debug. I see the three auth failures at the start but I'm really only interested in roaming. Hence my original question

 

 

Thanks for looking at the debug output. I see the three auth failures at the start and MFP is set to optional on that WLAN.

I'm really only interested in roaming at this point. Any other issues are secondary.

Hence my original question in relation to association, reassociation and CCX.

xx:xx:xx:xx:xx Association received from mobile on BSSID aa:aa:aa:aa:aa

xx:xx:xx:xx:xx Reassociation received from mobile on BSSID aa:aa:aa:aa:aa

VIP Purple

Since we cannot see

Since we cannot see successful authentication to the network you won't see any further re-association.

yes, to start the roaming process client station has to send "reassociation request" to an AP.

HTH

Rasika

**** Pls rate all useful responses ****

Community Member

I'm confused. Isn't there a

I'm confused. Isn't there a successful authentication at 11:01 to AP03 and then another successful authentication at 11:02 to AP01 for 00:80:48:78:50:65?

393
Views
1
Helpful
6
Replies
CreatePlease to create content