topic Re: AP got dissociated from vWLC - Error while upgrading in Wireless

Fixed - AP got dissociated from vWLC - Error while upgrading

EURL_IPSENS — Sun, 30 Jul 2023 03:22:05 GMT

Hi guys,

I'm trying to setup and 9120 AP to vWLC, I'm getting the following log on vWLC :

2 Fri Jul 28 22:14:20 2023 AP Disassociated. Base Radio MAC:24:36:da:17:xx:xx ApName - AP2436.DA34.YYYY
3 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP AP2436.DA34.YYYY Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC with Max Tx Power value: 0 dbm
4 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP AP2436.DA34.YYYY Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11bg New Tx Power level is: 0 Reason: DTPC with Max Tx Power value: 0 dbm
5 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
6 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
7 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
8 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
9 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
10 Fri Jul 28 22:14:18 2023 RF Manager updated TxPower for AP Base Radio MAC: 24:36:da:17:xx:xx and Radio Type: 802.11a New Tx Power level is: 0 Reason: DTPC Tx Power value: 0 dbm
11 Fri Jul 28 22:13:20 2023 AP Disassociated. Base Radio MAC:24:36:da:17:xx:xx ApName - AP2436.DA34.YYYY

On AP :

[*01/16/2022 00:03:05.0790] Firmware upgrade initiated by ble_management
[*01/16/2022 00:03:05.0790] Opening serial console to.. /dev/ttyH0
[*01/16/2022 00:03:05.0790] bundled_fw_ver = ['Lodestar', '2.7.16']
[*01/16/2022 00:03:05.0790] RSP: 04FF10FF070002150AFF020710320000000000
[*01/16/2022 00:03:05.0790] ls_ver = 2.7.16
[*01/16/2022 00:03:05.0790] ls_fw_ver 2.7.16
[*01/16/2022 00:03:05.0790] upgrade false
[*01/16/2022 00:03:05.0790] FW version is latest. No need to upgrade
[*01/16/2022 00:03:34.6130] AP IPv4 Address updated from 0.0.0.0 to 192.168.36.50
[*01/16/2022 00:03:36.1800] dtls_init: Use SUDI certificate
[*01/16/2022 00:03:36.1830]
[*01/16/2022 00:03:36.1830] CAPWAP State: Init
[*01/16/2022 00:03:40.8740] Start: RPC thread 2324018048 created.
[*01/16/2022 00:03:55.5350] Set PnP NTP Server pnpserver.
[*01/16/2022 00:04:25.6970] PNP:Server not reachable, Start CAPWAP Discovery
[*01/16/2022 00:04:25.6970]
[*01/16/2022 00:04:25.6970] CAPWAP State: Discovery
[*01/16/2022 00:04:25.7030] Discovery Request sent to 255.255.255.255, discovery type UNKNOWN(0)
[*01/16/2022 00:04:25.7040] Discovery Request sent to ff02::18c, discovery type UNKNOWN(0)
[*01/16/2022 00:04:25.7040] Discovery Response from 192.168.36.108
[*01/16/2022 00:04:25.7040]
[*01/16/2022 00:04:25.7040] CAPWAP State: Discovery
[*07/28/2023 22:25:42.0000]
[*07/28/2023 22:25:42.0000] CAPWAP State: DTLS Setup
[*07/28/2023 22:25:42.5610] sudi99_request_check_and_load: Use HARSA SUDI certificate
[*07/28/2023 22:25:42.9060] First connect to vWLC, accept vWLC by default
[*07/28/2023 22:25:42.9060]
[*07/28/2023 22:25:42.9240]
[*07/28/2023 22:25:42.9240] CAPWAP State: Join
[*07/28/2023 22:25:42.9420] Sending Join request to 192.168.36.108 through port 5251
[*07/28/2023 22:25:42.9490] Join Response from 192.168.36.108
[*07/28/2023 22:25:42.9490] AC accepted join request with result code: 0
[*07/28/2023 22:25:42.9500] Received wlcType 0, timer 30
[*07/28/2023 22:25:43.0330]
[*07/28/2023 22:25:43.0330] CAPWAP State: Image Data
[*07/28/2023 22:25:43.0330] AP image version 8.10.130.0 backup 0.0.0.0, Controller 8.10.185.0
[*07/28/2023 22:25:43.0330] Version does not match.
[*07/28/2023 22:25:43.0580] upgrade.sh: Script called with args:[PRECHECK]
[*07/28/2023 22:25:43.1010] do PRECHECK, part1 is active part
[*07/28/2023 22:25:43.1210] upgrade.sh: /tmp space: OK available 101464, required 40000
[*07/28/2023 22:25:43.1220] wtpImgFileReadRequest: request ap1g7, local /tmp/part.tar
[*07/28/2023 22:25:43.1290] Image Data Request sent to 192.168.36.108, fileName [ap1g7], slaveStatus 0
[*07/28/2023 22:25:43.1300] Image Data Response from 192.168.36.108
[*07/28/2023 22:25:43.1300] AC accepted join request with result code: 0
[*07/28/2023 22:25:43.1420] <> 0 bytes, 1 msgs, 0 last
[*07/28/2023 22:25:43.1420] Last block stored, IsPre 0, WriteTaskId 0
[*07/28/2023 22:25:43.1420] Image transfer completed from WLC, last 1
[*07/28/2023 22:25:43.1420] wtpProcessImageDataRequest(10): fileName ap1g7, pre 0
[*07/28/2023 22:25:43.1680] upgrade.sh: Script called with args:[PREDOWNLOAD]
[*07/28/2023 22:25:43.2150] do PREDOWNLOAD, part1 is active part
[*07/28/2023 22:25:43.2300] upgrade.sh: Start doing upgrade arg1=PREDOWNLOAD arg2= arg3= ...
[*07/28/2023 22:25:43.2940] upgrade.sh: Using image /tmp/part.tar on axel-bcm ...
[*07/28/2023 22:25:43.3300] upgrade.sh: ERROR: Image type mismatch. Expected:ap1g7 Got:
[*07/28/2023 22:25:43.3500] upgrade.sh: Cleanup for do_upgrade...
[*07/28/2023 22:25:43.3670] upgrade.sh: /tmp/upgrade_in_progress cleaned
[*07/28/2023 22:25:43.3800] upgrade.sh: Cleanup tmp files ...
[*07/28/2023 22:25:43.4000] capwap-upgrade script returned failure when calling PREDOWNLOAD.
[*07/28/2023 22:25:43.4000] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Image Data(10).
[*07/28/2023 22:25:43.4000] CAPWAP SM handler: Failed to process message type 15 state 10.
[*07/28/2023 22:25:43.4010] Failed to handle capwap control message from controller - status 2
[*07/28/2023 22:25:43.4010] Failed to process encrypted capwap packet 0x5587cc5000 from 192.168.36.108
[*07/28/2023 22:25:43.4010] Failed to send capwap message 0 to the state machine. Packet already freed.
[*07/28/2023 22:26:14.3110] Re-Tx Count=1, Max Re-Tx Value=5, SendSeqNum=2, NumofPendingMsgs=1
[*07/28/2023 22:26:14.3110]
[*07/28/2023 22:26:17.1620] Re-Tx Count=2, Max Re-Tx Value=5, SendSeqNum=2, NumofPendingMsgs=1
[*07/28/2023 22:26:17.1620]
[*07/28/2023 22:26:20.0120] Re-Tx Count=3, Max Re-Tx Value=5, SendSeqNum=2, NumofPendingMsgs=1
[*07/28/2023 22:26:20.0120]
[*07/28/2023 22:26:22.8640] Re-Tx Count=4, Max Re-Tx Value=5, SendSeqNum=2, NumofPendingMsgs=1
[*07/28/2023 22:26:22.8640]
[*07/28/2023 22:26:25.7140] Re-Tx Count=5, Max Re-Tx Value=5, SendSeqNum=2, NumofPendingMsgs=1
[*07/28/2023 22:26:25.7140]
[*07/28/2023 22:26:28.5650] Max retransmission count exceeded, going back to DISCOVER mode.
[*07/28/2023 22:26:28.5650] Dropping msg CAPWAP_ECHO_REQUEST, type = 1, len = 0, eleLen = 8, sendSeqNum = 2
[*07/28/2023 22:26:28.5840]
[*07/28/2023 22:26:28.5840] CAPWAP State: DTLS Teardown
[*07/28/2023 22:26:28.6070] Aborting image download(0x0): Dtls cleanup, ap1g7
[*07/28/2023 22:26:28.6780] upgrade.sh: Script called with args:[ABORT]
[*07/28/2023 22:26:28.7180] do ABORT, part1 is active part
[*07/28/2023 22:26:28.7400] upgrade.sh: Cleanup tmp files ...
[*07/28/2023 22:26:28.7610] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
[*07/28/2023 22:26:28.7610] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
[*07/28/2023 22:26:33.3320]
[*07/28/2023 22:26:33.3320] CAPWAP State: Discovery
...

