Flexconnect ap losing Controller Associated Time

raikone14 · ‎04-17-2021

I have few aps model: AIR-AP1815W-E-K9 with the ios version:8.5.151.0 that have uptime of more than 100 days, but the association time stays 1 hour or less, and reset.They losing the connection with the controller.

They operate in flex-connect over wan links, I checked that the latency for flexconnect aps cant be more than 300 ms, I enable link latency in one of the apps, but shows me a maximum of 17 ms .

I enabled capwap events and errors and got this: Anyone has any ideia what is the cause of this problem please ?

capwapSocketTask: Apr 17 22:06:14.248: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:06:14.248: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:06:14.257: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:06:14.257: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:06:14.257: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:06:14.257: [PA] Failed to find DtlsConnection.

*osapiBsnTimer: Apr 17 22:06:16.841: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:06:27.053: [PA] Same gateway prevails
*spamApTask6: Apr 17 22:06:28.530: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask6: Apr 17 22:06:28.530: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask6: Apr 17 22:06:28.532: [PA] Flex Group Feature BITMAP 0
*osapiBsnTimer: Apr 17 22:06:37.265: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:06:47.481: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:06:57.701: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:07:07.917: [PA] Same gateway prevails
*spamApTask6: Apr 17 22:07:10.011: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask6: Apr 17 22:07:10.011: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask6: Apr 17 22:07:10.013: [PA] Flex Group Feature BITMAP 0
*osapiBsnTimer: Apr 17 22:07:18.137: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:07:28.349: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:07:38.561: [PA] Same gateway prevails
*spamApTask2: Apr 17 22:07:48.526: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:07:48.526: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:07:48.527: [PA] Flex Group Feature BITMAP 0
*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*osapiBsnTimer: Apr 17 22:07:48.777: [PA] Same gateway prevails
*capwapSocketTask: Apr 17 22:07:48.778: [PA] Failed to find DtlsConnection.

*spamApTask4: Apr 17 22:07:49.186: [PA] Failed to process timer message 1

*osapiBsnTimer: Apr 17 22:07:58.981: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:08:09.185: [PA] Same gateway prevails
*spamApTask2: Apr 17 22:08:15.718: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:08:15.718: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:08:15.719: [PA] Flex Group Feature BITMAP 0
*osapiBsnTimer: Apr 17 22:08:19.405: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:08:29.597: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:08:39.825: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:08:50.052: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:09:00.241: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:09:10.457: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:09:20.673: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:09:30.893: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:09:41.117: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:09:51.329: [PA] Same gateway prevails
*spamApTask6: Apr 17 22:09:54.840: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask6: Apr 17 22:09:54.840: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask6: Apr 17 22:09:54.842: [PA] Flex Group Feature BITMAP 0
*osapiBsnTimer: Apr 17 22:10:01.533: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:10:11.741: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:10:21.953: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:10:32.153: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:10:42.365: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:10:52.573: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:11:02.797: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:11:13.009: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:11:23.221: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:11:33.437: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:11:43.649: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:11:53.861: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:12:04.073: [PA] Same gateway prevails
*spamApTask2: Apr 17 22:12:09.553: [PA] Failed to process DTLS Session Established notification 1

*osapiBsnTimer: Apr 17 22:12:14.289: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:12:24.501: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:12:34.713: [PA] Same gateway prevails
*osapiBsnTimer: Apr 17 22:12:44.933: [PA] Same gateway prevails
*spamApTask2: Apr 17 22:12:52.484: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:12:52.484: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:12:52.486: [PA] Flex Group Feature BITMAP 0

*spamApTask2: Apr 17 22:14:38.935: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1

*spamApTask2: Apr 17 22:24:07.389: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:24:07.389: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:24:07.390: [PA] Flex Group Feature BITMAP 0

*emWeb: Apr 17 22:26:42.991: [PA] USMWEB_IF_VER_SUPPORT_SENSOR_AP, Productionversionvalue: 8059700 minsenrsorvalue 8050000

*emWeb: Apr 17 22:27:37.216: [PA] USMWEB_IF_VER_SUPPORT_SENSOR_AP, Productionversionvalue: 8059700 minsenrsorvalue 8050000
*osapiBsnTimer: Apr 17 22:27:43.877: [PA] Same gateway prevails
*emWeb: Apr 17 22:27:46.423: [PA] USMWEB_IF_VER_SUPPORT_SENSOR_AP, Productionversionvalue: 8059700 minsenrsorvalue 8050000
*osapiBsnTimer: Apr 17 22:27:54.077: [PA] Same gateway prevails
*emWeb: Apr 17 22:27:56.913: [PA] USMWEB_IF_VER_SUPPORT_SENSOR_AP, Productionversionvalue: 8059700 minsenrsorvalue 8050000
*osapiBsnTimer: Apr 17 22:28:04.289: [PA] Same gateway prevails
*emWeb: Apr 17 22:28:09.771: [PA] USMWEB_IF_VER_SUPPORT_SENSOR_AP, Productionversionvalue: 8059700 minsenrsorvalue 8050000
*osapiBsnTimer: Apr 17 22:28:14.501: [PA] Same gateway prevails
*emWeb: Apr 17 22:28:19.965: [PA] USMWEB_IF_VER_SUPPORT_SENSOR_AP, Productionversionvalue: 8059700 minsenrsorvalue 8050000
*osapiBsnTimer: Apr 17 22:28:24.705: [PA] Same gateway prevails

patoberli · ‎04-19-2021

It looks like there is an unstable connection between the AP and the WLC. As a first step I suggest replacing the cable between the AP and the patch panel.

If that doesn't help, you can run a debug on the WLC for this AP, with some luck you will see the reason there.

raikone14 · ‎04-20-2021

Thanks a lot for your reply,

I really dont think is a cable problem, we have more than 200 aps, in different places with the same problem....

I tried to enable debug on the controller, but I really dont know if this is ok,,,

debug ap enable AP1_SITEA
debug ap command  "debug capwap client error" AP1_SITEA
debug ap command "debug dtls client events" AP1_SITEA
debug ap command "debug dtls client error" AP1_SITEA
debug ap command "debug capwap client events" AP1_SITEA

when I do show debug, return me :

(Cisco Controller) >show debug

MAC Addr 1.................................. 40:5B:D8:29:9B:10

SGT debugging .............................. disabled
Flex-AP Client Debugging ................... disabled
Flex-Group Client Debugging ................ disabled

Debug Flags Enabled:
  dhcp packet enabled.
  Client Event enabled.
  dot11 mobile enabled.
  dot11 state enabled
  dot1x events enabled.
  dot1x states enabled.
  mobility client handoff enabled.
  pem events enabled.
  pem state enabled.
  remote AP debug enabled.
  802.11r event debug enabled.
  802.11w event debug enabled.
  CCKM client debug enabled.

This mac address is not the same as my ap:

MAC Address...................................... 2c:57:41:43:19:90

what I am doing wrong please ?

patoberli · ‎04-20-2021

Ok, in that case, as it's not just one AP, you can run debug capwap events enable. This should show connection issues of the APs. There are also other capwap debugs that might help.

What you can also try is this show ap join stats detailed macaddressofAP. This should show something like this for a FlexConnect AP:

(Cisco Controller) >show ap join stats detailed f4:db:e6:xx:xx:xx

Sync phase statistics
- Time at sync request received............................ Not applicable
- Time at sync completed................................... Not applicable

Discovery phase statistics
- Discovery requests received.............................. 4
- Successful discovery responses sent...................... 4
- Unsuccessful discovery request processing................ 0
- Reason for last unsuccessful discovery attempt........... Not applicable
- Time at last successful discovery attempt................ Apr 15 22:07:55.997
- Time at last unsuccessful discovery attempt.............. Not applicable

