Re: Mobility Express APs points keep going offline then online

nalanguilan · ‎03-31-2019

Hi folks,

I have a mexpress controller with 5 1830 access points. I have been getting reports from users loosing wireless connection and have to reconnect again. and again.

======== start Part of the log:

rever: mutex lock operation failed. errcode = Resource deadlock avoided
Apr 1 01:57:00 eccp_mexpress.eccp.com ECCPAirAP1: *aaaQueueReader: Apr 01 09:57:00.496: %AAA-4-RADSERVER_NOT_FOUND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured
Apr 1 01:57:00 eccp_mexpress.eccp.com ECCPAirAP1: *Dot1x_NW_MsgTask_0: Apr 01 09:57:00.497: %LOG-4-Q_IND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured
Apr 1 01:57:00 eccp_mexpress.eccp.com ECCPAirAP1: *apfReceiveTask: Apr 01 09:57:00.499: %OSAPI-4-MUTEX_LOCK_FAILED: osapi_sem.c:1362 Failed to acquire a mutual exclusion object. waitforever: mutex lock operation failed. errcode = Resource deadlock avoided
Apr 1 01:57:00 eccp_mexpress.eccp.com ECCPAirAP1: *aaaQueueReader: Apr 01 09:57:00.500: %AAA-4-RADSERVER_NOT_FOUND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured
Apr 1 01:57:00 eccp_mexpress.eccp.com ECCPAirAP1: *Dot1x_NW_MsgTask_0: Apr 01 09:57:00.501: %LOG-4-Q_IND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured
Apr 1 01:57:11 eccp_mexpress.eccp.com ECCPAirAP1: *spamApTask0: Apr 01 09:57:11.574: %CAPWAP-3-ECHO_ERR: capwap_ac_sm.c:8034 Did not receive heartbeat reply; AP: b0:90:7e:a1:51:60
Apr 1 01:57:11 eccp_mexpress.eccp.com ECCPAirAP1: *spamApTask0: Apr 01 09:57:11.575: %CAPWAP-3-DTLS_CLOSED_ERR: capwap_ac_sm.c:7289 b0:90:7e:a1:51:60: DTLS connection closed forAP 192:168:0:44 (5264), Controller: 192:168:0:38 (5246) Echo Timer Expiry
Apr 1 01:57:11 eccp_mexpress.eccp.com ECCPAirAP1: *spamReceiveTask: Apr 01 09:57:11.576: %CAPWAP-4-INVALID_STATE_EVENT: capwap_ac_sm.c:9050 The system detects an invalid AP(b0:90:7e:a1:51:60) event (Capwap_configuration_update_request) and state (Capwap_dtls_teardown) combination
Apr 1 01:57:11 eccp_mexpress.eccp.com ECCPAirAP1: *spamApTask0: Apr 01 09:57:11.580: %CAPWAP-3-CCO_ASD_LOG_ERROR: spam_lrad.c:99028 CCO ASD logging failed on AP-MAC b0:90:7e:a0:3a:b8, reason: Index not found unable to delete tmp log
Apr 1 01:57:12 eccp_mexpress.eccp.com ECCPAirAP1: *spamApTask0: Apr 01 09:57:12.962: %CAPWAP-3-MAX_RETRANSMISSIONS_REACHED: capwap_ac_sm.c:7836 Max retransmissions reached on AP(00:7e:95:70:c1:80),message (CAPWAP_CONFIGURATION_UPDATE_REQUEST#015#012),number of pending messages(3)
Apr 1 01:57:12 eccp_mexpress.eccp.com ECCPAirAP1: *spamApTask0: Apr 01 09:57:12.963: %CAPWAP-3-DTLS_CLOSED_ERR: capwap_ac_sm.c:7289 00:7e:95:70:c1:80: DTLS connection closed forAP 192:168:0:42 (5272), Controller: 192:168:0:38 (5246) AP Message Timeout
Apr 1 01:57:12 eccp_mexpress.eccp.com ECCPAirAP1: *spamReceiveTask: Apr 01 09:57:12.965: %CAPWAP-4-INVALID_STATE_EVENT: capwap_ac_sm.c:9050 The system detects an invalid AP(00:7e:95:70:c1:80) event (Capwap_configuration_update_request) and state (Capwap_dtls_teardown) combination
Apr 1 01:57:12 eccp_mexpress.eccp.com ECCPAirAP1: *spamReceiveTask: Apr 01 09:57:12.965: %CAPWAP-4-INVALID_STATE_EVENT: capwap_ac_sm.c:9050 The system detects an invalid AP(00:7e:95:70:c1:80) event (Capwap_configuration_update_request) and state (Capwap_dtls_teardown) combination
Apr 1 01:57:12 eccp_mexpress.eccp.com ECCPAirAP1: *spamApTask0: Apr 01 09:57:12.967: %CAPWAP-3-CCO_ASD_LOG_ERROR: spam_lrad.c:99028 CCO ASD logging failed on AP-MAC 00:7e:95:70:17:a8, reason: Index not found unable to delete tmp log
Apr 1 01:57:21 eccp_mexpress.eccp.com ECCPAirAP1: *aaaQueueReader: Apr 01 09:57:21.516: %AAA-4-RADSERVER_NOT_FOUND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured
Apr 1 01:57:22 eccp_mexpress.eccp.com ECCPAirAP1: *aaaQueueReader: Apr 01 09:57:22.905: %AAA-4-RADSERVER_NOT_FOUND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured[...It occurred 2 times/sec!.]
Apr 1 01:57:32 eccp_mexpress.eccp.com ECCPAirAP1: *ConfigSynctoAp: Apr 01 09:57:32.037: %LOG-4-Q_IND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured[...It occurred 5 times.!]
Apr 1 01:57:32 eccp_mexpress.eccp.com ECCPAirAP1: *ConfigSynctoAp: Apr 01 09:57:32.037: %LWAPP-3-MSG_SEND_ERR: spam_api.c:75936 The system is unable to send Rsync to AP 192.168.0.43 Failed, ExidCode 30, File Type: ME Time File message to LWAPP; AP 2d94cd34:5a842d24:2d94c550:2d94c450:4063b447:2d94c550
Apr 1 01:57:33 eccp_mexpress.eccp.com ECCPAirAP1: *CAPWAP DATA: Apr 01 09:57:33.342: %RRM-3-RRM_LOGMSG: rrmClient.c:1314 RRM LOG: iapp chd, Unable to find AP 00:7e:95:70:c0:60
Apr 1 01:57:53 eccp_mexpress.eccp.com ECCPAirAP1: *vrrpConflictDetectionTask: Apr 01 09:57:53.720: %LOG-3-Q_IND: rrmClient.c:1314 RRM LOG: iapp chd, Unable to find AP 00:7e:95:70:c0:60
Apr 1 01:57:53 eccp_mexpress.eccp.com ECCPAirAP1: *vrrpConflictDetectionTask: Apr 01 09:57:53.720: %CNFGR-3-VRRP_CONFLICT_DETECTED: cnfgr.c:4933 VRRP group conflict detected with VRID 1!
Apr 1 01:58:09 eccp_mexpress.eccp.com ECCPAirAP1: *apfMsConnTask_0: Apr 01 09:58:09.230: %APF-3-PREAUTH_FAILURE: apf_80211.c:14910 There is no PMK cache entry for client40:9c:28:43:ff:9e. Can't do preauth
Apr 1 01:58:09 eccp_mexpress.eccp.com ECCPAirAP1: *apfMsConnTask_0: Apr 01 09:58:09.235: %APF-4-PROC_ACTION_FAILED: apf_80211k.c:786 Could not process 802.11 Action. Received RM 11K Action frame while not associated from mobile station. Mobile:40:9C:28:43:FF:9E.
Apr 1 01:58:09 eccp_mexpress.eccp.com ECCPAirAP1: *CAPWAP DATA: Apr 01 09:58:09.656: %LOG-4-Q_IND: apf_80211k.c:786 Could not process 802.11 Action. Received RM 11K Action frame while not associated from mobile station. Mobile:40:9C:28:43:FF:9E.
Apr 1 01:58:09 eccp_mexpress.eccp.com ECCPAirAP1: *CAPWAP DATA: Apr 01 09:58:09.656: %RRM-3-RRM_LOGMSG: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP 00:7e:95:70:c0:60
Apr 1 01:58:12 eccp_mexpress.eccp.com ECCPAirAP1: *Dot1x_NW_MsgTask_0: Apr 01 09:58:12.679: %LOG-3-Q_IND: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP 00:7e:95:70:c0:60
Apr 1 01:58:12 eccp_mexpress.eccp.com ECCPAirAP1: *apfReceiveTask: Apr 01 09:58:12.701: %OSAPI-4-MUTEX_LOCK_FAILED: osapi_sem.c:1362 Failed to acquire a mutual exclusion object. waitforever: mutex lock operation failed. errcode = Resource deadlock avoided
Apr 1 01:58:12 eccp_mexpress.eccp.com ECCPAirAP1: *aaaQueueReader: Apr 01 09:58:12.702: %AAA-4-RADSERVER_NOT_FOUND: radius_db.c:3770 Could not find appropriate RADIUS server for WLAN 0 - no aca accounting server configured

========== end part of the log

I also saw an entry in the logs:

XXXXAirAP1: *ConfigSynctoAp: Mar 30 10:54:07.928: %LWAPP-3-MSG_SEND_ERR: spam_api.c:75936 The system is unable to send Rsync to AP 192.168.0.41 Failed, ExidCode 30, File Type: WebAdminPrv file message to LWAPP; AP 2d96caf0:5ab5cd24:....

Does anyone from Cisco have a solution for this thing? The users are loosing patience. Help guys.

Leo Laohoo · ‎03-31-2019

What firmware is the WLC running on, 8.8.111.0?

nalanguilan · ‎03-31-2019

The WLC is running on 8.8.100.0

Leo Laohoo · ‎04-01-2019

And the wireless clients that are having issues are Intel-based? 7XXX and 8XXX series?

If this is the case, you might want to upgrade to 8.8.120.0 to fix CSCvn66715.

nalanguilan · ‎04-01-2019

I have downloaded the 8.8.120.0 and will update the firmware. I used to update using directly from cisco.com but all it gives me now is DNS: IP address not found. In any case, I may have to update the APs individually as the WLC goes on and off as well.

I don't exactly understand your first sentence but yes, the clients are intel based and the smartphones are also affected. If the series you're talking about are the APs, they're 1830s.

nalanguilan · ‎04-02-2019

Hello. Just and update. We were able to update the software to 8.8.120.0 but we are still getting reboots from four out of five APs -- blinking green light then blinking red/green light...

The last four lines of the log:

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

D_ERR: capwap_ac_sm.c:7331 b0:90:7e:a1:1f:a0: DTLS connection closed forAP 192:168:0:43 (5248), Controller: 192:168:0:38 (5246) Echo Timer Expiry
Apr 2 11:55:58 ECCPAirAP1: *apfReceiveTask: Apr 02 19:55:58.629: %CAPWAP-4-INVALID_STATE_EVENT: capwap_ac_sm.c:9092 The system detects an invalid AP(b0:90:7e:a1:57:a0) event (Capwap_configuration_update_request) and state (Capwap_join) combination
Apr 2 11:55:58 ECCPAirAP1: *apfReceiveTask: Apr 02 19:55:58.631: %CAPWAP-4-INVALID_STATE_EVENT: capwap_ac_sm.c:9092 The system detects an invalid AP(b0:90:7e:a1:57:a0) event (Capwap_configuration_update_request) and state (Capwap_join) combination
Apr 2 11:56:11 ECCPAirAP1: *httpImgDwnldTask0: Apr 02 19:56:11.588: %CAPWAP-3-PRED_ERR3: capwap_ac_img_dwnld.c:1840 ECCPAir_AP6: Curl returned error code= 28 , err_string: Timeout was reached

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

Do you guys have any other ideas as I am tired and currently out of fresh ideas.

Thank you.

Leo Laohoo · ‎04-02-2019

@nalanguilan wrote:

We were able to update the software to 8.8.120.0 but we are still getting reboots from four out of five APs

I have re-read the start of the thread and nowhere was it ever mentioned that the APs were rebooting.

Can you go to Management > Tech Support > AP Crash Logs and see if there are recent crash logs there?

nalanguilan · ‎04-03-2019

Hello Leo,

Apologies if I did not mentioned the reboots. Frustration and tinge of panic can make me overlook things.

I do not have the Management - Tech Support option the the Mobility Express interface. I do have the Advanced - Controller Tools - Troubleshooting files where I can download the Support Bundle. Do you want me to upload it?

Update: After we were able update Mobility Express version 8.8.100.0 to version 8.8.120.0 last night the 1832 APs seem to settle down and when I came in the APs has stopped disappearing/appearing from the ME dashboard, only two APs were blinking. The AP status lights have stopped blinking and has been a steady green since this noon.

I am observing them and the dash and will try to go over the external logs of the ME.

nalanguilan · ‎04-03-2019

Hi folks,

After about 40 hours of all 6 APs being visible in the ME dashboard they have started disappearing again after a few minutes started randomly appearing in the AP list in the dash.

I downloaded the Troubleshooting Tools and found this in the /ctrl/msg.txt file (part of it). It appears that the APs go offline and try to join again but failing:

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

b0:90:7e:a1:57:a0
*CAPWAP DATA: Apr 04 11:03:45.694: %LOG-3-Q_IND: rrmClient.c:1314 RRM LOG: iapp chd, Unable to find AP b0:90:7e:a1:51:60
*CAPWAP DATA: Apr 04 11:03:45.511: %RRM-3-RRM_LOGMSG: rrmClient.c:1314 RRM LOG: iapp chd, Unable to find AP b0:90:7e:a1:51:60
*CAPWAP DATA: Apr 04 11:03:16.172: %RRM-3-RRM_LOGMSG: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP 00:7e:95:70:c1:80
*Dot1x_NW_MsgTask_0: Apr 04 11:03:06.202: %DOT1X-3-BAD_BUFFER_LENGTH: 1x_eapkey.c:3420 Invalid buffer length in KDF function x:384 keyLen:0 outputLen:48
*apfReceiveTask: Apr 04 11:03:06.200: %LOG-3-Q_IND: rrmClient.c:1192 RRM LOG: IAPP AGGR Neigh, Unable to find AP b0:90:7e:a1:51:60
*CAPWAP DATA: Apr 04 11:03:02.767: %RRM-3-RRM_LOGMSG: rrmClient.c:1192 RRM LOG: IAPP AGGR Neigh, Unable to find AP b0:90:7e:a1:51:60
*CAPWAP DATA: Apr 04 11:03:02.767: %LOG-3-Q_IND: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP b0:90:7e:a1:51:60
*CAPWAP DATA: Apr 04 11:02:59.756: %RRM-3-RRM_LOGMSG: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP b0:90:7e:a1:51:60
*spamApTask0: Apr 04 11:02:41.838: %CAPWAP-3-AP_AUTOCONVERT_ERR: capwap_ac_sm.c:3742 The system is unable to autoconvert AP b0:90:7e:a1:1f:a0 to supported mode.
*spamApTask0: Apr 04 11:02:34.749: %CAPWAP-3-AP_AUTOCONVERT_ERR: capwap_ac_sm.c:3742 The system is unable to autoconvert AP 00:7e:95:70:c1:80 to supported mode.
*ConfigSynctoAp: Apr 04 11:02:20.753: %LWAPP-3-MSG_SEND_ERR: spam_api.c:76458 The system is unable to send Rsync to AP 192.168.0.41 Failed, ExidCode 30, File Type: Opendns cert message to LWAPP; AP 2da13eb4:5af78d24:2da1361c:2da13494:45442220:2da1361c
*spamReceiveTask: Apr 04 11:02:16.776: %CAPWAP-3-DTLS_CONN_ERR: capwap_ac.c:1118 b0:90:7e:a1:1f:a0: DTLS connection not found forAP 192.168.0.43 (5248), Controller: 192.168.0.38 (5246) send packet
*CAPWAP DATA: Apr 04 11:02:15.673: %LOG-3-Q_IND: rrmClient.c:1314 RRM LOG: iapp chd, Unable to find AP b0:90:7e:a1:51:60
*ConfigSynctoAp: Apr 04 11:02:04.367: %LWAPP-3-MSG_SEND_ERR: spam_api.c:76458 The system is unable to send Rsync to AP 192.168.0.41 Failed, ExidCode 255, File Type: Credential file message to LWAPP; AP 2da13554:5af78d24:2da13594:2da13494:2b0a59d8:2da13594
*ConfigSynctoAp: Apr 04 11:01:45.667: %LWAPP-3-MSG_SEND_ERR: spam_api.c:76458 The system is unable to send Rsync to AP 192.168.0.41 Failed, ExidCode 30, File Type: WebAdminPrv file message to LWAPP; AP 2da13b34:5af78d24:2da13a60:2da13494:40878447:2da13a60
*ConfigSynctoAp: Apr 04 11:01:30.522: %LWAPP-3-MSG_SEND_ERR: spam_api.c:76458 The system is unable to send Rsync to AP 192.168.0.41 Failed, ExidCode 30, File Type: WebAdminCert file message to LWAPP; AP 2da13af4:5af78d24:2da13a60:2da13494:40878447:2da13a6
*ConfigSynctoAp: Apr 04 11:01:30.522: %LOG-3-Q_IND: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP b0:90:7e:a1:51:60
*CAPWAP DATA: Apr 04 11:01:29.696: %RRM-3-RRM_LOGMSG: rrmClient.c:1542 RRM LOG: iapp chd client stat , Unable to find AP b0:90:7e:a1:51:60
*vrrpConflictDetectionTask: Apr 04 11:01:05.482: %CNFGR-3-VRRP_CONFLICT_DETECTED: cnfgr.c:4943 VRRP group conflict detected with VRID 1!

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

If anyone has any ideas, please... ?

Another weird thing I found is in the Update Software section under Cisco.com which I made a screenshot of. We have ME 8.8.1200.0 installed but it is showing that the latest updated from Cisco is 8.8.100.0

Thank you.

cam0001 · ‎02-23-2020

I am having this issue as well (Aironet 1832i with ME), with firmware 8.10.112.0. any ideas?

Furanity · ‎05-02-2020

I'm having this issue too (also on the 1830 series, 4x 1832i in my case). Tried multiple firmwares and am now on 8.10.121.0. Have this issue with ALL my devices, Windows machines, Mac's, iPhones, so it doesn't really seem to be related to the clients.

Tried 8.10.112.0, 8.10.105.0, 8.8.111.0, all to no avail. Didn't have the issues as much with older firmwares, but I'm not sure if I was in 8.7.102.0, 8.6.101.0 or 8.5.105.0, so I'll try one of those.

I'm a bit disappointed in the stability of the Mobility Express firmware, honestly.

patoberli · ‎05-04-2020

Can you show your log please?

cam0001 · ‎05-04-2020

I had this issue before (rebooting for no reason) with 8.10.112.0. The one I found to be stable in my case was 8.8.120.0 (you might want to try that one).

The other option (and to rule out not being on the latest) is to try 8.10.121.0 (which is the last one released and is marked as the suggested release. (However, I wouldn't hold my breath on this one).

03300209 · ‎09-25-2022

I have same feeling with you.