Also on WLC :

Any idea on how to fix it ?

Re: AP got dissociated from vWLC - Error while upgrading

Flavio Miranda — Fri, 28 Jul 2023 23:11:57 GMT

Hi @EURL_IPSENS

"[*07/28/2023 22:25:43.0330] AP image version 8.10.130.0 backup 0.0.0.0, Controller 8.10.185.0
[*07/28/2023 22:25:43.0330] Version does not match."

Either you upgrade the AP or you downgrade the WLC

Re: AP got dissociated from vWLC - Error while upgrading

EURL_IPSENS — Fri, 28 Jul 2023 23:13:22 GMT

Shouldn't the AP auto upgrade via WLC ?

Re: AP got dissociated from vWLC - Error while upgrading

Flavio Miranda — Fri, 28 Jul 2023 23:35:08 GMT

It should Indeed. The vWLC you are running is AirOs based? Or IOS-XE?

Virtual WLC based in AirOS is deprecated . This could be the problem.

Re: AP got dissociated from vWLC - Error while upgrading

Leo Laohoo — Sat, 29 Jul 2023 00:29:38 GMT

Flip the AP and look at the serial number "plate" of the AP. At the bottom of this plate is the Date of Manufacture. Was the AP manufactured AFTER September 2022?

If the AP was manufactured after September 2022 then this behaviour is due to FN - 72424 - Later Versions of Some Wi-Fi 6 Access Points Fail to Join the WLAN Controller.

