Re: Cisco 9120 AP not swapping image on change of controller

james.mathieson · ‎08-02-2023

Hi all,

I've got a Cisco 9800-40 WLC with software 17.6.5

I've also got a WLC 5520 with software 8.10.151

If I try to move a 9210 from the 9800 to the 5520 the AP doesn't move, even after I change the controller on the HA tab and reload the AP.

Although the AP has the image on for the 5520, it stays on the image for the 9800 unless I manually change the path.

Once the path is changed then it moves across fine.

Does anyone know why this manual intervention is needed?

Many thanks.

James

Claes Karlsson · ‎08-02-2023

Hi,

What do you mean by saying "manually change the path"? There was a "bug" regarding certificates that made it impossible to download the new image from 9800 after passing a specific date (see the thread in the link below), but I think that was only for the 17.3.x version and should be solved in this newer releases.

https://community.cisco.com/t5/wireless/5520-to-9800-migration-and-ap-image-certificate-issues/td-p/4798716

What does the console says?

There should not be any manual intervention besides changing the Primary Controller IP-adress for the APs. I have migrated several APs from AireOS to 9800. Both manually and with Prime Infrastructure. Never ran into any issues.

james.mathieson · ‎08-02-2023

When I say, manually change the image, I mean SSH to the AP, and change the boot path - then it works fine.

This is unusual and this isn't the first time I've moved APs but they seem to get stuck moving across on their own.

I can wait for ages and nothing happens, then reboot the AP and it remains on the 9800 image.

When I do a show config from the AP, you can see the controller is now the 5520 but becuase the image isn't flippng over on its own, then the AP isn't moving.

Claes Karlsson · ‎08-02-2023

Gaah, OK. Just figured out the problem description.. I thought this was a move from 5520 to 9800.

Why would you like to move from a 9800 to a 5520? 9800 Is the new platform and the way to go forward

I would still check the console output from the 9120 to see if it display any info during the move. You can also have a look at Ap Join statistics on the 5520 to see if it displays any clues there.

It should be easy to move from a 9800 to a 5520 without any problems.

Flavio Miranda · ‎08-02-2023

Hi @james.mathieson

Usually you dont need to reload, only adding the wlc on the HA tab and save the config, the AP swap a few minutes later.

Try to change the AP failover priority from Low to High.

And, in the Join profile, check the option Enable Fallback under capwap.

JPavonM · ‎08-02-2023

Have you checked the console while trying to join AireOS WLC looking for the errors?

Also, enable CAPWAP debugging in the WLC to see what is happening.

Leo Laohoo · ‎08-02-2023

Post the serial number of that AP.

james.mathieson · ‎08-02-2023

Hey Leo,

Here you go...

FCW2541YYEL

James

Leo Laohoo · ‎08-02-2023

Remote or console into the AP and post the complete output to the command "sh logs".

james.mathieson · ‎08-02-2023

Here you go...

Console logging : Level - notification, Status - enabled

Syslog logging : Level - warning, Status - active, IP - 10.151.x.x

System logging :
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.7860] capwapd: reading file /click/nss_lag_control/capwap_state: No such file or directory
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.7860]
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.7860] !!!!! {/opt/cisco/bin/capwapd} reading /click/nss_lag_control/capwap_state failed [2]: No such file or directory
Aug 2 12:02:06 brain: CDP PoE - waiting for CDP from PSE, timeout 59
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.8350] USB Device Disconnected from the AP
Aug 2 12:02:06 kernel: [08/02/2023 12:02:06.8740] NXP-RHL-Driver 0001:01:00.0: rhbwifi_sysfs_get_cal_ptr: offset[6fa0], size[12240]
Aug 2 12:02:06 kernel: SUBSYSTEM=pci
Aug 2 12:02:06 kernel: DEVICE=+pci:0001:01:00.0
Aug 2 12:02:06 kernel: [08/02/2023 12:02:06.9760] NXP-RHL-Driver 0001:01:00.0: rhbwifi_sysfs_get_cal_ptr: offset[9f70], size[12240]
Aug 2 12:02:06 kernel: SUBSYSTEM=pci
Aug 2 12:02:06 kernel: DEVICE=+pci:0001:01:00.0
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] EEPROM Size = 65536
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] loading trx table from EEPROM to DTCM
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] 24480 bytes copied from RHL EEPROM to DTCM
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] EEPROM Size = 65536
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] loading ro1 table from EEPROM to DTCM
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] 12240 bytes copied from RHL EEPROM to DTCM
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] EEPROM Size = 65536
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] loading ro2 table from EEPROM to DTCM
Aug 2 12:02:06 kernel: [*08/02/2023 12:02:06.9790] 12240 bytes copied from RHL EEPROM to DTCM
Aug 2 12:02:07 FIPS[5907]: *** /opt/cisco/bin/wcpd: FIPS Mode = disabled ***
Aug 2 12:02:07 kernel: [*08/02/2023 12:02:07.1240] systemd[1]: Started WCPD process.
Aug 2 12:02:07 kernel: [*08/02/2023 12:02:07.7100] WCP: Opening /var/platform/num_wan_ports failed!
Aug 2 12:02:07 kernel: [*08/02/2023 12:02:07.7320] DOT11_TXP[0]:Domain configured: 12 class:E
Aug 2 12:02:07 brain: CDP PoE - waiting for CDP from PSE, timeout 58
Aug 2 12:02:07 kernel: [*08/02/2023 12:02:07.9050] DOT11_TXP[0]:Domain configured: 12 class:E
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.1060] DOT11_TXP[0]:Domain configured: 1 class:E
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.1760] flags value is 0 process ble_init
Aug 2 12:02:08 root: BLE reset lock acquired
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.3720] Error: Socket open failed
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.5460] DOT11_DRV[1]: BCM FIPS POST for CCMP-128 and GCMP-128 passed
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.5460] DOT11_DRV[1]: Stop Radio1
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.5460] Stopped Radio 1
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.5680] GB (GB/0) UNITED KINGDOM
Aug 2 12:02:08 kernel: [*08/02/2023 12:02:08.5740] DOT11_DRV[1]: set_channel Channel set to 36/20
Aug 2 12:02:08 brain: CDP PoE - waiting for CDP from PSE, timeout 57
Aug 2 12:02:09 kernel: [*08/02/2023 12:02:09.6120] DOT11_DRV[0]: BCM FIPS POST for CCMP-128 and GCMP-128 passed
Aug 2 12:02:09 kernel: [*08/02/2023 12:02:09.6130] DOT11_DRV[0]: Stop Radio0
Aug 2 12:02:09 kernel: [*08/02/2023 12:02:09.6130] Stopped Radio 0
Aug 2 12:02:09 kernel: [*08/02/2023 12:02:09.6360] GB (GB/0) UNITED KINGDOM
Aug 2 12:02:09 kernel: [*08/02/2023 12:02:09.6420] DOT11_DRV[0]: set_channel Channel set to 6/20
Aug 2 12:02:09 brain: CDP PoE - waiting for CDP from PSE, timeout 56
Aug 2 12:02:10 kernel: [*08/02/2023 12:02:10.3800] DOT11_DRV[2]: off_channel timeout but no req in progress
Aug 2 12:02:10 root: released BLE reset lock
Aug 2 12:02:10 brain: CDP PoE - waiting for CDP from PSE, timeout 55
Aug 2 12:02:11 brain: CDP PoE - waiting for CDP from PSE, timeout 54
Aug 2 12:02:11 kernel: [*08/02/2023 12:02:11.9470] size: 17475 bytes (48061 left)
Aug 2 12:02:12 kernel: [*08/02/2023 12:02:12.2030] DOT11_DRV[0]: set_channel Channel set to 6/20
Aug 2 12:02:12 fw_dnld_iot.py: IOT Firmware utility initiated by ble_init
Aug 2 12:02:12 kernel: [*08/02/2023 12:02:12.4230] wl: Unsupported
Aug 2 12:02:12 kernel: [*08/02/2023 12:02:12.7060] systemd[1]: Started Security Auditing Service.
Aug 2 12:02:12 brain: CDP PoE - waiting for CDP from PSE, timeout 53
Aug 2 12:02:13 kernel: [*08/02/2023 12:02:13.3010] DOT11_DRV[0]: set_channel Channel set to 6/20
Aug 2 12:02:13 brain: CDP PoE - waiting for CDP from PSE, timeout 52
Aug 2 12:02:14 kernel: [*08/02/2023 12:02:14.2820] DOT11_DRV[0]: set_channel Channel set to 6/20
Aug 2 12:02:14 kernel: [*08/02/2023 12:02:14.5810] DOT11_DRV[0]: set_channel Channel set to 6/20
Aug 2 12:02:14 brain: CDP PoE - waiting for CDP from PSE, timeout 51
Aug 2 12:02:15 brain: CDP PoE - waiting for CDP from PSE, timeout 50
Aug 2 12:02:15 brain: dhcpc succeeded on wired0
Aug 2 12:02:15 brain: do_state:5013: assigning brain state: gateway_check 0; reason: dhcp_on_wired0
Aug 2 12:02:15 kernel: [*08/02/2023 12:02:15.9090] ethernet_port wired0, ip 192.168.15.118, netmask 255.255.254.0, gw 192.168.15.254, mtu 1500, bcast 192.168.15.255, dns1 10.151.32.12, dns2 10.151.32.10, domain XSWLSTG-TR.NHS.UKDOT11_DRV[0]: set_channel Channel set to 6/20
Aug 2 12:02:17 kernel: [*08/02/2023 12:02:17.2280] size: 17475 bytes (48061 left)
Aug 2 12:02:17 kernel: [*08/02/2023 12:02:17.4470] wl: Bad Channel
Aug 2 12:02:17 kernel: [*08/02/2023 12:02:17.4480] DOT11_DRV[1]: set_channel Channel set to 108/80
Aug 2 12:02:17 kernel: [*08/02/2023 12:02:17.6460] wl: Unsupported
Aug 2 12:02:18 kernel: [*08/02/2023 12:02:18.4550] DOT11_DRV[1]: set_channel Channel set to 108/80
Aug 2 12:02:19 kernel: [*08/02/2023 12:02:19.6180] DOT11_DRV[1]: set_channel Channel set to 108/80
Aug 2 12:02:20 kernel: [*08/02/2023 12:02:20.7070] DOT11_DRV[1]: set_channel Channel set to 108/80
Aug 2 12:02:20 kernel: [*08/02/2023 12:02:20.9120] DOT11_DRV[1]: set_channel Channel set to 108/80
Aug 2 12:02:22 kernel: [*08/02/2023 12:02:22.5590] DOT11_DRV[1]: set_channel Channel set to 108/80
Aug 2 12:02:23 brain: transitioning from scan1 to gateway_check 0
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.0770] systemd[1]: Starting dnsmasq watcher...
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.1030] systemd[1]: Starting DNSmasq for host...
Aug 2 12:02:23 dnsmasq[8104]: started, version 2.85 cache disabled
Aug 2 12:02:23 dnsmasq[8104]: compile time options: IPv6 GNU-getopt no-DBus no-UBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-cryptohash no-DNSSEC loop-detect inotify dumpfile
Aug 2 12:02:23 dnsmasq[8104]: using nameserver 10.151.x.x#53
Aug 2 12:02:23 dnsmasq[8104]: using nameserver 10.151.x.x#53
Aug 2 12:02:23 dnsmasq[8104]: read /etc/hosts - 3 addresses
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.1740] systemd[1]: Started DNSmasq for host.
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.1940] systemd[1]: Started dnsmasq watcher.
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.2470] systemd[1]: Starting dnsmasq watcher...
Aug 2 12:02:23 dnsmasq[8104]: exiting on receipt of SIGTERM
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.2590] systemd[1]: Stopping DNSmasq for host...
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.2630] systemd[1]: Starting DNSmasq for host...
Aug 2 12:02:23 dnsmasq[8132]: started, version 2.85 cache disabled
Aug 2 12:02:23 dnsmasq[8132]: compile time options: IPv6 GNU-getopt no-DBus no-UBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-cryptohash no-DNSSEC loop-detect inotify dumpfile
Aug 2 12:02:23 dnsmasq[8132]: using nameserver 10.151.x.x#53
Aug 2 12:02:23 dnsmasq[8132]: using nameserver 10.151.x.x#53
Aug 2 12:02:23 dnsmasq[8132]: read /etc/hosts - 3 addresses
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.3120] systemd[1]: Started DNSmasq for host.
Aug 2 12:02:23 kernel: [*08/02/2023 12:02:23.3300] systemd[1]: Started dnsmasq watcher.
Aug 2 12:02:23 fw_dnld_iot.py: bundled_fw_ver = ['Lodestar', '2.7.20']
Aug 2 12:02:24 brain: CDP PoE - waiting for CDP from PSE, timeout 49
Aug 2 12:02:24 brain: do_state:4921: assigning brain state: gateway_good 0; reason: internet and dns connectivity successful
Aug 2 12:02:24 brain: transitioning from gateway_check 0 to gateway_good 0
Aug 2 12:02:24 brain: boot time: 87.730 seconds, 8143 processes spawned
Aug 2 12:02:24 kernel: [*08/02/2023 12:02:24.2610] AP IPv4 Address updated from 0.0.0.0 to 192.168.15.118
Aug 2 12:02:24 fw_dnld_iot.py: RSP: 04FF10FF070002150AFF020714320000000000
Aug 2 12:02:24 fw_dnld_iot.py: ls_ver = 2.7.20
Aug 2 12:02:24 fw_dnld_iot.py: ls_fw_ver : 2.7.20
Aug 2 12:02:24 fw_dnld_iot.py: upgrade false
Aug 2 12:02:24 fw_dnld_iot.py: FW version is latest. No need to upgrade
Aug 2 12:02:25 brain: CDP PoE - waiting for CDP from PSE, timeout 48
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6180] IOT Bootloader Flash Tool 1.4
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6180] Firmware upgrade initiated by ble_init
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6180] bundled_ver_split ['2', '7', '20']
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6790] systemd[1]: Started BLE init service.
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6810] systemd[1]: Reached target Multi-User System.
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6810] systemd[1]: Startup finished in 51.495s (kernel) + 1min 12.145s (initrd) + 22.069s (userspace) = 2min 25.709s.
Aug 2 12:02:25 kernel: [*08/02/2023 12:02:25.6820] systemd[1]: Starting Multi-User System.
Aug 2 12:02:26 brain: CDP PoE - waiting for CDP from PSE, timeout 47
Aug 2 12:02:27 brain: CDP PoE - waiting for CDP from PSE, timeout 46
Aug 2 12:02:28 brain: CDP PoE - waiting for CDP from PSE, timeout 45
Aug 2 12:02:29 brain: CDP PoE negotiation START
Aug 2 12:02:31 brain: CDP PoE negotiation in process, Allocated power 30000 mWatt Requested power 30000 mWatt
Aug 2 12:02:31 brain: Power mode: Full-Power, power_detection: DC_adapter(FALSE), 802.3AF_POE(TRUE)
Aug 2 12:02:31 SYS-COND: AP is in good condition
Aug 2 12:02:31 SYS-COND: Set radio 0 power 4 antenna mask 0xF
Aug 2 12:02:31 SYS-COND: Set radio 1 power 4 antenna mask 0xF
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1020] systemd[1]: Starting dhcpv6 client watcher...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1060] systemd[1]: Starting Core Files Uploader Watcher...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1270] systemd[1]: Stopping DHCPv6 client...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1340] systemd[1]: Starting DHCPv6 client...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1400] systemd[1]: Started Core Files Uploader.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1410] systemd[1]: Starting Core Files Uploader...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1550] systemd[1]: Started Core Files Uploader Watcher.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1710] systemd[1]: Started DHCPv6 client.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.1950] systemd[1]: Started dhcpv6 client watcher.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.2770] systemd[1]: Starting dhcpv6 client watcher...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.2890] systemd[1]: Stopping DHCPv6 client...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.2930] systemd[1]: Starting DHCPv6 client...
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.3230] systemd[1]: Started DHCPv6 client.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.3430] systemd[1]: Started dhcpv6 client watcher.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6190] dtls_init: Use SUDI certificate
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6200]
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6200] CAPWAP State: Init
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6240]
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6240] CAPWAP State: Discovery
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6300] Discovery Request sent to 192.168.15.249, discovery type STATIC_CONFIG(1)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6310] Discovery Request sent to 192.168.100.249, discovery type STATIC_CONFIG(1)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6330] Discovery Request sent to 10.206.253.249, discovery type STATIC_CONFIG(1)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6330] Got WLC address 192.168.15.249 from DHCP.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6330] IP DNS query for CISCO-CAPWAP-CONTROLLER.XSWLSTG-TR.NHS.UK
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6400] Discovery Request sent to 192.168.15.249, discovery type STATIC_CONFIG(1)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6420] Discovery Request sent to 192.168.100.249, discovery type STATIC_CONFIG(1)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6530] Discovery Request sent to 10.206.253.249, discovery type STATIC_CONFIG(1)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6540] Discovery Request sent to 255.255.255.255, discovery type UNKNOWN(0)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6550]
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6550] CAPWAP State: Discovery
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6550] Discovery Response from 192.168.100.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6840] Start: RPC thread 2323276672 created.
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 10.206.253.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 192.168.15.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 192.168.15.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 192.168.100.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 10.206.253.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 192.168.15.249
Aug 2 12:02:48 FIPS[8517]: *** /usr/sbin/sshd: FIPS Mode = disabled ***
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.0000] Started wait dtls timer (60 sec)
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.0000]
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.0000] CAPWAP State: DTLS Setup
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.0380] dtls_verify_server_cert: Controller certificate verification successful
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.5730] sudi99_request_check_and_load: Use HARSA SUDI certificate
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.9140]
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.9140] CAPWAP State: Join
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.9170] Sending Join request to 192.168.100.249 through port 5278
Aug 2 12:04:43 sshd[8517]: error: Could not get shadow information for xxx
Aug 2 12:04:43 sshd[8517]: Accepted password for xxx from 10.199.109.253 port 4378 ssh2
Aug 2 12:04:43 FIPS[8592]: *** shell: FIPS Mode = disabled ***
Aug 2 12:04:50 kernel: [*08/02/2023 12:04:50.0310] systemd[1]: Starting dhcpv6 client watcher...
Aug 2 12:04:50 kernel: [*08/02/2023 12:04:50.0500] systemd[1]: Stopping DHCPv6 client...
Aug 2 12:04:50 kernel: [*08/02/2023 12:04:50.0550] systemd[1]: Starting DHCPv6 client...
Aug 2 12:04:50 kernel: [*08/02/2023 12:04:50.0870] systemd[1]: Started DHCPv6 client.
Aug 2 12:04:50 kernel: [*08/02/2023 12:04:50.1090] systemd[1]: Started dhcpv6 client watcher.
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.0340]
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.0340] CAPWAP State: DTLS Teardown
Aug 2 12:05:37 upgrade: Script called with args:[CANCEL]
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.1460] status 'upgrade.sh: Script called with args:[CANCEL]'
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.1890] do CANCEL, part2 is active part
Aug 2 12:05:37 upgrade: Cleanup tmp files ...
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.2120] status 'upgrade.sh: Cleanup tmp files ...'
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.2360] Dropping dtls packet since session is not established. Peer 192.168.100.249-5246, Local 192.168.15.118-5278, conn (nil)
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.2360] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
Aug 2 12:05:37 kernel: [*08/02/2023 12:05:37.2360] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7830]
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7830] CAPWAP State: Discovery
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7850] Discovery Request sent to 192.168.15.249, discovery type STATIC_CONFIG(1)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7870] Discovery Request sent to 192.168.100.249, discovery type STATIC_CONFIG(1)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7870] systemd[1]: Starting dhcpv6 client watcher...
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7880] Discovery Request sent to 10.206.253.249, discovery type STATIC_CONFIG(1)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7930] Got WLC address 192.168.15.249 from DHCP.
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7930] IP DNS query for CISCO-CAPWAP-CONTROLLER.XSWLSTG-TR.NHS.UK
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7980] Discovery Request sent to 192.168.15.249, discovery type STATIC_CONFIG(1)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.7990] Discovery Request sent to 192.168.100.249, discovery type STATIC_CONFIG(1)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8000] Discovery Request sent to 10.206.253.249, discovery type STATIC_CONFIG(1)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Request sent to 255.255.255.255, discovery type UNKNOWN(0)
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Response from 192.168.15.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Response from 192.168.100.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Response from 10.206.253.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Response from 192.168.15.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Response from 192.168.100.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8020] Discovery Response from 10.206.253.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8030] Discovery Response from 192.168.15.249
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8180] systemd[1]: Stopping DHCPv6 client...
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8260] systemd[1]: Starting DHCPv6 client...
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8560] systemd[1]: Started DHCPv6 client.
Aug 2 12:05:51 kernel: [*08/02/2023 12:05:51.8790] systemd[1]: Started dhcpv6 client watcher.
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.0000] Started wait dtls timer (60 sec)
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.0000]
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.0000] CAPWAP State: DTLS Setup
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.0420] dtls_verify_server_cert: Controller certificate verification successful
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.3800]
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.3800] CAPWAP State: Join
Aug 2 12:06:01 kernel: [*08/02/2023 12:06:01.3820] Sending Join request to 192.168.100.249 through port 5278
Aug 2 12:06:05 kernel: [*08/02/2023 12:06:05.0980] systemd[1]: Starting Lighttpd Watcher...
Aug 2 12:06:05 kernel: [*08/02/2023 12:06:05.1300] systemd[1]: Started Lighttpd Watcher.
Aug 2 12:06:57 kernel: [*08/02/2023 12:06:57.0970] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: Join(5).
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.0320]
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.0320] CAPWAP State: DTLS Teardown
Aug 2 12:06:58 upgrade: Script called with args:[CANCEL]
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.1160] status 'upgrade.sh: Script called with args:[CANCEL]'
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.1700] do CANCEL, part2 is active part
Aug 2 12:06:58 upgrade: Cleanup tmp files ...
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.1920] status 'upgrade.sh: Cleanup tmp files ...'
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.2230] Dropping dtls packet since session is not established. Peer 192.168.100.249-5246, Local 192.168.15.118-5278, conn (nil)
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.2230] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.2230] Discarding msg CAPWAP_WTP_EVENT_REQUEST(type 9) in CAPWAP state: DTLS Teardown(4).
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7770]
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7770] CAPWAP State: Discovery
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7790] Discovery Request sent to 192.168.15.249, discovery type STATIC_CONFIG(1)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7800] Discovery Request sent to 192.168.100.249, discovery type STATIC_CONFIG(1)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7810] Discovery Request sent to 10.206.253.249, discovery type STATIC_CONFIG(1)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7810] Got WLC address 192.168.15.249 from DHCP.
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7810] IP DNS query for CISCO-CAPWAP-CONTROLLER.XSWLSTG-TR.NHS.UK
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7840] systemd[1]: Starting dhcpv6 client watcher...
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.7980] Discovery Request sent to 192.168.15.249, discovery type STATIC_CONFIG(1)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8070] Discovery Request sent to 192.168.100.249, discovery type STATIC_CONFIG(1)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8080] Discovery Request sent to 10.206.253.249, discovery type STATIC_CONFIG(1)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8090] Discovery Request sent to 255.255.255.255, discovery type UNKNOWN(0)
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8090] Discovery Response from 192.168.100.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8090] Discovery Response from 10.206.253.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8090] Discovery Response from 192.168.15.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8090] Discovery Response from 192.168.15.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8100] systemd[1]: Stopping DHCPv6 client...
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8160] Discovery Response from 192.168.100.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8160] Discovery Response from 192.168.15.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8160] Discovery Response from 10.206.253.249
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8180] systemd[1]: Starting DHCPv6 client...
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8490] systemd[1]: Started DHCPv6 client.
Aug 2 12:07:12 kernel: [*08/02/2023 12:07:12.8690] systemd[1]: Started dhcpv6 client watcher.
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.0000] Started wait dtls timer (60 sec)
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.0000]
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.0000] CAPWAP State: DTLS Setup
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.0440] dtls_verify_server_cert: Controller certificate verification successful
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.3880]
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.3880] CAPWAP State: Join
Aug 2 12:07:23 kernel: [*08/02/2023 12:07:23.3910] Sending Join request to 192.168.100.249 through port 5278

