Diassociation of 2802I

[AK002]

Hi Team,

Can anyone help on the AP re association issue..

 AP model : 2802 8.5.161.0 WLC : 5520

System logging:
Jun  2 20:26:06 NCI: I0: Requesting MonBand [5700, 5700] bw=20MHz/0 ant=0xbc
Jun  2 20:26:06 NCI: I0: Monitoring (cf=5700, span=20), RadioUsage=3%
Jun  2 20:26:06 NCI: I0:     dwell=20000us, update=1000ms, resBW=78126
Jun  2 20:26:06 NCI: CLEANAIR: Slot 0 enabled
Jun  2 20:26:06 NCI: I1: openSensor(slot=1)
Jun  2 20:26:08 NCI: I1: SensorApp=1.15.4
Jun  2 20:26:08 NCI: I1: SensorHdw=1.2.3.0
Jun  2 20:26:08 NCI: I1: Hardware Radio Band = [4890, 5935] MHz, BW=150625
Jun  2 20:26:08 NCI: slot=1 mode=2 chanCnt=1 cw=1
Jun  2 20:26:08 NCI: chans: 60 0 0 0 0 0 0 0 0 0 0
Jun  2 20:26:08 NCI: I1: channel map channels: in=1 cloned=1
Jun  2 20:26:08 NCI: I1: Requesting MonBand [5300, 5300] bw=20MHz/0 ant=0xbc
Jun  2 20:26:08 NCI: I1: Monitoring (cf=5300, span=20), RadioUsage=3%
Jun  2 20:26:08 NCI: I1:     dwell=20000us, update=1000ms, resBW=78126
Jun  2 20:26:08 NCI: CLEANAIR: Slot 1 enabled
Jun  2 20:26:30 kernel: [*06/02/2020 20:26:30.5327] CAPWAP HW tunnel params changed, DELETING the existing
Jun  2 20:26:31 kernel: [*06/02/2020 20:26:31.5868] HW CAPWAP tunnel is ADDED
Jun  2 20:26:59 kernel: [*06/02/2020 20:26:59.0353] CAPWAP HW tunnel params changed, DELETING the existing
Jun  2 20:27:00 kernel: [*06/02/2020 20:27:00.0895] HW CAPWAP tunnel is ADDED
Jun  2 20:27:04 kernel: [*06/02/2020 20:27:04.7446] CAPWAP HW tunnel params changed, DELETING the existing
Jun  2 20:27:05 kernel: [*06/02/2020 20:27:05.7989] HW CAPWAP tunnel is ADDED
Jun  3 02:37:20 kernel: [*06/03/2020 02:37:20.3780] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=197, NumofPendingMsgs=1
Jun  3 02:37:20 kernel: [*06/03/2020 02:37:20.3780]
Jun  3 02:37:23 kernel: [*06/03/2020 02:37:23.2288] Re-Tx Count=2, Max Re-Tx Value=5, SendSeqNum=198, NumofPendingMsgs=2
Jun  3 02:37:23 kernel: [*06/03/2020 02:37:23.2288]
Jun  3 02:37:28 kernel: [*06/03/2020 02:37:28.7405] Re-Tx Count=3, Max Re-Tx Value=5, SendSeqNum=198, NumofPendingMsgs=1
Jun  3 02:37:28 kernel: [*06/03/2020 02:37:28.7405]
Jun  3 02:37:31 kernel: [*06/03/2020 02:37:31.5914] Re-Tx Count=4, Max Re-Tx Value=5, SendSeqNum=198, NumofPendingMsgs=1
Jun  3 02:37:31 kernel: [*06/03/2020 02:37:31.5914]
Jun  3 02:37:34 kernel: [*06/03/2020 02:37:34.4422] Re-Tx Count=5, Max Re-Tx Value=5, SendSeqNum=198, NumofPendingMsgs=1
Jun  3 02:37:34 kernel: [*06/03/2020 02:37:34.4422]
Jun  3 02:37:37 kernel: [*06/03/2020 02:37:37.3007] Re-Tx Count=6, Max Re-Tx Value=5, SendSeqNum=198, NumofPendingMsgs=1
Jun  3 02:37:37 kernel: [*06/03/2020 02:37:37.3007]
Jun  3 02:37:37 kernel: [*06/03/2020 02:37:37.3008] Max retransmission count exceeded, going back to DISCOVER mode.
Jun  3 02:37:37 kernel: [*06/03/2020 02:37:37.3011] Flexconnect Switching to Standalone Mode!
Jun  3 02:37:37 kernel: [*06/03/2020 02:37:37.3065]
Jun  3 02:37:37 kernel: [*06/03/2020 02:37:37.3065] CAPWAP State: DTLS Teardown
Jun  3 02:37:38 NCI: CLEANAIR: Slot 0 CAPWAP down
Jun  3 02:37:38 NCI: I0: shutdownNci
Jun  3 02:37:38 NCI: CLEANAIR: Slot 1 CAPWAP down
Jun  3 02:37:38 NCI: I1: shutdownNci
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.1233] Discovery Response from 10.130.0.110
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.1312] Discovery Response from 10.130.0.110
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.1389] Discovery Response from 10.130.0.110
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.0001]
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.0001] CAPWAP State: DTLS Setup
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.7111]
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.7111] CAPWAP State: Join
Jun  3 02:37:43 kernel: [*06/03/2020 02:37:43.7126] Sending Join request to 10.130.0.110 through port 5256
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3554] Join Response from 10.130.0.110
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3558]
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3559] CAPWAP State: Image Data
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3926] do NO_UPGRADE, part2 is active part
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3964]
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3964] CAPWAP State: Configure
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3986] DOT11_CFG[0] Radio Mode is changed from FlexConnect to FlexConnect
Jun  3 02:37:48 kernel: [*06/03/2020 02:37:48.3991] DOT11_CFG[1] Radio Mode is changed from FlexConnect to FlexConnect
Jun  3 02:37:49 kernel: [*06/03/2020 02:37:49.4298]
Jun  3 02:37:49 kernel: [*06/03/2020 02:37:49.4298] CAPWAP State: Run
Jun  3 02:37:49 kernel: [*06/03/2020 02:37:49.5272] AP has joined controller WLC1
Jun  3 02:37:49 kernel: [*06/03/2020 02:37:49.5483] Flexconnect Switching to Connected Mode!
Jun  3 02:37:51 root: SYS-COND: Retrigger fair condition, 6 power
Jun  3 02:37:54 syslog: Password for user changed
Jun  3 02:37:54 kernel: [*06/03/2020 02:37:54.2452] Password for user changed
Jun  3 02:37:54 kernel: [*06/03/2020 02:37:54.5897] /usr/sbin/capwapd: opening /click/cli_h/apr_bypass/active failed!: No such file or directory
Jun  3 02:37:54 kernel: [*06/03/2020 02:37:54.7776] save_on_failure is set to 1
Jun  3 02:37:54 kernel: [*06/03/2020 02:37:54.7779] save_on_failure is set to 1
Jun  3 02:38:18 kernel: [*06/03/2020 02:38:18.9146] set cleanair [slot0][band0] enabled
Jun  3 02:38:18 NCI: I0: openSensor(slot=0)
Jun  3 02:38:18 kernel: [*06/03/2020 02:38:18.9210] set cleanair [slot0][band1] enabled
Jun  3 02:38:18 kernel: [*06/03/2020 02:38:18.9271] set cleanair [slot1][band1] enabled
Jun  3 02:38:19 NCI: I0: SensorApp=1.15.4
Jun  3 02:38:19 NCI: I0: SensorHdw=1.2.3.0
Jun  3 02:38:19 NCI: I0: Hardware Radio Band = [4890, 5935] MHz, BW=150625
Jun  3 02:38:19 NCI: I0: Hardware Radio Band = [2400, 2500] MHz, BW=150625
Jun  3 02:38:19 NCI: slot=0 mode=2 chanCnt=1 cw=1
Jun  3 02:38:19 NCI: chans: 140 0 0 0 0 0 0 0 0 0 0
Jun  3 02:38:19 NCI: I0: channel map channels: in=1 cloned=1
Jun  3 02:38:19 NCI: I0: Requesting MonBand [5700, 5700] bw=20MHz/0 ant=0xbc
Jun  3 02:38:20 NCI: I0: Monitoring (cf=5700, span=20), RadioUsage=3%
Jun  3 02:38:20 NCI: I0:     dwell=20000us, update=1000ms, resBW=78126
Jun  3 02:38:20 NCI: CLEANAIR: Slot 0 enabled
Jun  3 02:38:20 NCI: I1: openSensor(slot=1)
Jun  3 02:38:21 NCI: I1: SensorApp=1.15.4
Jun  3 02:38:21 NCI: I1: SensorHdw=1.2.3.0
Jun  3 02:38:21 NCI: I1: Hardware Radio Band = [4890, 5935] MHz, BW=150625
Jun  3 02:38:21 NCI: slot=1 mode=2 chanCnt=1 cw=1
Jun  3 02:38:21 NCI: chans: 60 0 0 0 0 0 0 0 0 0 0
Jun  3 02:38:21 NCI: I1: channel map channels: in=1 cloned=1
Jun  3 02:38:21 NCI: I1: Requesting MonBand [5300, 5300] bw=20MHz/0 ant=0xbc
Jun  3 02:38:21 NCI: I1: Monitoring (cf=5300, span=20), RadioUsage=3%
Jun  3 02:38:21 NCI: I1:     dwell=20000us, update=1000ms, resBW=78126
Jun  3 02:38:21 NCI: CLEANAIR: Slot 1 enabled
Jun  3 02:38:46 kernel: [*06/03/2020 02:38:46.5674] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 02:38:47 kernel: [*06/03/2020 02:38:47.6219] HW CAPWAP tunnel is ADDED
Jun  3 02:39:15 kernel: [*06/03/2020 02:39:15.0674] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 02:39:16 kernel: [*06/03/2020 02:39:16.1218] HW CAPWAP tunnel is ADDED
Jun  3 02:39:20 kernel: [*06/03/2020 02:39:20.7750] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 02:39:21 kernel: [*06/03/2020 02:39:21.8298] HW CAPWAP tunnel is ADDED
Jun  3 06:12:22 kernel: [*06/03/2020 06:12:22.2423] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 06:12:23 kernel: [*06/03/2020 06:12:23.2965] HW CAPWAP tunnel is ADDED
Jun  3 06:12:27 kernel: [*06/03/2020 06:12:27.9511] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 06:12:29 kernel: [*06/03/2020 06:12:29.0085] HW CAPWAP tunnel is ADDED
Jun  3 09:10:07 kernel: [*06/03/2020 09:10:07.2891] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=67, NumofPendingMsgs=1
Jun  3 09:10:07 kernel: [*06/03/2020 09:10:07.2891]
Jun  3 09:12:00 kernel: [*06/03/2020 09:12:00.3515] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=83, NumofPendingMsgs=2
Jun  3 09:12:00 kernel: [*06/03/2020 09:12:00.3515]
Jun  3 09:12:17 kernel: [*06/03/2020 09:12:17.6468] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=89, NumofPendingMsgs=3
Jun  3 09:12:17 kernel: [*06/03/2020 09:12:17.6468]
Jun  3 09:12:57 kernel: [*06/03/2020 09:12:57.1788] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=94, NumofPendingMsgs=1
Jun  3 09:12:57 kernel: [*06/03/2020 09:12:57.1788]
Jun  3 09:14:44 kernel: [*06/03/2020 09:14:44.5767] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=109, NumofPendingMsgs=3
Jun  3 09:14:44 kernel: [*06/03/2020 09:14:44.5767]
Jun  3 09:15:16 kernel: [*06/03/2020 09:15:16.8863] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=119, NumofPendingMsgs=3
Jun  3 09:15:16 kernel: [*06/03/2020 09:15:16.8863]
Jun  3 09:16:03 kernel: [*06/03/2020 09:16:03.6404] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=125, NumofPendingMsgs=1
Jun  3 09:16:03 kernel: [*06/03/2020 09:16:03.6405]
Jun  3 09:17:04 kernel: [*06/03/2020 09:17:04.3424] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=131, NumofPendingMsgs=1
Jun  3 09:17:04 kernel: [*06/03/2020 09:17:04.3425]
Jun  3 09:17:07 kernel: [*06/03/2020 09:17:07.1933] Re-Tx Count=2, Max Re-Tx Value=5, SendSeqNum=133, NumofPendingMsgs=3
Jun  3 09:17:07 kernel: [*06/03/2020 09:17:07.1933]
Jun  3 09:18:00 kernel: [*06/03/2020 09:18:00.4094] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=143, NumofPendingMsgs=2
Jun  3 09:18:00 kernel: [*06/03/2020 09:18:00.4094]
Jun  3 09:21:20 kernel: [*06/03/2020 09:21:20.8104] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=183, NumofPendingMsgs=3
Jun  3 09:21:20 kernel: [*06/03/2020 09:21:20.8104]
Jun  3 09:23:06 kernel: [*06/03/2020 09:23:06.7814] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=193, NumofPendingMsgs=1
Jun  3 09:23:06 kernel: [*06/03/2020 09:23:06.7814]
Jun  3 09:23:17 kernel: [*06/03/2020 09:23:17.8048] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=197, NumofPendingMsgs=2
Jun  3 09:23:17 kernel: [*06/03/2020 09:23:17.8048]
Jun  3 09:23:20 kernel: [*06/03/2020 09:23:20.6556] Re-Tx Count=2, Max Re-Tx Value=5, SendSeqNum=197, NumofPendingMsgs=2
Jun  3 09:23:20 kernel: [*06/03/2020 09:23:20.6556]
Jun  3 09:23:23 kernel: [*06/03/2020 09:23:23.5065] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=197, NumofPendingMsgs=1
Jun  3 09:23:23 kernel: [*06/03/2020 09:23:23.5065]
Jun  3 09:23:52 kernel: [*06/03/2020 09:23:52.5853] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=200, NumofPendingMsgs=2
Jun  3 09:23:52 kernel: [*06/03/2020 09:23:52.5853]
Jun  3 09:24:02 kernel: [*06/03/2020 09:24:02.0881] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=203, NumofPendingMsgs=1
Jun  3 09:24:02 kernel: [*06/03/2020 09:24:02.0881]
Jun  3 09:25:43 kernel: [*06/03/2020 09:25:43.0085] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=217, NumofPendingMsgs=1
Jun  3 09:25:43 kernel: [*06/03/2020 09:25:43.0085]
Jun  3 09:26:08 kernel: [*06/03/2020 09:26:08.8564] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=224, NumofPendingMsgs=4
Jun  3 09:26:08 kernel: [*06/03/2020 09:26:08.8564]
Jun  3 09:27:00 kernel: [*06/03/2020 09:27:00.6002] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=231, NumofPendingMsgs=2
Jun  3 09:27:00 kernel: [*06/03/2020 09:27:00.6002]
Jun  3 09:27:50 kernel: [*06/03/2020 09:27:50.5854] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=242, NumofPendingMsgs=1
Jun  3 09:27:50 kernel: [*06/03/2020 09:27:50.5854]
Jun  3 09:29:06 kernel: [*06/03/2020 09:29:06.7202] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=253, NumofPendingMsgs=2
Jun  3 09:29:06 kernel: [*06/03/2020 09:29:06.7202]
Jun  3 09:30:12 kernel: [*06/03/2020 09:30:12.6419] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=10, NumofPendingMsgs=3
Jun  3 09:30:12 kernel: [*06/03/2020 09:30:12.6419]
Jun  3 09:31:09 kernel: [*06/03/2020 09:31:09.6590] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=18, NumofPendingMsgs=3
Jun  3 09:31:09 kernel: [*06/03/2020 09:31:09.6590]
Jun  3 09:36:46 kernel: [*06/03/2020 09:36:46.5699] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 09:36:47 kernel: [*06/03/2020 09:36:47.6246] HW CAPWAP tunnel is ADDED
Jun  3 11:56:58 kernel: [*06/03/2020 11:56:58.3446] hostapd:FT: invalid assoc req. (reason 1) from 6c:4d:73:ae:eb:d0
Jun  3 12:38:22 kernel: [*06/03/2020 12:38:22.3753] CAPWAP HW tunnel params changed, DELETING the existing
Jun  3 12:38:23 kernel: [*06/03/2020 12:38:23.4304] HW CAPWAP tunnel is ADDED
Jun  3 13:58:35 syslog: Password for user changed
Jun  3 13:58:35 kernel: [*06/03/2020 13:58:35.5019] Password for user changed
Jun  3 13:59:36 FIPS[32408]: *** shell: FIPS Mode = disabled ***
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7551]
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7551] Total STA List Count 1
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7551] | NO|              MAC|STATE|
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7551] -----------------------------
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7551] |  1|6c:4d:73:ae:eb:d0|    8|
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7563]
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7563] Total STA List Count 3
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7563] | NO|              MAC|STATE|
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7563] -----------------------------
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7563] |  1|38:53:9c:c4:b8:fd|    8|
Jun  3 14:09:13 kernel: [*06/03/2020 14:09:13.7563] |  2|40:83:1d: 2:7a:10|    8|