Join phase statistics
- Join requests received................................... 2
- Successful join responses sent........................... 2
- Unsuccessful join request processing..................... 0
- Reason for last unsuccessful join attempt................ Not applicable
- Time at last successful join attempt..................... Apr 15 22:08:10.692
- Time at last unsuccessful join attempt................... Not applicable

Configuration phase statistics

--More-- or (q)uit
- Configuration requests received.......................... 7
- Successful configuration responses sent.................. 3
- Unsuccessful configuration request processing............ 0
- Reason for last unsuccessful configuration attempt....... Not applicable
- Time at last successful configuration attempt............ Apr 15 22:08:14.739
- Time at last unsuccessful configuration attempt.......... Not applicable

Last AP message decryption failure details
- Reason for last message decryption failure............... Not applicable

Last AP disconnect details
- Reason for last AP connection failure.................... Not applicable
- Last AP disconnect reason................................ Unknown failure reason

Last join error summary
- Type of error that occurred last......................... None
- Reason for error that occurred last...................... Not applicable
- Time at which the last join error occurred............... Not applicable

AP disconnect details
- Reason for last AP connection failure.................... Not applicable
Ethernet Mac : f4:db:e6:xx:xx:xx Ip Address : xxx.xxx.3.18

raikone14 · ‎04-21-2021

thank so much for your reply,using "show ap join stats" i got something that look interesting:

Sync phase statistics
- Time at sync request received............................ Not applicable
- Time at sync completed................................... Not applicable

Discovery phase statistics
- Discovery requests received.............................. 50
- Successful discovery responses sent...................... 100
- Unsuccessful discovery request processing................ 0
- Reason for last unsuccessful discovery attempt........... Not applicable
- Time at last successful discovery attempt................ Apr 21 13:27:32.098
- Time at last unsuccessful discovery attempt.............. Not applicable

Join phase statistics
- Join requests received................................... 25
- Successful join responses sent........................... 25
- Unsuccessful join request processing..................... 0
- Reason for last unsuccessful join attempt................ Not applicable
- Time at last successful join attempt..................... Apr 21 13:28:43.361
- Time at last unsuccessful join attempt................... Not applicable

Configuration phase statistics

--More-- or (q)uit
- Configuration requests received.......................... 127
- Successful configuration responses sent.................. 51
- Unsuccessful configuration request processing............ 0
- Reason for last unsuccessful configuration attempt....... Not applicable
- Time at last successful configuration attempt............ Apr 21 13:28:43.989
- Time at last unsuccessful configuration attempt.......... Not applicable

Last AP message decryption failure details
- Reason for last message decryption failure............... Not applicable

Last AP disconnect details
- Reason for last AP connection failure.................... Number of message retransmission to the AP has reached maximum
- Last AP disconnect reason................................ Unknown failure reason

Last join error summary
- Type of error that occurred last......................... AP got or has been disconnected
- Reason for error that occurred last...................... Number of message retransmission to the AP has reached maximum
- Time at which the last join error occurred............... Apr 20 13:04:48.164

AP disconnect details
- Reason for last AP connection failure.................... Number of message retransmission to the AP has reached maximum

this mean latency ? and another question, "time at witch the last join error occurred", is showing that was yesterday, but this ap lost the association 3 times today,should not be today in this field ?

about the debut, just return me some msg like this:

*osapiBsnTimer: Apr 17 22:07:38.561: [PA] Same gateway prevails
*spamApTask2: Apr 17 22:07:48.526: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:07:48.526: [PA] TLV Encoding WLAN SGT 0 in config update request for wlan id 1
*spamApTask2: Apr 17 22:07:48.527: [PA] Flex Group Feature BITMAP 0
*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

*capwapSocketTask: Apr 17 22:07:48.776: [PA] Failed to find DtlsConnection.

thank you again.

patoberli · ‎04-22-2021

Could be latency, could be overloaded connection. Or probably packet loss on the connection. Make sure you always have enough spare bandwidth for the CAPWAP packets. If you run FlexConnect Central Switching, make also sure that the bandwidth between the AP and WLC can support the client traffic plus CAPWAP. Otherwise you might need to look into FlexConnect Local Switching.