Re: AP got dissociated from vWLC - Error while upgrading

EURL_IPSENS — Sat, 29 Jul 2023 02:46:48 GMT

It's vWL AirOS, yes deprecated but should work (supported in matrix)?

Re: AP got dissociated from vWLC - Error while upgrading

EURL_IPSENS — Sat, 29 Jul 2023 02:47:47 GMT

It's a C9120AXI-E v05 from 01/2022.

Re: AP got dissociated from vWLC - Error while upgrading

Leo Laohoo — Sat, 29 Jul 2023 04:24:26 GMT

Ok, I got an idea and it will involve downloading any firmware for the AP, like 17.11.1.

Download this firmware and put it in a TFTP server. Make sure the no FW is blocking the AP from reaching the TFTP server.

Console or remote into the AP and use the following command:

archive download-sw /no-reboot tftp://<TFTP IP ADDRESS>/ap1g7-k9w8-tar.153-3.JPP.tar

Depending on the link of the TFTP server, it should take 60 seconds for the AP to download and unpack the firmware.

After firmware has been downloaded, DO IT AGAIN.

After the firmware has been downloaded TWICE, verify using the command "sh version" and see if 17.11.1 is the primary and backup.

If it is, COLD reboot the AP.

Let us see if this works.

Re: AP got dissociated from vWLC - Error while upgrading

EURL_IPSENS — Sun, 30 Jul 2023 03:21:19 GMT

Ok guys, I fixed it..!
Cisco download page is WRONG, WLC is wrong.

As a try, I downloaded and installed AP_BUNDLE_CTVM_SMALL_8_10_185_0.aes.