Leo Laohoo · ‎08-02-2023

@james.mathieson wrote:
Aug 2 12:02:24 fw_dnld_iot.py: FW version is latest. No need to upgrade

I do not see anything wrong here.

Post the complete output to the command "sh version".

James M · ‎08-08-2023

Apologies for the late reply. Also please note Cisco made me change my username.

Cisco AP Software, (ap3g3), C2802, RELEASE SOFTWARE
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2023 by Cisco Systems, Inc.
Compiled Tue Jan 24 09:32:07 GMT 2023

ROM: Bootstrap program is U-Boot boot loader
BOOTLDR: U-Boot boot loader Version 2013.01-g2ee3a18aa (Jun 03 2022 - 11:27:17)

SPH-Wandsworth-EIS-AP01 uptime is 0 days, 0 hours, 4 minutes
Last reload time : Wed Aug 9 06:36:25 UTC 2023
Last reload reason : Image Upgrade

cisco AIR-AP2802I-E-K9 ARMv7 Processor rev 1 (v7l) with 1028224/590276K bytes of memory.
Processor board ID FCW2402PAZA
AP Running Image : 17.6.5.22
Primary Boot Image : 17.6.5.22
Backup Boot Image : 8.10.151.0
Primary Boot Image Hash: 9a9d44d3beb92d9a3a7d810a4ff505d11c1fce986d74e6cbf92e52c58d3e7fa20dfa77747e76aecf2c39430029a1d70b64b879babc2ca8df9bf8c45932cedab4
Backup Boot Image Hash:
2 Gigabit Ethernet interfaces
2 802.11 Radios
Radio Driver version : 9.0.5.5-W8964
Radio FW version : 9.1.8.1
NSS FW version : 2.4.28

Base ethernet MAC Address : A0:B4:39:8D:C5:2C
Part Number : 0-000000-00
PCA Assembly Number : 800-105674-01
PCA Revision Number : A0
PCB Serial Number : FOC23497RR9
Top Assembly Part Number : 800-105674-01
Top Assembly Serial Number : FCW2402PAZA
Top Revision Number : A0
Product/Model Number : AIR-AP2802I-E-K9

JPavonM · ‎08-02-2023

From this output AP is selecting 192.168.100.249 WLC because this is the WLC where it was connected before, or this is manually set, or maybe it is the less loaded, and because image version matches the active partition 2. Then for some reason it is not said, this is failing and dropping connection so sending new discovery request and going through the same process once and again:

Aug 2 12:02:24 kernel: [*08/02/2023 12:02:24.2610] AP IPv4 Address updated from 0.0.0.0 to 192.168.15.118
(...)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6330] Got WLC address 192.168.15.249 from DHCP.
(...)
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6550] Discovery Response from 192.168.100.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 10.206.253.249
Aug 2 12:02:42 kernel: [*08/02/2023 12:02:42.6850] Discovery Response from 192.168.15.249
(...)
Aug 2 12:04:40 kernel: [*08/02/2023 12:04:40.9170] Sending Join request to 192.168.100.249 through port 5278
(...)
Aug 2 12:06:58 kernel: [*08/02/2023 12:06:58.2230] Dropping dtls packet since session is not established. Peer 192.168.100.249-5246, Local 192.168.15.118-5278, conn (nil)

I would recommend you to enter CLI from console, and invoke "debug capwap client event|info|detail" to see more details.
I would also recommend you to manually set the primary WLC you want from cli "cawap ap primary-base <WLCName> <WLCIp>".

Rich R · ‎08-04-2023

https://bst.cloudapps.cisco.com/bugsearch/bug/CSCvx98176
Access point with 17.6 or later image cannot join controller running older AireOS

The AP needs to be able join to discover the WLC version and then switch. Since it cannot join it doesn't know to switch. Update AireOS WLC as per below - current latest release is 8.10.185.3

------------------------------
Please click Helpful if this post helped you and Select as Solution (drop down menu at top right of this reply) if this answered your query.
------------------------------
TAC recommended codes for AireOS WLC's and TAC recommended codes for 9800 WLC's
Best Practices for AireOS WLC's, Best Practices for 9800 WLC's and Cisco Wireless compatibility matrix
Check your 9800 WLC config with Wireless Config Analyzer using "show tech wireless" output or "config paging disable" then "show run-config" output on AireOS and use Wireless Debug Analyzer to analyze your WLC client debugs
Field Notice: FN63942 APs and WLCs Fail to Create CAPWAP Connections Due to Certificate Expiration
Field Notice: FN72424 Later Versions of WiFi 6 APs Fail to Join WLC - Software Upgrade Required
Field Notice: FN72524 IOS APs stuck in downloading state after 4 Dec 2022 due to Certificate Expired
- Fixed in 8.10.196.0, latest 9800 releases, 8.5.182.12 (8.5.182.13 for 3504) and 8.5.182.109 (IRCM, 8.5.182.111 for 3504)
Field Notice: FN70479 AP Fails to Join or Joins with 1 Radio due to Country Mismatch, RMA needed
How to avoid boot loop due to corrupted image on Wave 2 and Catalyst 11ax Access Points (CSCvx32806)
Field Notice: FN74035 - Wave2 APs DFS May Not Detect Radar After Channel Availability Check Time
Leo's list of bugs affecting 2800/3800/4800/1560 APs

James M · ‎08-08-2023

That's really interesting Rich.

This used to work fine but then I did do an upgrade on the 9800 to the new version it's on now.

I think this may be the issue which I now need to look into.

James