Subject: Re: bug#78852: shepherd: internal syslog records not in chronological order

From: Ludovic Courtès <[email-masked]>
Date: Sun, 29 Jun 2025 12:19:49 +0200

Hi,

[email-masked] writes:

> ... /dev/kmsg and shepherd messages interleaved, but obviously not in chronological order
>
> 2025-06-20 16:59:44 localhost shepherd[1]: Service mountall running with value #t.
> 2025-06-20 16:59:44 localhost shepherd[1]: Starting service rsyslogd...
> 2025-06-20 16:59:44 localhost shepherd[1]: Service rsyslogd has been started.
> 2025-06-20 16:59:44 localhost shepherd[1]: Service rsyslogd started.
> 2025-06-20 16:59:44 localhost linux: [ 0.000000] Command line:
> BOOT_IMAGE=/boot/vmlinuz-6.1.0-21-amd64
> root=UUID=b5539695-8658-493c-9197-a59078c20f65 ro init=/bin/shepherd
> quiet
> 2025-06-20 16:59:44 localhost shepherd[1]: Service rsyslogd running with value #<system-log 7fcf42806d00>.
> 2025-06-20 16:59:44 localhost shepherd[1]: Starting service mountall-bootclean...
> 2025-06-20 16:59:44 localhost shepherd[1]: Service mountall-bootclean started.
> 2025-06-20 16:59:44 localhost shepherd[1]: Service mountall-bootclean running with value #t.
> 2025-06-20 16:59:44 localhost linux: [    0.000000] BIOS-provided physical RAM map:

/dev/kmsg is read when ‘system-log’ starts, and it already contains lots
of lines.  These lines are dumped concurrently with logging output
coming from shepherd services, hence this behavior.

The problem is that /dev/kmsg doesn’t associate a proper timestamp with
each line (only the elapsed time since boot in square brackets).  Thus
I’m not sure what can be done here.

If you have ideas from other such systems, please share!

Thanks,
Ludo’.