"Supplementary AP Bundle Images for Cisco CTVM_SMALL Series WLC Release 8.10. This bundle is mandatory to support AP9117", no... It also seems to be mandatory for all 9100 series.
I was laking ap1g6, so yes, file needed for 9117, but I already had the ap1g7 for C9115,C9120, but it seems it has been updated via the bundle.

The AP successfully updated and join the controller, so much better 😄

[*07/30/2023 05:08:40.0000] CAPWAP State: DTLS Setup
[*07/30/2023 05:08:40.5610] sudi99_request_check_and_load: Use HARSA SUDI certificate
[*07/30/2023 05:08:40.9100] First connect to vWLC, accept vWLC by default
[*07/30/2023 05:08:40.9100]
[*07/30/2023 05:08:40.9280]
[*07/30/2023 05:08:40.9280] CAPWAP State: Join
[*07/30/2023 05:08:40.9300] Sending Join request to 192.168.36.108 through port 5278
[*07/30/2023 05:08:40.9380] Join Response from 192.168.36.108
[*07/30/2023 05:08:40.9380] AC accepted join request with result code: 0
[*07/30/2023 05:08:40.9380] Received wlcType 0, timer 30
[*07/30/2023 05:08:40.9930]
[*07/30/2023 05:08:40.9930] CAPWAP State: Image Data
[*07/30/2023 05:08:40.9940] AP image version 8.10.130.0 backup 0.0.0.0, Controller 8.10.185.0
[*07/30/2023 05:08:40.9940] Version does not match.
[*07/30/2023 05:08:41.0160] upgrade.sh: Script called with args:[PRECHECK]
[*07/30/2023 05:08:41.0550] do PRECHECK, part1 is active part
[*07/30/2023 05:08:41.0740] upgrade.sh: /tmp space: OK available 101536, required 40000
[*07/30/2023 05:08:41.0740] wtpImgFileReadRequest: request ap1g7, local /tmp/part.tar
[*07/30/2023 05:08:41.0760] Image Data Request sent to 192.168.36.108, fileName [ap1g7], slaveStatus 0
[*07/30/2023 05:08:41.0770] Image Data Response from 192.168.36.108
[*07/30/2023 05:08:41.0770] AC accepted join request with result code: 0
[*07/30/2023 05:08:41.0890] <..................................................
[*07/30/2023 05:08:58.4720] ..................................................
[*07/30/2023 05:09:15.5190] .......Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Image Data(10).
[*07/30/2023 05:09:20.8040] ...........................................
[*07/30/2023 05:09:38.0680] ..................................................
[*07/30/2023 05:09:57.6390] ...........................................Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Image Data(10).
[*07/30/2023 05:10:11.7820] .......
[*07/30/2023 05:10:14.0980] ....................> 71628800 bytes, 54101 msgs, 400 last
[*07/30/2023 05:10:20.5680] Last block stored, IsPre 0, WriteTaskId 0
[*07/30/2023 05:10:20.5680] Image transfer completed from WLC, last 1
[*07/30/2023 05:10:20.5680] wtpProcessImageDataRequest(10): fileName ap1g7, pre 0
[*07/30/2023 05:10:20.5950] upgrade.sh: Script called with args:[PREDOWNLOAD]
[*07/30/2023 05:10:20.6390] do PREDOWNLOAD, part1 is active part
[*07/30/2023 05:10:20.6510] upgrade.sh: Start doing upgrade arg1=PREDOWNLOAD arg2= arg3= ...
[*07/30/2023 05:10:20.7180] upgrade.sh: Using image /tmp/part.tar on axel-bcm ...
[*07/30/2023 05:10:21.6950] Image signing verify success.

Re: AP got dissociated from vWLC - Error while upgrading

Leo Laohoo — Sun, 30 Jul 2023 04:18:27 GMT

Interesting fix.

Thanks for providing the update.

Re: AP got dissociated from vWLC - Error while upgrading

Flavio Miranda — Sun, 30 Jul 2023 11:15:09 GMT

Hi @EURL_IPSENS yes, it should work as per the compatibility matrix and it seens it worked. Congrats and thanks for sharing here. It is not the first time I saw people struggling with this problem around here and now we can recommend your solution.