Re: WLC 2504 - retransmission to the AP has reached maximum error

rengaraj.p · ‎03-07-2022

Our WLC running on 8.5.171(recently upgraded) with 1852 AP's every four or five hours my AP's are disconnecting from the controller for unknown reason, Switchport is up, AP uptime is good, so the AP is not rebooting, but AP couldn't able to join the controller. All AP's are in Flexconnect mode with Flex connect local switching enabled.
Controller log: Show AP join stats 00:00:00 shows that

Last AP connection failure: "retransmission to the AP has reached maximum"

last Error occurred: "AP got or has been disconnected"

Last AP disconnect reason: "Unknown failure reason"

or

Last join error summary
- Type of error that occurred last......................... AP got or has been disconnected
- Reason for error that occurred last...................... Timed out while waiting for ECHO repsonse from the AP
- Time at which the last join error occurred...............

AP disconnect details
- Reason for last AP connection failure.................... Timed out while waiting for ECHO repsonse from the AP

Rebooted controller, rebooted all AP's

Have 25 AP's, around 17 AP's are facing this issue per day,
any immediate help will be appreciable

Scott Fella · ‎03-07-2022

Did the issue start after you upgraded? Was there any other changes to the network? Any reason why you are not reverting back to the code prior to the upgrade?

-Scott
*** Please rate helpful posts ***

rengaraj.p · ‎03-07-2022

Hi Thank for response , because of this long pending issue we upgraded..., no issues in the LAN

Scott Fella · ‎03-08-2022

Okay, to be clear, this issue with ap's disassociating with the controller has been happening prior to the upgrade? Since your ap's are in FlexConnect and I'm assuming located in a different location than the controller, it can be a WAN issue. How far away is the access points from the controller? What is the link between the two location? Do you have any issue when you have a FlexConnect ap located in the same LAN as the controller?

-Scott
*** Please rate helpful posts ***

rengaraj.p · ‎03-08-2022

Hi Even the APs are in flex connect, it is located in the same building same vlan

MHM Cisco World · ‎03-07-2022

There are many reason but let start one by one

FW are fw open both port for CAPWAP ? If one of them is block then echo from WLC to ap and return path drop.

NAT timeout or misconfig this make ap WLC face reachability issue

asymmetric routing, ap use different path than WLC.

rengaraj.p · ‎03-07-2022

Yes FW ports 5246 & 5247 are open, FYI, all the ap's, sw's &fw's in the same network locally, even the ap's are connected in flexmode. So do we need to check NAT timeout ?

MHM Cisco World · ‎03-08-2022

Hi friend,
I see the attachment photo,
why the Join Statistic show MAX number of AP ? what is the number of AP in your WLC license?

for NAT check the FW if PAT entry when the AP is disconnect.

when AP is disconnect do show cdp in switch AP connect and check if the AP have IP address.

rengaraj.p · ‎03-08-2022

thanks for your reply, we have 25 AP licenses in WLC and 26 AP's are there, one AP we made down ot avoid license issue. and FYI we have WLC HA, i will check the CDP while disconnecting. out of 25 AP's only 17 AP's are acting this weird, these AP's are connecting in three different switches, on the same vlan.

MHM Cisco World · ‎03-08-2022

https://rscciew.wordpress.com/category/ap-joining-issues-to-wlc/

check this link.

rengaraj.p · ‎03-08-2022

Mar 8 04:50:04 kernel: [*03/08/2022 04:50:04.7791] save_on_failure is set to 1
Mar 8 04:50:04 kernel: [*03/08/2022 04:50:04.7791] save_on_failure is set to 1
Mar 8 04:50:04 FIPS[26077]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 8 04:50:04 FIPS[26079]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:50:08 kernel: [*03/09/2022 05:50:08.3380] ol_if_dfs_enable: called
Mar 9 05:50:08 kernel: [*03/09/2022 05:50:08.3380] ieee80211_dfs_cac_start CAC Still Valid. Skip CAC
Mar 9 05:50:09 kernel: [*03/09/2022 05:50:09.3877] ol_if_dfs_enable: called
Mar 9 05:50:10 kernel: [*03/09/2022 05:50:10.4374] ol_if_dfs_enable: called
Mar 9 05:51:19 kernel: [*03/09/2022 05:51:19.1943] Re-Tx Count=1, Max Re-Tx Value=8, SendSeqNum=20, NumofPendingMsgs=2
Mar 9 05:51:19 kernel: [*03/09/2022 05:51:19.1943]
Mar 9 05:51:23 kernel: [*03/09/2022 05:51:23.9528] Re-Tx Count=2, Max Re-Tx Value=8, SendSeqNum=20, NumofPendingMsgs=2
Mar 9 05:51:23 kernel: [*03/09/2022 05:51:23.9528]
Mar 9 05:51:28 kernel: [*03/09/2022 05:51:28.7013] Re-Tx Count=3, Max Re-Tx Value=8, SendSeqNum=20, NumofPendingMsgs=2
Mar 9 05:51:28 kernel: [*03/09/2022 05:51:28.7013]
Mar 9 05:51:33 kernel: [*03/09/2022 05:51:33.4599] Re-Tx Count=4, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=4
Mar 9 05:51:33 kernel: [*03/09/2022 05:51:33.4599]
Mar 9 05:51:38 kernel: [*03/09/2022 05:51:38.2084] Re-Tx Count=5, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=4
Mar 9 05:51:38 kernel: [*03/09/2022 05:51:38.2084]
Mar 9 05:51:42 kernel: [*03/09/2022 05:51:42.9569] Re-Tx Count=6, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=4
Mar 9 05:51:42 kernel: [*03/09/2022 05:51:42.9569]
Mar 9 05:51:47 kernel: [*03/09/2022 05:51:47.7054] Re-Tx Count=7, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=4
Mar 9 05:51:47 kernel: [*03/09/2022 05:51:47.7054]
Mar 9 05:51:52 kernel: [*03/09/2022 05:51:52.4639] Re-Tx Count=8, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=4
Mar 9 05:51:52 kernel: [*03/09/2022 05:51:52.4639]
Mar 9 05:51:57 kernel: [*03/09/2022 05:51:57.2224] Re-Tx Count=9, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=4
Mar 9 05:51:57 kernel: [*03/09/2022 05:51:57.2224]
Mar 9 05:51:57 kernel: [*03/09/2022 05:51:57.2224] Max retransmission count exceeded, going back to DISCOVER mode.
Mar 9 05:51:57 kernel: [*03/09/2022 05:51:57.2224] Flexconnect Switching to Standalone Mode!
Mar 9 05:51:57 kernel: [*03/09/2022 05:51:57.3024]
Mar 9 05:51:57 kernel: [*03/09/2022 05:51:57.3024] CAPWAP State: DTLS Teardown
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.0850] Discovery Response from 192.168.162.65
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.1150] Discovery Response from 192.168.162.66
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.0000]
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.0000] CAPWAP State: DTLS Setup
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.2499]
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.2499] CAPWAP State: Join
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.2599] Sending Join request to 192.168.162.65 through port 5272
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.2599] Join Response from 192.168.162.65
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.3699]
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.3699] CAPWAP State: Image Data
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.4199] do NO_UPGRADE, part2 is active part
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.4199]
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.4199] CAPWAP State: Configure
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.4199] DOT11_CFG[0] Radio Mode is changed from FlexConnect to FlexConnect
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.4199] DOT11_CFG[1] Radio Mode is changed from FlexConnect to FlexConnect
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.7098]
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.7098] CAPWAP State: Run
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.8597] AP has joined controller IN02WLC-P
Mar 9 05:52:21 kernel: [*03/09/2022 05:52:21.8797] Flexconnect Switching to Connected Mode!
Mar 9 05:52:22 kernel: [*03/09/2022 05:52:22.0397] DOT11_DRV[0]: Stop Radio0
Mar 9 05:52:22 kernel: [*03/09/2022 05:52:22.0597] DOT11_DRV[0]: Start Radio0
Mar 9 05:52:22 kernel: [*03/09/2022 05:52:22.3596] DOT11_DRV[1]: Stop Radio1
Mar 9 05:52:22 kernel: [*03/09/2022 05:52:22.3596] ol_if_dfs_enable: called
Mar 9 05:52:22 kernel: [*03/09/2022 05:52:22.3796] DOT11_DRV[1]: Start Radio1
Mar 9 05:52:22 kernel: [*03/09/2022 05:52:22.3896] ol_if_dfs_enable: called
Mar 9 05:52:23 kernel: [*03/09/2022 05:52:23.1793] /usr/sbin/capwapd: opening /click/cli_h/apr_bypass/active failed!: No such file or directory
Mar 9 05:52:23 FIPS[26483]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:52:23 FIPS[26492]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:52:23 kernel: [*03/09/2022 05:52:23.8891] save_on_failure is set to 1
Mar 9 05:52:23 kernel: [*03/09/2022 05:52:23.8991] save_on_failure is set to 1
Mar 9 05:52:24 FIPS[26494]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:52:24 FIPS[26496]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:52:27 kernel: [*03/09/2022 05:52:27.4180] ol_if_dfs_enable: called
Mar 9 05:52:27 kernel: [*03/09/2022 05:52:27.4180] ieee80211_dfs_cac_start CAC Still Valid. Skip CAC
Mar 9 05:52:28 kernel: [*03/09/2022 05:52:28.4677] ol_if_dfs_enable: called
Mar 9 05:52:29 kernel: [*03/09/2022 05:52:29.5173] ol_if_dfs_enable: called
Mar 9 05:53:18 kernel: [*03/09/2022 05:53:18.5920] Re-Tx Count=1, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=1
Mar 9 05:53:18 kernel: [*03/09/2022 05:53:18.5920]
Mar 9 05:53:23 kernel: [*03/09/2022 05:53:23.3405] Re-Tx Count=2, Max Re-Tx Value=8, SendSeqNum=22, NumofPendingMsgs=1
Mar 9 05:53:23 kernel: [*03/09/2022 05:53:23.3405]
Mar 9 05:53:28 kernel: [*03/09/2022 05:53:28.0990] Re-Tx Count=3, Max Re-Tx Value=8, SendSeqNum=24, NumofPendingMsgs=3
Mar 9 05:53:28 kernel: [*03/09/2022 05:53:28.0990]
Mar 9 05:53:32 kernel: [*03/09/2022 05:53:32.8475] Re-Tx Count=4, Max Re-Tx Value=8, SendSeqNum=24, NumofPendingMsgs=3
Mar 9 05:53:32 kernel: [*03/09/2022 05:53:32.8475]
Mar 9 05:53:37 kernel: [*03/09/2022 05:53:37.5961] Re-Tx Count=5, Max Re-Tx Value=8, SendSeqNum=24, NumofPendingMsgs=3
Mar 9 05:53:37 kernel: [*03/09/2022 05:53:37.5961]
Mar 9 05:53:42 kernel: [*03/09/2022 05:53:42.3446] Re-Tx Count=6, Max Re-Tx Value=8, SendSeqNum=25, NumofPendingMsgs=4
Mar 9 05:53:42 kernel: [*03/09/2022 05:53:42.3446]
Mar 9 05:53:47 kernel: [*03/09/2022 05:53:47.1131] Re-Tx Count=7, Max Re-Tx Value=8, SendSeqNum=25, NumofPendingMsgs=4
Mar 9 05:53:47 kernel: [*03/09/2022 05:53:47.1131]
Mar 9 05:53:51 kernel: [*03/09/2022 05:53:51.8616] Re-Tx Count=8, Max Re-Tx Value=8, SendSeqNum=25, NumofPendingMsgs=4
Mar 9 05:53:51 kernel: [*03/09/2022 05:53:51.8616]
Mar 9 05:53:56 kernel: [*03/09/2022 05:53:56.6101] Re-Tx Count=9, Max Re-Tx Value=8, SendSeqNum=26, NumofPendingMsgs=5
Mar 9 05:53:56 kernel: [*03/09/2022 05:53:56.6101]
Mar 9 05:53:56 kernel: [*03/09/2022 05:53:56.6101] Max retransmission count exceeded, going back to DISCOVER mode.
Mar 9 05:53:56 kernel: [*03/09/2022 05:53:56.6101] Flexconnect Switching to Standalone Mode!
Mar 9 05:53:56 kernel: [*03/09/2022 05:53:56.7401]
Mar 9 05:53:56 kernel: [*03/09/2022 05:53:56.7401] CAPWAP State: DTLS Teardown
Mar 9 05:54:01 kernel: [*03/09/2022 05:54:01.4886] Discovery Response from 192.168.162.65
Mar 9 05:54:01 kernel: [*03/09/2022 05:54:01.5086] Discovery Response from 192.168.162.66
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.0000]
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.0000] CAPWAP State: DTLS Setup
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.2299]
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.2299] CAPWAP State: Join
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.2299] Sending Join request to 192.168.162.65 through port 5272
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.2299] Join Response from 192.168.162.65
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3399]
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3399] CAPWAP State: Image Data
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3899] do NO_UPGRADE, part2 is active part
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3899]
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3899] CAPWAP State: Configure
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3899] DOT11_CFG[0] Radio Mode is changed from FlexConnect to FlexConnect
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.3899] DOT11_CFG[1] Radio Mode is changed from FlexConnect to FlexConnect
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.6698]
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.6698] CAPWAP State: Run
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.8297] AP has joined controller IN02WLC-P
Mar 9 05:54:11 kernel: [*03/09/2022 05:54:11.8397] Flexconnect Switching to Connected Mode!
Mar 9 05:54:12 kernel: [*03/09/2022 05:54:12.0097] DOT11_DRV[0]: Stop Radio0
Mar 9 05:54:12 kernel: [*03/09/2022 05:54:12.0297] DOT11_DRV[0]: Start Radio0
Mar 9 05:54:12 kernel: [*03/09/2022 05:54:12.3296] DOT11_DRV[1]: Stop Radio1
Mar 9 05:54:12 kernel: [*03/09/2022 05:54:12.3396] ol_if_dfs_enable: called
Mar 9 05:54:12 kernel: [*03/09/2022 05:54:12.3596] DOT11_DRV[1]: Start Radio1
Mar 9 05:54:12 kernel: [*03/09/2022 05:54:12.3596] ol_if_dfs_enable: called
Mar 9 05:54:13 kernel: [*03/09/2022 05:54:13.1493] /usr/sbin/capwapd: opening /click/cli_h/apr_bypass/active failed!: No such file or directory
Mar 9 05:54:13 FIPS[26814]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:54:13 FIPS[26816]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:54:13 kernel: [*03/09/2022 05:54:13.8491] save_on_failure is set to 1
Mar 9 05:54:13 kernel: [*03/09/2022 05:54:13.8691] save_on_failure is set to 1
Mar 9 05:54:13 FIPS[26818]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:54:14 FIPS[26820]: *** /usr/sbin/hostapd: FIPS Mode = disabled ***
Mar 9 05:54:17 kernel: [*03/09/2022 05:54:17.3880] ol_if_dfs_enable: called
Mar 9 05:54:17 kernel: [*03/09/2022 05:54:17.3880] ieee80211_dfs_cac_start CAC Still Valid. Skip CAC
Mar 9 05:54:18 kernel: [*03/09/2022 05:54:18.4377] ol_if_dfs_enable: called
Mar 9 05:54:19 kernel: [*03/09/2022 05:54:19.4873] ol_if_dfs_enable: called
Mar 9 05:54:36 kernel: [*03/09/2022 05:54:36.4720] Re-Tx Count=1, Max Re-Tx Value=8, SendSeqNum=16, NumofPendingMsgs=1
Mar 9 05:54:36 kernel: [*03/09/2022 05:54:36.4720]
Mar 9 05:54:41 kernel: [*03/09/2022 05:54:41.2206] Re-Tx Count=2, Max Re-Tx Value=8, SendSeqNum=16, NumofPendingMsgs=1
Mar 9 05:54:41 kernel: [*03/09/2022 05:54:41.2206]
Mar 9 05:54:45 kernel: [*03/09/2022 05:54:45.9691] Re-Tx Count=3, Max Re-Tx Value=8, SendSeqNum=17, NumofPendingMsgs=2
Mar 9 05:54:45 kernel: [*03/09/2022 05:54:45.9691]
Mar 9 05:54:50 kernel: [*03/09/2022 05:54:50.7176] Re-Tx Count=4, Max Re-Tx Value=8, SendSeqNum=17, NumofPendingMsgs=2
Mar 9 05:54:50 kernel: [*03/09/2022 05:54:50.7176]
Mar 9 05:54:55 kernel: [*03/09/2022 05:54:55.4661] Re-Tx Count=5, Max Re-Tx Value=8, SendSeqNum=17, NumofPendingMsgs=2
Mar 9 05:54:55 kernel: [*03/09/2022 05:54:55.4661]
Mar 9 08:55:18 FIPS[17733]: *** shell: FIPS Mode = disabled ***

