GNU bug report logs - #78852
shepherd: internal syslog records not in chronological order

Previous Next

Full log

View this message in rfc822 format

From: burban <at> opopop.net
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 78852 <at> debbugs.gnu.org
Subject: bug#78852: shepherd: internal syslog records not in chronological order
Date: Wed, 02 Jul 2025 23:01:13 +0000

Hello,

That the lines from /dev/kmsg are dumped concurrently with
these from shepherd services is to be expected of course.

But when ‘system-log’ starts, it would be logical to flush first
/proc/kmesg while keeping on hold it's own messaging until that is
done.

I don't know how hard that would be to implement, my hope was that the
syslog service is already a bit special (it's generated with hard
coded start and stop for instance).

And yes, timestamps in the boot process logs are bogus also with
traditional logging systems before they start, but the ordering is at
least ok.

Ludovic Courtès <ludo <at> gnu.org> writes:

> Hi,
>
> burban <at> opopop.net 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’.

Sincerely.

-- 

Bernard

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.