Regards,

Arun

[Leo Laohoo]

---

@AK002 wrote:

Jun  3 11:56:58 kernel: [*06/03/2020 11:56:58.3446] hostapd:FT: invalid assoc req. (reason 1) from 6c:4d:73:ae:eb:d0

---

What exactly is the problem?  Is it the error message above?  If it is, then this could be CSCvj1125.

[AK002]

Hi Leo,

We can see random Aps are re associating frequently from the WLC.. everyday there will be some APs which is dis associating from controller and joining back..

[Leo Laohoo]

1. What is the uptime of the WLC? 
2. Is the WLC in HA SSO or standalone? 
3. Pick an AP (or two) that has recently dropped off and joined and post the complete output to the following command: 

show ap join stats detailed <AP NAME>

[Rich R]

Have you checked to see whether the APs have crashed? Otherwise more likely to be a problem with connectivity or packet loss between the APs and WLC. If you can't see an obvious cause then you'll need to run debugs on AP and WLC and ideally get packet captures at both ends too to work out what's going wrong.

[AK002]

There is no crash files available from the Ap end. Also there is no sign on the the WLC and AP connectivity problem..

WLC is placed in datacenter and AP is in remote sites..Every day there will be some random AP's are Re-joining

[Leo Laohoo]

Have a look at CSCvk53499.

