Restarting syslogd repeats kernel log messages in log file(s) #29
Comments
troglobit
changed the title
opty77
referenced
this issue
in rgerhards/rsyslog
Oct 31, 2023
... as module parameters. Here, "parseKernelTimestamp" is modelled after the same param from imklog. In essence, it permits to ignore all kernel time stamps and use current time instead. Parameter fixKernelTimeStamp uses the kernel time stamp during the initial read loop of /dev/kmsg, but replaced it later ignores it for later reads. The reasoning at least for the later is given in a sysklogd commit by Joachim Wiberg, which we reproduce here to have a stable reference. The commit itself can be found for example at: troglobit/sysklogd@9f6fbb3 ============== QUOTE =============== The spec[1] says the /dev/kmsg timestamp is a monotonic clock and in microseconds. After a while you realize it's also relative to the boot of the system, that fact was probably too obvious to be put in the spec. However, what's *not* in the spec, and what takes a while to realize, is that this monotonic time is *not* adjusted for suspend/resume cycles ... On a frequently used laptop this can manifest itself as follows. The kernel is stuck on Nov 15, and for the life of me I cannot find any to adjust for this offset: $ dmesg -T |tail -1; date [Mon Nov 15 01:42:08 2021] wlan0: Limiting TX power to 23 (23 - 0) dBm as advertised by 18:e8:29:55:b0:62 Tue 23 Nov 2021 05:20:53 PM CET Hence this patch. After initial "emptying" of /dev/kmsg when syslogd starts up, we raise a flag (denoting done with backlog), and after this point we ignore the kernel's idea of time and replace it with the actual time we have now, the same that userspace messages are logged with. Sure, there will be occasions where there's a LOT of kernel messages to read and we won't be able to keep track. Yet, this patch is better than the current state (where we log Nov 15). [1]: https://www.kernel.org/doc/Documentation/ABI/testing/dev-kmsg ===========END QUOTE =============== closes rsyslog#4561 closes rsyslog#5161
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Since v2.2.0, and the change from /proc/kmsg to /dev/kmsg, sysklogd repeats kernel log messages when restarting the daemon.
Comment: this is because reading from /dev/kmsg doesn't empty the ring buffer. This allows multiple consumers. The solution in syslogd could be to track the last read/logged sequence number.
The text was updated successfully, but these errors were encountered: