Ap reboot 3800

[Anjana A]

Hello Team,

we are using 3800i access point and those ap's are associated with 9800 wlc.

Today all of sudden not all few ap's went down.

enclosed ap logs from ap cli, which went down.

Oct 10 09:55:14 kernel: [*10/10/2023 09:55:14.9508] systemd[1]: Started dnsmasq watcher.
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.0403] systemd[1]: Starting dnsmasq watcher...
Oct 10 09:55:15 dnsmasq[9393]: exiting on receipt of SIGTERM
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.0609] systemd[1]: Stopping DNSmasq for host...
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.0651] systemd[1]: Starting DNSmasq for host...
Oct 10 09:55:15 dnsmasq[9424]: started, version 2.85 cache disabled
Oct 10 09:55:15 dnsmasq[9424]: 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
Oct 10 09:55:15 dnsmasq[9424]: using nameserver x.x.x.x
Oct 10 09:55:15 dnsmasq[9424]: using nameserver x.x.x.x
Oct 10 09:55:15 dnsmasq[9424]: read /etc/hosts - 3 addresses
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.2114] systemd[1]: Started DNSmasq for host.
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.2422] systemd[1]: Started dnsmasq watcher.
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.8298] DOT11_DRV[0]: Stopped Radio 0
Oct 10 09:55:15 kernel: [*10/10/2023 09:55:15.8515] DOT11_DRV[0]: DOT11_DRV[0]: set_channel Channel set to 6
Oct 10 09:55:16 brain: do_state:5135: assigning brain state: gateway_good 0; reason: internet and dns connectivity successful
Oct 10 09:55:16 brain: transitioning from gateway_check 0 to gateway_good 0
Oct 10 09:55:16 brain: boot time: 103.700 seconds, 9522 processes spawned
Oct 10 09:55:16 kernel: [*10/10/2023 09:55:16.4454] DOT11_DRV[0]: Started Radio 0
Oct 10 09:55:17 kernel: [*10/10/2023 09:55:17.7338] DOT11_DRV[0]: Stopped Radio 0
Oct 10 09:55:17 kernel: [*10/10/2023 09:55:17.7554] DOT11_DRV[0]: DOT11_DRV[0]: set_channel Channel set to 6
Oct 10 09:55:18 kernel: [*10/10/2023 09:55:18.4236] DOT11_DRV[0]: Started Radio 0
Oct 10 09:55:18 kernel: [*10/10/2023 09:55:18.6276] DOT11_DRV[0]: Stopped Radio 0
Oct 10 09:55:18 kernel: [*10/10/2023 09:55:18.6506] DOT11_DRV[0]: DOT11_DRV[0]: set_channel Channel set to 6
Oct 10 09:55:19 kernel: [*10/10/2023 09:55:19.2622] DOT11_DRV[0]: Started Radio 0
Oct 10 09:55:20 kernel: [*10/10/2023 09:55:20.5871] bftype is 6
Oct 10 09:55:20 kernel: [*10/10/2023 09:55:20.7191] DOT11_DRV[0]: Stopped Radio 0
Oct 10 09:55:20 kernel: [*10/10/2023 09:55:20.7414] DOT11_DRV[0]: DOT11_DRV[0]: set_channel Channel set to 6
Oct 10 09:55:21 kernel: [*10/10/2023 09:55:21.4534] DOT11_DRV[0]: Started Radio 0
Oct 10 09:55:22 kernel: [*10/10/2023 09:55:22.4752] DOT11_DRV[0]: Stopped Radio 0
Oct 10 09:55:22 kernel: [*10/10/2023 09:55:22.4977] DOT11_DRV[0]: DOT11_DRV[0]: set_channel Channel set to 6
Oct 10 09:55:23 kernel: [*10/10/2023 09:55:23.2011] DOT11_DRV[0]: Started Radio 0
Oct 10 09:55:23 kernel: [*10/10/2023 09:55:23.9871] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:24 kernel: [*10/10/2023 09:55:24.0088] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:24 kernel: [*10/10/2023 09:55:24.2030] AP IPv4 Address updated from 0.0.0.0 to 10.78.251.172
Oct 10 09:55:24 kernel: [*10/10/2023 09:55:24.5902] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:25 kernel: [*10/10/2023 09:55:25.5506] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:25 kernel: [*10/10/2023 09:55:25.5719] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:26 kernel: [*10/10/2023 09:55:26.1580] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:27 kernel: [*10/10/2023 09:55:27.3752] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:27 kernel: [*10/10/2023 09:55:27.3969] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:27 kernel: [*10/10/2023 09:55:27.9804] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:27 kernel: [*10/10/2023 09:55:27.9937] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:28 kernel: [*10/10/2023 09:55:28.0152] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:28 kernel: [*10/10/2023 09:55:28.6169] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:30 kernel: [*10/10/2023 09:55:30.0655] bftype is 6
Oct 10 09:55:30 kernel: [*10/10/2023 09:55:30.1849] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:30 kernel: [*10/10/2023 09:55:30.2067] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:31 kernel: [*10/10/2023 09:55:31.0608] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:32 kernel: [*10/10/2023 09:55:32.0231] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:32 kernel: [*10/10/2023 09:55:32.0454] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:32 kernel: [*10/10/2023 09:55:32.8984] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:33 kernel: [*10/10/2023 09:55:33.8518] DOT11_DRV[1]: Stopped Radio 1
Oct 10 09:55:33 kernel: [*10/10/2023 09:55:33.8733] DOT11_DRV[1]: DOT11_DRV[1]: set_channel Channel set to 149
Oct 10 09:55:34 kernel: [*10/10/2023 09:55:34.2288] systemd[1]: Starting dhcpv6 client watcher...
Oct 10 09:55:34 kernel: [*10/10/2023 09:55:34.2615] systemd[1]: Stopping DHCPv6 client...
Oct 10 09:55:34 kernel: [*10/10/2023 09:55:34.2978] systemd[1]: Starting DHCPv6 client...
Oct 10 09:55:34 kernel: [*10/10/2023 09:55:34.3720] systemd[1]: Started DHCPv6 client.
Oct 10 09:55:34 kernel: [*10/10/2023 09:55:34.4229] systemd[1]: Started dhcpv6 client watcher.
Oct 10 09:55:34 kernel: [*10/10/2023 09:55:34.7926] DOT11_DRV[1]: Started Radio 1
Oct 10 09:55:39 mrvlfwd: Starting main loop on radio 0
Oct 10 09:55:39 mrvlfwd: Starting main loop on radio 1
Oct 10 09:55:39 mrvlfwd: wifi dev 2 open failed, errno 2
Oct 10 09:55:39 mrvlfwd: Init of radio 2 failed!!!!!
Oct 10 09:55:44 kernel: [*10/10/2023 09:55:44.9623] systemd[1]: Starting dhcpv6 client watcher...
Oct 10 09:55:44 kernel: [*10/10/2023 09:55:44.9822] systemd[1]: Starting Core Files Uploader Watcher...
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.0052] systemd[1]: Stopping DHCPv6 client...
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.0642] systemd[1]: Started Core Files Uploader Watcher.
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.1043] systemd[1]: Starting DHCPv6 client...
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.1600] systemd[1]: Started DHCPv6 client.
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.2011] systemd[1]: Started dhcpv6 client watcher.
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.6764] dtls_init: Use SUDI certificate
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.6874]
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.6874] CAPWAP State: Init
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.7945]
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.7945] CAPWAP State: Discovery
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.7982] Discovery Request sent to 10.10.10.10, discovery type STATIC_CONFIG(1)
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.8034] Discovery Request sent to 10.10.10.10, discovery type STATIC_CONFIG(1)
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.8035] Got WLC address 10.10.10.10 from DHCP.
Oct 10 09:55:45 kernel: [*10/10/2023 09:55:45.8036] IP DNS query for CISCO-CAPWAP-CONTROLLER.net.honeywell.com
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.1958] Discovery Request sent to 10.10.10.10, discovery type STATIC_CONFIG(1)
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2129] Discovery Request sent to 10.10.10.10 discovery type STATIC_CONFIG(1)
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2148] Discovery Request sent to 10.10.10.10, discovery type DHCP(2)
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2166] Discovery Request sent to 255.255.255.255, discovery type UNKNOWN(0)
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2250]
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2250] CAPWAP State: Discovery
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2260] Discovery Response from 10.10.10.10
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2312] Discovery Response from 10.10.10.10
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2663] Start: RPC thread 1947667440 created.
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.2664] Discovery Response from 10.10.10.10
Oct 10 09:55:46 kernel: [*10/10/2023 09:55:46.3094] Discovery Response from 10.10.10.10
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.0000] Started wait dtls timer (60 sec)
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.0103]
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.0103] CAPWAP State: DTLS Setup
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.1571] First connect to vWLC, accept vWLC by default
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.1571]
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.1631] dtls_verify_server_cert: vWLC is using SSC, returning 1
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.8695]
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.8695] CAPWAP State: Join
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.9701] OOBImageDnld: OOB Image Download in ap_cap_bitmask(2)
Oct 10 09:57:02 kernel: [*10/10/2023 09:57:02.9705] Sending Join request to 10.10.10.10 through port 5272, packet size 1376
Oct 10 09:57:05 kernel: [*10/10/2023 09:57:05.0154] systemd[1]: Starting dhcpv6 client watcher...
Oct 10 09:57:05 kernel: [*10/10/2023 09:57:05.0399] systemd[1]: Stopping DHCPv6 client...
Oct 10 09:57:05 kernel: [*10/10/2023 09:57:05.0457] systemd[1]: Starting DHCPv6 client...
Oct 10 09:57:05 kernel: [*10/10/2023 09:57:05.1002] systemd[1]: Started DHCPv6 client.
Oct 10 09:57:05 kernel: [*10/10/2023 09:57:05.1347] systemd[1]: Started dhcpv6 client watcher.
Oct 10 09:57:07 kernel: [*10/10/2023 09:57:07.6920] OOBImageDnld: OOB Image Download in ap_cap_bitmask(2)
Oct 10 09:57:07 kernel: [*10/10/2023 09:57:07.6922] Sending Join request to 10.10.10.10 through port 5272, packet size 1376
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.4403] OOBImageDnld: OOB Image Download in ap_cap_bitmask(2)
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.4406] Sending Join request to 10.10.10.10 through port 5272, packet size 896
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.5148] Join Response from 10.10.10.10, packet size 917
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.5148] AC accepted previous sent request with result code: 0
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.5149] Received wlcType 0, timer 30
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.7033]
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.7033] CAPWAP State: Image Data
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.7038] AP image version 17.9.2.52 backup 17.9.3.201, Controller 17.9.2.52
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.7040] Version is the same, do not need update.
Oct 10 09:57:12 upgrade: Script called with args:[NO_UPGRADE]
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.7483] status 'upgrade.sh: Script called with args:[NO_UPGRADE]'
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.8065] do NO_UPGRADE, part2 is active part
Oct 10 09:57:12 syslog: Check lagloadbalance setting flex_mode 1 cfg 0 linkstate 0 ap_type 52
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.8279]
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.8279] CAPWAP State: Configure
Oct 10 09:57:12 kernel: [*10/10/2023 09:57:12.8347] Telnet is not supported by AP, should not encode this payload
Oct 10 09:57:13 kernel: [*10/10/2023 09:57:13.6924] hostapd:dot1x: CTRL-EVENT-EAP-FAILURE EAP authentication failed
Oct 10 09:57:13 kernel: [*10/10/2023 09:57:13.9878] Radio [2] Administrative state DISABLED change to ENABLED
Oct 10 09:57:13 kernel: [*10/10/2023 09:57:13.9887] Radio [1] Administrative state DISABLED change to ENABLED
Oct 10 09:57:13 kernel: [*10/10/2023 09:57:13.9893] Radio [0] Administrative state DISABLED change to ENABLED
Oct 10 09:57:14 kernel: [*10/10/2023 09:57:14.4981]
Oct 10 09:57:14 kernel: [*10/10/2023 09:57:14.4981] CAPWAP State: Run
Oct 10 09:57:14 kernel: [*10/10/2023 09:57:14.5382] AP has joined controller wlc
Oct 10 09:57:14 kernel: [*10/10/2023 09:57:14.5390] Flexconnect Switching to Connected Mode!
Oct 10 09:57:14 kernel: [10/10/2023 09:57:14.7400] audit: audit_lost=51 audit_rate_limit=100 audit_backlog_limit=8192
Oct 10 09:57:14 kernel: [10/10/2023 09:57:14.8400] audit: rate limit exceeded
Oct 10 09:57:16 syslog: Check lagloadbalance setting flex_mode 1 cfg 0 linkstate 0 ap_type 52
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.3873] Previous AP mode is 2, change to 2
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4075] Current session mode: ssh, Configured: Telnet-No, SSH-Yes, Console-Yes
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4075]
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4076] Current session mode: telnet, Configured: Telnet-No, SSH-Yes, Console-Yes
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4076]
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4078] Current session mode: console, Configured: Telnet-No, SSH-Yes, Console-Yes
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4078]
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4163] systemd[1]: Starting Cisco syslogd watcher...
Oct 10 09:57:16 syslog: password for user changed
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.4688] chpasswd: password for user changed
Oct 10 09:57:16 syslogd exiting
Oct 10 09:57:16 syslogd started: BusyBox v1.32.1
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.5906] systemd[1]: Started Cisco syslogd watcher.
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.7002]
Oct 10 09:57:16 kernel: [*10/10/2023 09:57:16.7002] Same LSC mode, no action needed
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.0599] systemd[1]: Starting ntp file watcher...
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.0633] CLSM[00:00:00:00:00:00]: U3 Client RSSI Stats feature is deprecated; can no longer be enabled
Oct 10 09:57:17 syslog: NTP: Tue Oct 10 09:57:17 2023 :Can not create ntp process log file.
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.1019] Update NTP source to WLC
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.1233] systemd[1]: Starting ntp watcher...
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.1262] systemd[1]: Started ntp file watcher.
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.1757] systemd[1]: Started ntp watcher.
Oct 10 09:57:17 kernel: [*10/10/2023 09:57:17.5527] Got WSA Server config TLVs
Oct 10 09:57:00 kernel: [*10/10/2023 09:57:00.2035] systemd[1]: Starting ntp watcher...
Oct 10 09:57:00 kernel: [*10/10/2023 09:57:00.2365] systemd[1]: Starting NTPD daemon...
Oct 10 09:57:00 ntpd[13127]: ntpd 4.2.8p15@1.3728-o Fri Oct 28 21:08:14 UTC 2022 (1): Starting
Oct 10 09:57:00 ntpd[13127]: Command line: /sbin/ntpd
Oct 10 09:57:00 ntpd[13127]: ----------------------------------------------------
Oct 10 09:57:00 ntpd[13127]: ntp-4 is maintained by Network Time Foundation,
Oct 10 09:57:00 ntpd[13127]: Inc. (NTF), a non-profit 501(c)(3) public-benefit
Oct 10 09:57:00 ntpd[13127]: corporation. Support and training for ntp-4 are
Oct 10 09:57:00 ntpd[13127]: available at https://www.nwtime.org/support
Oct 10 09:57:00 ntpd[13127]: ----------------------------------------------------
Oct 10 09:57:00 ntpd[13129]: proto: precision = 0.880 usec (-20)
Oct 10 09:57:00 ntpd[13129]: basedate set to 2022-10-16
Oct 10 09:57:00 ntpd[13129]: gps base set to 2022-10-16 (week 2232)
Oct 10 09:57:00 ntpd[13129]: Listen and drop on 0 v6wildcard [::]:123
Oct 10 09:57:00 ntpd[13129]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Oct 10 09:57:00 ntpd[13129]: Listen normally on 2 lo 127.0.0.1:123
Oct 10 09:57:00 ntpd[13129]: Listen normally on 3 srcr2 10.78.251.172:123
Oct 10 09:57:00 ntpd[13129]: Listen normally on 4 lo [::1]:123
Oct 10 09:57:00 ntpd[13129]: Listen normally on 5 srcr2 [fe80::a223:9fff:feae:de22%49]:123
Oct 10 09:57:00 ntpd[13129]: Listening on routing socket on fd #22 for interface updates
Oct 10 09:57:00 ntpd[13129]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Oct 10 09:57:00 ntpd[13129]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Oct 10 09:57:00 kernel: [*10/10/2023 09:57:00.2647] systemd[1]: Started NTPD daemon.
Oct 10 09:57:00 kernel: [*10/10/2023 09:57:00.2980] systemd[1]: Started ntp watcher.
Oct 10 09:57:00 kernel: [*10/10/2023 09:57:00.4544] SD AVC only supports 802.11ax AP
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1207] systemd[1]: Starting NBAR deamon...
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1281] chatter: wl0: Beacon rate info: Previous: 0 Current: 251660288
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1281] chatter: wl0: Beacon PID : Previous: 0 Current: 0
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1408] systemd[1]: Started NBAR deamon.
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1888] [13169] - 2023-10-10 09:57:01.188 - [WD ][INFO ] - Launched
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1908] [13169] - 2023-10-10 09:57:01.190 - [WD ][INFO ] - Hog timeout: 2000 ms; Kill timeout: 7200000 ms
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.1909] [13169] - 2023-10-10 09:57:01.190 - [WD ][INFO ] - Reload is disabled
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2061] [13175] - 2023-10-10 09:57:01.206 - [server][INFO ] - Current session logging being saved at '/tmp/stilecpd.log'
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2064] [13175] - 2023-10-10 09:57:01.206 - [server][INFO ] - Configured in: 'kernel mode'
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2068] [13175] - 2023-10-10 09:57:01.206 - [server][INFO ] - Version: nitro @ v3.20-26-g14e67cfc
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2070] [13175] - 2023-10-10 09:57:01.207 - [server][INFO ] - Architecture: armv7l @ 32 bit
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2071] [13175] - 2023-10-10 09:57:01.207 - [server][INFO ] - Compiler: gcc 4.7.1
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2073] [13175] - 2023-10-10 09:57:01.207 - [server][INFO ] - Attributes: optimized, slave
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2075] [13175] - 2023-10-10 09:57:01.207 - [server][INFO ] - Loading nitro engine
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2247] [13175] - 2023-10-10 09:57:01.224 - [ipc ][INFO ] - CP to DP socket send queue size: 2097152
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2252] [13175] - 2023-10-10 09:57:01.225 - [server][INFO ] - Activating nitro
Oct 10 09:57:01 kernel: [*10/10/2023 09:57:01.2339] NTKM - ntkm_activate - Activating DP
Oct 10 09:57:03 kernel: [*10/10/2023 09:57:03.4501] [13175] - 2023-10-10 09:57:03.450 - [NBAR ][INFO ] - Engine: 46, Protocol pack: 61.0 , CL: BLD_NBAR_XE179_20220606_160017
Oct 10 09:57:03 kernel: [*10/10/2023 09:57:03.4503] [13175] - 2023-10-10 09:57:03.450 - [server][INFO ] - Nitro activated successfully
Oct 10 09:57:03 kernel: [*10/10/2023 09:57:03.4508] [13175] - 2023-10-10 09:57:03.450 - [server][INFO ] - Waiting for messages
Oct 10 09:57:03 kernel: [*10/10/2023 09:57:03.4651] NTKM - ntkm_check_for_state_change - DP active
Oct 10 09:57:04 kernel: [*10/10/2023 09:57:04.0914] chatter: wl1: Beacon rate info: Previous: 0 Current: 252643328
Oct 10 09:57:04 kernel: [*10/10/2023 09:57:04.0915] chatter: wl1: Beacon PID : Previous: 0 Current: 15
Oct 10 09:57:05 kernel: [*10/10/2023 09:57:05.9258] systemd[1]: Starting nbar watcher...
Oct 10 09:57:06 kernel: [*10/10/2023 09:57:06.0490] systemd[1]: Started nbar watcher.
Oct 10 09:57:26 kernel: [*10/10/2023 09:57:26.0156] set cleanair [slot0][band0] enabled
Oct 10 09:57:26 NCI: I0: openSensor(slot=0)
Oct 10 09:57:26 kernel: [*10/10/2023 09:57:26.0860] set cleanair [slot1][band1] enabled
Oct 10 09:57:27 NCI: I : Entering spawned RxLoop
Oct 10 09:57:27 NCI: I0: SensorApp=7006d32a
Oct 10 09:57:27 NCI: I0: SensorHdw=1.2.300
Oct 10 09:57:27 NCI: I0: Hardware Radio Band = [4890, 5935] MHz, BW=150625, band=1
Oct 10 09:57:27 NCI: I0: Hardware Radio Band = [2400, 2500] MHz, BW=150625, band=0
Oct 10 09:57:27 NCI: slot=0 mode=2 chanCnt=1 cw=1
Oct 10 09:57:27 NCI: Squashed Channel List:
Oct 10 09:57:27 NCI: chans: 6
Oct 10 09:57:27 NCI: cf(MHz): 2437
Oct 10 09:57:27 NCI: I0: channel map channels: in=1 cloned=1
Oct 10 09:57:27 NCI: I0: Requesting MonBand [2437, 2437] bw=20MHz/0 ant=0xbc
Oct 10 09:57:27 NCI: I0: Monitoring (cf=2437, span=20), RadioUsage=3%
Oct 10 09:57:27 NCI: I0: dwell=25000us, update=1000ms, resBW=78126
Oct 10 09:57:27 NCI: CLEANAIR: Slot 0 enabled
Oct 10 09:57:28 NCI: I1: openSensor(slot=1)
Oct 10 09:57:28 mrvlfwd: radio 1: cfg loopback only mode 0
Oct 10 09:57:30 NCI: I1: SensorApp=7006d32a
Oct 10 09:57:30 NCI: I1: SensorHdw=1.2.300
Oct 10 09:57:30 NCI: I1: Hardware Radio Band = [4890, 5935] MHz, BW=150625, band=1
Oct 10 09:57:30 NCI: slot=1 mode=2 chanCnt=2 cw=3
Oct 10 09:57:30 NCI: Squashed Channel List:
Oct 10 09:57:30 NCI: chans: 149 153
Oct 10 09:57:30 NCI: cf(MHz): 5745 5765
Oct 10 09:57:30 NCI: I1: channel map channels: in=2 cloned=2
Oct 10 09:57:30 NCI: I1: Requesting MonBand [5755, 5755] bw=40MHz/0 ant=0xbc
Oct 10 09:57:30 NCI: I1: Monitoring (cf=5755, span=40), RadioUsage=3%
Oct 10 09:57:30 NCI: I1: dwell=20000us, update=1000ms, resBW=156249
Oct 10 09:57:30 NCI: CLEANAIR: Slot 1 enabled
Oct 10 09:57:32 kernel: [*10/10/2023 09:57:32.9408] systemd[1]: Starting Lighttpd Watcher...
Oct 10 09:57:33 kernel: [*10/10/2023 09:57:32.9968] systemd[1]: Started Lighttpd Watcher.
Oct 10 10:02:37 kernel: [*10/10/2023 10:02:37.2243]
Oct 10 10:02:53 ntpd[13129]: set_freq: ntp_loopfilter.c line 1092: invalid struct timex "constant" element value: 0
Oct 10 10:06:04 kernel: [*10/10/2023 10:02:37.2243] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:06:04 kernel: [*10/10/2023 10:06:04.3367]
Oct 10 10:16:28 kernel: [*10/10/2023 10:06:04.3367] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:28 kernel: [*10/10/2023 10:16:28.3244]
Oct 10 10:16:28 kernel: [*10/10/2023 10:16:28.3245] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:28 kernel: [*10/10/2023 10:16:28.9308]
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:28.9309] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.3933]
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.3933] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.3933]
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.3933] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.3933]
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.3933] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.4595]
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.4595] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:29 kernel: [*10/10/2023 10:16:29.6138]
Oct 10 10:16:31 kernel: [*10/10/2023 10:16:29.6138] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:31 kernel: [*10/10/2023 10:16:31.8741]
Oct 10 10:16:32 kernel: [*10/10/2023 10:16:31.8742] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:32 kernel: [*10/10/2023 10:16:32.5992]
Oct 10 10:16:32 kernel: [*10/10/2023 10:16:32.5992] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:32 kernel: [*10/10/2023 10:16:32.5993]
Oct 10 10:16:32 kernel: [*10/10/2023 10:16:32.5993] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:32 kernel: [*10/10/2023 10:16:32.5993]
Oct 10 10:16:33 kernel: [*10/10/2023 10:16:32.5993] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:33 kernel: [*10/10/2023 10:16:33.4916]
Oct 10 10:16:33 kernel: [*10/10/2023 10:16:33.4916] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:16:33 kernel: [*10/10/2023 10:16:33.7716]
Oct 10 10:18:26 kernel: [*10/10/2023 10:16:33.7716] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:18:26 kernel: [*10/10/2023 10:18:26.8212]
Oct 10 10:23:19 kernel: [*10/10/2023 10:18:26.8212] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:23:19 kernel: [*10/10/2023 10:23:19.1826]
Oct 10 10:23:19 kernel: [*10/10/2023 10:23:19.1826] *** RSN ERROR: Received a data frame when no keys are plumbed<30>systemd[1]: Starting nbar watcher...
Oct 10 10:23:19 kernel: [*10/10/2023 10:23:19.4393] systemd[1]: Started nbar watcher.
Oct 10 10:25:12 kernel: [*10/10/2023 10:25:12.9456]
Oct 10 10:40:43 kernel: [*10/10/2023 10:25:12.9456] *** RSN ERROR: Received a data frame when no keys are plumbedCurrent session mode: ssh, Configured: Telnet-No, SSH-Yes, Console-Yes
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.7393]
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.7394] Current session mode: telnet, Configured: Telnet-No, SSH-Yes, Console-Yes
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.7394]
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.7395] Current session mode: console, Configured: Telnet-No, SSH-Yes, Console-Yes
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.7395]
Oct 10 10:40:43 syslog: password for user changed
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.7817] chpasswd: password for user changed
Oct 10 10:40:43 syslog: password for user changed
Oct 10 10:40:43 kernel: [*10/10/2023 10:40:43.8282] chpasswd: password for user changed
Oct 10 10:41:10 kernel: [*10/10/2023 10:41:10.1776]
Oct 10 10:41:10 kernel: [*10/10/2023 10:41:10.1776] *** RSN ERROR: Received a data frame when no keys are plumbed
Oct 10 10:41:10 kernel: [*10/10/2023 10:41:10.2747]
Oct 10 10:41:16 kernel: [*10/10/2023 10:41:10.2747] *** RSN ERROR: Received a data frame when no keys are plumbed<30>systemd[1]: Starting Lighttpd Watcher...
Oct 10 10:41:16 kernel: [*10/10/2023 10:41:16.1203] systemd[1]: Started Lighttpd Watcher.
Oct 10 10:44:37 FIPS[16504]: *** /usr/sbin/sshd: FIPS Mode = disabled ***
Oct 10 10:44:51 sshd[16504]: Invalid user admin from 10.17.21.145 port 56565
Oct 10 10:44:58 sshd[16504]: error: Could not get shadow information for NOUSER
Oct 10 10:44:58 sshd[16504]: Failed password for invalid user admin from 10.10.10.10 port 56565 ssh2
Oct 10 10:45:08 sshd[16504]: Failed password for invalid user admin from 10.10.10.10 port 56565 ssh2
Oct 10 10:46:31 FIPS[17922]: *** /usr/sbin/sshd: FIPS Mode = disabled ***
Oct 10 10:46:37 sshd[16504]: fatal: Timeout before authentication for 10.10.10.10 port 56565
Oct 10 10:46:44 sshd[17922]: error: Could not get shadow information for Admin
Oct 10 10:46:44 sshd[17922]: Accepted password for Admin from 10.10.10.10 port 56620 ssh2
Oct 10 10:46:46 FIPS[18112]: *** shell: FIPS Mode = disabled ***

Regards,

Anjana

[marce1000]

                         - Strange what is in the controller logs when the APs try to join ?
    Further analyze AP joining issues with instructions from : https://logadvisor.cisco.com/logadvisor/wireless/9800/9800APJoin

   Also check the 9800 wlc configuration with the CLI command show tech wireless ; feed the output into :
                                                                                              Wireless Config Analyzer

  M.
                                      

[Rich R]

- Check for AP crashes - see 
https://www.cisco.com/c/en/us/support/docs/wireless/catalyst-9800-series-wireless-controllers/218396-troubleshoot-catalyst-9800-ap-join-or-di.html
https://www.cisco.com/c/en/us/support/docs/wireless/catalyst-9800-series-wireless-controllers/215523-quick-start-guide-on-what-logs-and-debug.html
- Check for power issues
- Check for connectivity issues - when AP can't reach WLC it will retry for a while and eventually reboot in an attempt to restore connectivity with WLC