AP Radios disconnecting Randomly

[Richard Imus]

Hello!

We're experiencing an issue where all wireless clients are being disconnected randomly throughout the day, however it doesn't show the APs went down because the uptime is still showing it's been up for a long time.

I've looked through the logs in the WLC and I saw some logs where the radios are going down. below are examples of the logs we're seeing. Apparently it's happening to all APs. I've checked the switch ports where our APs are connected and they have been up and no logs of going down. I'm also not seeing any errors in the switch interfaces.

Anyone know what's causing the APs to disassociate? Please help.

137	Thu Oct 20 07:10:48 2022	AP's Interface:0(802.11abgn) Operation State Down: Base Radio MAC:34:b8:83:5f:e2:00 Cause=RADIO_RC_CODE_UNDEF: Radio reset due to (0) Unknown Reset Status:NA

138	Thu Oct 20 07:10:46 2022	AP 'APA00F.378F.1A94', MAC: 34:b8:83:5f:e2:00 disassociated previously due to Link Failure. Uptime: 28 days, 22 h 19 m 10 s . Reason: Capwap Discovery Request.

[marce1000]

 - If you have intranet firewalling between the ap's and the controller then make sure that  ports 5647 and 5646 (UDP) are allowed at all times, for the rest make sure basic network connectivity for the access points is stable (look at interface counters). Or use for instance  logging event link-status on ports where access points are connected. Check switch logs (afterwards) or use a syslog server (better).

 M.

[Richard Imus]

Thanks for your reply. we did check our firewall and we're not seeing anything being blocked but we're not seeing anything being allowed either. I've also looked at the interface counters of the switchports and they are clean. i'll check about the logging event link-status.

[marce1000]

 - If nothing turns up try a reboot of the controller.

 M.

[Arshad Safrulla]

Can you login to the impacted AP itself and post the logs from there. Also post more info such as WLC model, code, AP model etc. I would also check whether the AP is getting the full power from the switchport as well

[Richard Imus]

Hi Arshad, this is what we have right now.

WLC: 3504 running 8.10.171.0 code

AP: C9120AXI-D

Based on the switchports they're getting full power.

Unfortunately i couldn't get SSH to work on the APs even though I have assigned username and passwords in them.

[marce1000]

                     >...i couldn't get SSH to work

                  (controller)>config ap ssh enable all

 M.

[Richard Imus]

I was able to login to one of the AP that had a radio reset below are the logs from AP and the WLC

Logs from WLC:

12 Thu Oct 20 22:44:29 2022 AP's Interface:1(802.11a) Operation State Up: Base Radio MAC:34:b8:83:5f:e2:00 Cause=RADIO_RC_CODE_UNDEF: Radio reset due to (0) Unknown Reset Status:NA
13 Thu Oct 20 22:44:29 2022 AP's Interface:0(802.11abgn) Operation State Down: Base Radio MAC:34:b8:83:5f:e2:00 Cause=RADIO_RC_CODE_UNDEF: Radio reset due to (0) Unknown Reset Status:NA

