R7800 - OpenWrt 23.05-SNAPSHOT r23067 (hnyman) - Unexpected Reboot

Hi all!

Been stable for months. Was using PC hardwired to router and lost internet. Figured it was Spectrum, but checked modem logs and nothing. Router logs show this:

Thu Jun  8 23:03:53 2023 daemon.notice netifd: Wireless device 'radio1' is now up
Tue Nov 14 21:59:56 2023 user.notice ntpd: Time set, stratum=16 interval=32 offset=13737363.110430
Tue Nov 14 21:59:57 2023 daemon.info dnsmasq[1]: exiting on receipt of SIGTERM
Tue Nov 14 21:59:58 2023 user.info adblock-4.1.5[4027]: backup directory '/tmp/adblock-Backup' created
Tue Nov 14 21:59:58 2023 user.info adblock-4.1.5[4027]: report directory '/tmp/adblock-Report' created
Tue Nov 14 21:59:58 2023 user.info adblock-4.1.5[4027]: adblock instance started ::: action: start, priority: 0, pid: 4027
Tue Nov 14 21:59:58 2023 user.err banIP-0.8.6-2[4090]: banIP is disabled
Tue Nov 14 22:00:00 2023 kern.warn kernel: [   51.349307] ath10k_pci 0000:01:00.0: 10.4 wmi init: vdevs: 16  peers: 48  tid: 96
Tue Nov 14 22:00:00 2023 kern.warn kernel: [   51.349348] ath10k_pci 0000:01:00.0: msdu-desc: 2500  skid: 32
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.431392] ath10k_pci 0000:01:00.0: wmi print 'P 48/48 V 16 K 144 PH 176 T 186  msdu-desc: 2500  sw-crypt: 0 ct-sta: 0'
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.432217] ath10k_pci 0000:01:00.0: wmi print 'free: 84920 iram: 13156 sram: 11224'
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.816605] ath10k_pci 0000:01:00.0: rts threshold -1
Tue Nov 14 22:00:01 2023 kern.warn kernel: [   51.816949] ath10k_pci 0000:01:00.0: Firmware lacks feature flag indicating a retry limit of > 2 is OK, requested limit: 4
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.823162] br-lan: port 3(phy0-ap0) entered blocking state
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.831707] br-lan: port 3(phy0-ap0) entered disabled state
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.837450] device phy0-ap0 entered promiscuous mode
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.842745] br-lan: port 3(phy0-ap0) entered blocking state
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.847904] br-lan: port 3(phy0-ap0) entered forwarding state
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: started, version 2.89 cachesize 1000
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: DNS service limited to local subnets
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: compile time options: IPv6 GNU-getopt no-DBus UBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-nftset no-auth no-cryptohash no-DNSSEC no-ID loop-detect inotify dumpfile
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: UBus support enabled: connected to system bus
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq-dhcp[1]: DHCP, IP range 192.168.6.100 -- 192.168.6.249, lease time 12h
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using nameserver 209.18.47.62#53
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using nameserver 209.18.47.63#53
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Tue Nov 14 22:00:01 2023 daemon.err dnsmasq[1]: failed to load names from /etc/dnsmasq.hosts: No such file or directory
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 11 names
Tue Nov 14 22:00:01 2023 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Tue Nov 14 22:00:01 2023 daemon.notice hostapd: ACS: Automatic channel selection started, this may take a bit
Tue Nov 14 22:00:01 2023 daemon.notice hostapd: phy0-ap0: interface state UNINITIALIZED->ACS
Tue Nov 14 22:00:01 2023 daemon.notice hostapd: phy0-ap0: ACS-STARTED
Tue Nov 14 22:00:01 2023 kern.info kernel: [   51.870277] br-lan: port 3(phy0-ap0) entered disabled state
Tue Nov 14 22:00:01 2023 daemon.err collectd[2938]: plugin_read_thread: read-function of the `iwinfo' plugin took 13737373.673 seconds, which is above its read interval (30.000 seconds). You might want to adjust the `Interval' or `ReadThreads' settings.
Tue Nov 14 22:00:01 2023 user.notice nlbwmon: Reloading nlbwmon due to ifup of loopback (lo)
Tue Nov 14 22:00:02 2023 user.notice firewall: Reloading firewall due to ifup of WG0 (WG0)

The second line (one related to this incident) and this line:

Tue Nov 14 22:00:01 2023 daemon.err collectd[2938]: plugin_read_thread: read-function of the `iwinfo' plugin took 13737373.673 seconds, which is above its read interval (30.000 seconds). You might want to adjust the `Interval' or `ReadThreads' settings.

Looks like router rebooted? I could not find anything by searching for those lines. 2 references to "13737373...seconds" seems odd.

Thoughts?

The second line is only the ntp time jump at boot to sync the time to the right time.

1 Like

Not odd.
There is no realtime clock, so the time starts from the last file timestamp in /etc, and then ntp fetches correct time from net. Collectd had started before that, and then noticed the 5-month jump.

The problem is that if you don’t have a hard saved log system setup somewhere the log from before the reboot is lost in ram memory.

But I doubt the pre boot log would matter since reboots mostly are caused by hardware failures without any pre-warning.