[AK002]

WLC running on fixed release, Also the Error in the bug not having any link to our issue leo..

[Leo Laohoo]

---

@AK002 wrote:

WLC running on fixed release

---

Ignore the information about "fixed release".  

---

@AK002 wrote:

Also the Error in the bug not having any link to our issue

---

Run a debug on the AP to determine whether or not DTLS is being dropped by the WLC.  

This is why I'm asking what is the uptime of the WLC.  

Also, if the WLC gets rebooted, will the AP join or not?

[Rich R]

Hi Leo - he doesn't have a problem with the AP joining. He's concerned that the APs are randomly dropping off then re-joining (if I've understood correctly?)

[AK002]

yes that's correct..

[AK002]

Ap is joining back without any issue, need to find why the AP's are disassociating and re-joining..

Somewhat difficult to run Debug because Random AP's are re-joining and don't have any specific time.

WLC uptime is more than two weeks. I have uploaded old debug logs from WLC.

[Rich R]

> Last AP failure was due to Link Failure
This really looks like you have packet loss or errors between the AP and the WLC.
So you need to check the entire path hop by hop in both directions, if necessary get packet captures at each point to work out where those packets are getting lost. And like I said think about any NAT or firewalls that might timeout the connection which are in the path.

[Leo Laohoo]

---

@AK002 wrote:

Last AP failure was due to Link Failure

---

This error message keeps popping up. 

Since the APs are in Flex, are the APs having popping out coming from the same site?  I am trying to determine if the APs are leaving the controller due to congestion (or latency) of the WAN link.

[AK002]

No, the AP disassociation from both the sites.