Logs from AP:

Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.8580] capwapd: reading file /click/nss_lag_control/lacp_state: No such file or directory
Oct 20 22:44:26 capwapd[5269]: reading /click/nss_lag_control/lacp_state failed [2]: No such file or directory
Oct 20 22:44:26 capwapd[5269]: reading /click/nss_lag_control/capwap_state failed [2]: No such file or directory
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.8590]
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.8590] !!!!! {/opt/cisco/bin/capwapd} reading /click/nss_lag_control/lacp_state failed [2]: No such file or directory
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.8590] capwapd: reading file /click/nss_lag_control/capwap_state: No such file or directory
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.8590]
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.8590] !!!!! {/opt/cisco/bin/capwapd} reading /click/nss_lag_control/capwap_state failed [2]: No such file or directory
Oct 20 22:44:26 capwapd[5269]: Check lagloadbalance setting flex mode 0 cfg 0 linkstate 1 ap_type 86
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.0430] DOT11_CFG[1]: Starting radio 1
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.0430] DOT11_DRV[1]: Start Radio1
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.0500] DOT11_DRV[1]: set_channel Channel set to 157/20
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.4520] Started Radio 1
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.9730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Configure(8).
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.9730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Configure(8).
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.9730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Configure(8).
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.9730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Configure(8).
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.9730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Configure(8).
Oct 20 22:44:27 kernel: [*10/20/2022 22:44:27.9730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Configure(8).
Oct 20 22:44:28 kernel: [*10/20/2022 22:44:28.5000] Null cert id for TLV_AP_CACERTS_CONFIG_PAYLOAD
Oct 20 22:44:29 kernel: [*10/20/2022 22:44:29.0200]
Oct 20 22:44:29 kernel: [*10/20/2022 22:44:29.0200] CAPWAP State: Run
Oct 20 22:44:29 kernel: [*10/20/2022 22:44:29.0640] AP has joined controller wlc1.hyd1
Oct 20 22:44:31 chpasswd: password for user changed
Oct 20 22:44:31 kernel: [*10/20/2022 22:44:31.1710] chpasswd: password for user changed
Oct 20 22:44:31 kernel: [*10/20/2022 22:44:31.3150] apphost feature is not supported
Oct 20 22:44:31 kernel: [*10/20/2022 22:44:31.3960] Got WSA Server config TLVs
Oct 20 22:44:31 kernel: [*10/20/2022 22:44:31.6890]
Oct 20 22:44:31 kernel: [*10/20/2022 22:44:31.6890] Same LSC mode, no action needed
Oct 20 22:44:31 kernel: [*10/20/2022 22:44:31.6960] DOT11_DRV[0]: set_channel Channel set to 1/20
Oct 20 22:44:32 kernel: [*10/20/2022 22:44:32.4380] wl: Unsupported
Oct 20 22:44:32 kernel: [*10/20/2022 22:44:32.4380] ERROR: return from vap_amsdu_rx_max was -45
Oct 20 22:44:32 kernel: [*10/20/2022 22:44:32.7520] wl: Busy
Oct 20 22:44:32 kernel: [*10/20/2022 22:44:32.7700] DOT11_DRV[0]: failed to set Radio 0 HE/802.11ax BSS Color to 1
Oct 20 22:44:32 kernel: [*10/20/2022 22:44:32.7770] wl: Unsupported
Oct 20 22:44:33 kernel: [*10/20/2022 22:44:33.1540] DOT11_DRV[1]: set_channel Channel set to 157/20
Oct 20 22:44:34 kernel: [*10/20/2022 22:44:34.3750] wl: Unsupported
Oct 20 22:44:34 kernel: [*10/20/2022 22:44:34.3750] ERROR: return from vap_amsdu_rx_max was -45
Oct 20 22:44:36 kernel: [*10/20/2022 22:44:36.0160] wl: Unsupported
Oct 20 22:44:36 kernel: [*10/20/2022 22:44:36.3810] DOT11_DRV[2]: off_chhannel RX timeout, ch = 149
Oct 20 22:44:36 kernel: [*10/20/2022 22:44:36.3810] DOT11_DRV[2]: RHL: Off-channel done received but there are no pending requests! , rc_counter = 0
Oct 20 22:44:36 kernel: [*10/20/2022 22:44:36.9670] size: 17410 bytes (48126 left)
Oct 20 22:44:37 kernel: [*10/20/2022 22:44:37.5930] size: 17410 bytes (48126 left)
Oct 20 22:44:38 kernel: [*10/20/2022 22:44:38.0380] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=25, NumofPendingMsgs=7
Oct 20 22:44:38 kernel: [*10/20/2022 22:44:38.0380]
Oct 20 22:44:38 kernel: [*10/20/2022 22:44:38.0400] systemd[1]: Starting Cisco syslogd watcher...

[Arshad Safrulla]

What is the DCA timer set? If it is 10mins pls make sure that you increase it to somewhere north of 4 hours.

I don’t see any conclusive evidence form the logs pointing to an issue. Please make sure that best practices are followed.

Pls disable Cleanair and SI until the AP becomes stable. Pls allow RRM to to assign channels, don’t use static channel assignments.

[Richard Imus]

I've been going through the AP logs and noticed that the AP at some point went to discovery mode due to "Max retransmission count exceeded". The time that it happened, there was a log in the WLC for that particular AP as well. Could this be the cause? if it is, is it safe to increase the retransmission count in the global config?

Logs from WLC:

Thu Oct 20 22:44:29 2022

AP's Interface:0(802.11abgn) Operation State Down: Base Radio MAC:34:b8:83:5f:e2:00 Cause=RADIO_RC_CODE_UNDEF: Radio reset due to (0) Unknown Reset Status:NA

Logs from AP:

Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.3020] Max retransmission count exceeded, going back to DISCOVER mode.
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.3020] Dropping msg CAPWAP_WTP_EVENT_REQUEST, type = 34, len = 550, eleLen = 558, sendSeqNum = 143
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.3020] ...Vendor SubType: AP_CDP_CACHE_PAYLOAD(24) len: 546 vendId 409600
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.3020] GOING BACK TO DISCOVER MODE
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.3180]
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.3180] CAPWAP State: DTLS Teardown
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.4160] DOT11_DRV[1]: Stop Radio1
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.4160] Stopped Radio 1
Oct 20 22:43:52 upgrade: Script called with args:[ABORT]
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.4940] upgrade.sh: Script called with args:[ABORT]
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.5370] do ABORT, part1 is active part
Oct 20 22:43:52 upgrade: Cleanup tmp files ...
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.5540] upgrade.sh: Cleanup tmp files ...
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.5730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
Oct 20 22:43:52 kernel: [*10/20/2022 22:43:52.5730] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.0700]
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.0700] CAPWAP State: Discovery
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.0710] IP DNS query for CISCO-CAPWAP-CONTROLLER.knoah.com
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.0720] systemd[1]: Starting dhcpv6 client watcher...
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.0840] systemd[1]: Stopping DHCPv6 client...
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.0880] systemd[1]: Starting DHCPv6 client...
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.1210] systemd[1]: Started DHCPv6 client.
Oct 20 22:44:07 kernel: [*10/20/2022 22:44:07.1400] systemd[1]: Started dhcpv6 client watcher.
Oct 20 22:44:17 kernel: [*10/20/2022 22:44:17.1120] Discovery Request sent to 10.160.12.11, discovery type STATIC_CONFIG(1)
Oct 20 22:44:17 kernel: [*10/20/2022 22:44:17.1130] Discovery Request sent to 255.255.255.255, discovery type UNKNOWN(0)
Oct 20 22:44:17 kernel: [*10/20/2022 22:44:17.1140] Discovery Response from 10.160.12.11
Oct 20 22:44:17 kernel: [*10/20/2022 22:44:17.1150] Discovery Response from 10.160.12.11
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.0000]
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.0000] CAPWAP State: DTLS Setup
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.7410]
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.7410] CAPWAP State: Join
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.7440] Sending Join request to 10.160.12.11 through port 5248
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.7480] Join Response from 10.160.12.11
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.7480] AC accepted join request with result code: 0
Oct 20 22:44:26 kernel: [*10/20/2022 22:44:26.7630] Received wlcType 0, timer 30