This is ap log at the time of disconnection Mar 9, 05:52 - 05:55, please let me know if u can find in this logs

MHM Cisco World · ‎03-09-2022

until Now it not clear the issue but from log you send,

usr/sbin/capwap/ not such file....
https://bst.cloudapps.cisco.com/bugsearch/bug/CSCux84138

so this bug mention that when change mode of AP from local to Flex the AP can not join or error appear.
so can you check,

only config one with local AP and see if it can join without error.

then if it success and stable then we will solve other issue.

rengaraj.p · ‎03-09-2022

Thank you, thts a good option, after the upgrade we dint try in local mode. will move some access points to local mode and monitor the situation for a day. and let u know the results... and also let me know u recommend any other changes in the controller ?

rengaraj.p · ‎03-09-2022

Hi, changing some AP's to Local mode and move some AP's to HA controller dint help, we faced the same issue now on the AP's. we rebooted the AP's and WLC in the past weeks. let me know any other things to try ?

MHM Cisco World · ‎03-10-2022

OK,
HA WLC
what is the IP of WLC use in discovery "which I think via DHCP op" is it same primary WLC of HA or it the IP of the WLC backup primary ?
backup primary WLC IP is config on both WLC ??
are the debug is from Primary or backup primary WLC ?
-----------------------------------------
Also
AP & Ver. ?
WLC both Ver.?
do
show ap image <- check WLC have image Last Image of AP.
-----------------------------------------------------
I see that AP get IP but after the config the AP loss connectivity to WLC.... are Native VLAN is allow in SW ?