Logs are partially missing when saving to USB drive

I'm using the latest OpenWRT 21.02 on my DLink DIR 2640 which has an MT7615N SoC.

I want to enable persistent logging because, sometimes, my router reboots without my interaction and I can't figure out why.

I inserted a USB drive to my router and have mounted it at /data. I edited /etc/config/system and configured the option log_file to /data/logs/messages. However,

  • most of the early boot messages aren't written to /data/logs/messages but only visible using logread

  • logs are written in incorrect order (chronologically).

Here's how the /data/logs/messages file looks like after a reboot. The logs shown below are what's actually written as the first message after boot. You can notice how some logs from 01:00 are written before 00:59.

Fri Oct 29 00:11:18 2021 daemon.err uhttpd[3187]: luci: accepted login on / for root from 192.168.1.100
Fri Oct 29 00:13:08 2021 cron.err crond[4316]: crond (busybox 1.33.1) started, log level 5
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan0: interface state ENABLED->DISABLED
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan0: AP-DISABLED
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan0: CTRL-EVENT-TERMINATING
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
Fri Oct 29 01:00:04 2021 daemon.notice netifd: Network device 'wlan0' link is down
Fri Oct 29 01:00:04 2021 daemon.notice netifd: Interface 'guest' has link connectivity loss
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan1: interface state ENABLED->DISABLED
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan1: AP-DISABLED
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: wlan1: CTRL-EVENT-TERMINATING
Fri Oct 29 01:00:04 2021 daemon.notice hostapd: nl80211: deinit ifname=wlan1 disabled_11b_rates=0
Fri Oct 29 01:00:05 2021 daemon.notice dnscrypt-proxy[1457]: Stopped.
Fri Oct 29 00:59:59 2021 user.notice dnsmasq: DNS rebinding protection is active, will discard upstream RFC1918 responses!
Fri Oct 29 00:59:59 2021 user.notice dnsmasq: Allowing 127.0.0.0/8 responses
Fri Oct 29 00:59:59 2021 daemon.info dnsmasq[1649]: Connected to system UBus
Fri Oct 29 00:59:59 2021 daemon.info dnsmasq[1649]: started, version 2.85 cachesize 150
Fri Oct 29 00:59:59 2021 daemon.info dnsmasq[1649]: DNS service limited to local subnets
Fri Oct 29 00:59:59 2021 daemon.info dnsmasq[1649]: compile time options: IPv6 GNU-getopt no-DBus UBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-cryptohash no-DNSSEC no-ID loop-detect inotify dumpfile
Fri Oct 29 00:59:59 2021 daemon.info dnsmasq[1649]: UBus support enabled: connected to system bus

How can I fix this? I want all the messages since boot to be logged to that file and the chronological order of logging shouldn't be buggy.

Do I need to change the priority of the fstab process which mounts the USB stick? If yes, do I just edit the /etc/init.d/fstab file?

That is probably to the NTP time sync correcting the time after the reboot.
Apparently it first corrected a lot from 00:13:08 to 01:00:04, and then a few seconds later adjusted back 6 seconds (from 01:00:05 to 00:59:59).

(Most routers do not have real-time clock, so the initial boot time reflects the firmware build date/time or the date/time of the more recent file in /etc, until NTP kicks in and corrects the time from internet.)

2 Likes

Is there a way to fix this issue though? I'm reluctant to move over to rsyslog or syslog-ng because I don't want to export my logs to remote hosts and don't want to deal with configuring either of them, which is why I'm using got a USB drive to store logs.

What's interesting is that logread presents the log correctly but the file in /data/logs/messages itself doesn't. Do I need to change the priority of the log/fstab process? Do I need to switch to rsyslog/syslog-ng to fix this?

Sure, buy a device with RTC built in.

So there's no way to enable persistent logging which logs everything since boot in the correct order besides buying a router with RTC?