[Richard Imus]

I was looking at the WLC traps and noticed that before the AP radios reset, the AP goes through some Tx power changes as seen in the logs below. Not sure what's triggering RRM to run its algorithm, we have couple other sites and which we are not seeing the same issue nor logs. We're thinking of playing with fixed power levels and see if the situation improves but if someone has suggestion or comments please feel free to drop them. thanks. 

71	Fri Oct 28 10:52:21 2022	AP's Interface:1(802.11a) Operation State Up: Base Radio MAC:34:b8:83:60:07:00 Cause=RADIO_RC_CODE_UNDEF: Radio reset due to (0) Unknown Reset Status:NA
72	Fri Oct 28 10:52:21 2022	AP's Interface:0(802.11abgn) Operation State Down: Base Radio MAC:34:b8:83:60:07:00 Cause=RADIO_RC_CODE_UNDEF: Radio reset due to (0) Unknown Reset Status:NA
73	Fri Oct 28 10:52:19 2022	AP 'APA00F.378F.1F34', MAC: 34:b8:83:60:07:00 disassociated previously due to AP Reset. Uptime: 6 days, 15 h 22 m 50 s . Reason: Unknown.
74	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP APA00F.378F.1F34 Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 5 Reason: DTPC Tx Power value: 7 dbm
75	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP APA00F.378F.1F34 Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 1 Reason: DTPC Tx Power value: 23 dbm
76	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP APA00F.378F.1F34 Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 7 Reason: DTPC Tx Power value: 5 dbm
77	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP APA00F.378F.1F34 Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC with Max Tx Power value: 0 dbm
78	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP APA00F.378F.1F34 Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11bg New Tx Power level is: 0 Reason: DTPC with Max Tx Power value: 0 dbm
79	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
80	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
81	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
82	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
83	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
84	Fri Oct 28 10:52:19 2022	RF Manager updated TxPower for AP Base Radio MAC: 34:b8:83:60:07:00 and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm

[Rich R]

https://www.cisco.com/c/en/us/td/docs/wireless/controller/technotes/8-3/b_RRM_White_Paper/tpc.html

https://www.cisco.com/c/en/us/td/docs/wireless/controller/8-10/config-guide/b_cg810/radio_resource_management.html#ID70