Hi,
I tried to replace package rsyslog by using shepherd internal logging
service. If everything is directed to say /var/log/shepherd, some lines
are out of sequence, below an example with 1.0.3 on Debian Trixie (the
--- lines are my comments and enclose deleted lines of no direct interest)
======================================
2025-06-19 23:56:11 localhost shepherd[1]: Stopping service
mountall-bootclean...
2025-06-19 23:56:11 localhost shepherd[1]: Service mountall-bootclean stopped.
2025-06-19 23:56:11 localhost shepherd[1]: Service mountall-bootclean is now
stopped.
... Above, the last recorded lines before shepĥerd syslog is stopped because we
have to unmount /var before shutdown
2025-06-20 16:59:44 localhost linux: [ 0.000000] Linux version
6.1.0-21-amd64 (debian-ker...@lists.debian.org) (gcc-12 (Debian 12.2.0-14)
12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 SMP PREEMPT_DYNAMIC Debian
6.1.90-1 (2024-05-03)
... /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:
2025-06-20 16:59:44 localhost shepherd[1]: Service mountall-bootclean has been
started.
2025-06-20 16:59:44 localhost shepherd[1]: Starting service
kernel-variables-setup...
2025-06-20 16:59:44 localhost linux: [ 0.000000] BIOS-e820: [mem
0x0000000000000000-0x000000000009fbff] usable
2025-06-20 16:59:44 localhost linux: [ 0.000000] BIOS-e820: [mem
0x000000000009fc00-0x000000000009ffff] reserved
2025-06-20 16:59:44 localhost linux: [ 0.000000] BIOS-e820: [mem
0x00000000000f0000-0x00000000000fffff] reserved
2025-06-20 16:59:44 localhost linux: [ 0.000000] BIOS-e820: [mem
0x0000000000100000-0x000000005dbdffff] usable
2025-06-20 16:59:44 localhost linux: [ 0.000000] BIOS-e820: [mem
0x000000005dbe0000-0x000000005dbfffff] reserved
...
2025-06-20 16:59:44 localhost linux: [ 0.038751] ACPI: INT_SRC_OVR (bus 0
bus_irq 11 global_irq 11 high level)
2025-06-20 16:59:44 localhost linux: [ 0.038755] ACPI: Using ACPI (MADT) for
SMP configuration information
2025-06-20 16:59:44 localhost linux: [ 0.038756] ACPI: HPET id: 0x8086a201
base: 0xfed00000
2025-06-20 16:59:44 localhost linux: [ 0.038763] smpboot: Allowing 1 CPUs, 0
hotplug CPUs
2025-06-20 16:59:44 localhost shepherd[1]: Service kernel-variables-setup has
been started.
2025-06-20 16:59:44 localhost linux: [ 0.038787] PM: hibernation: Registered
nosave memory: [mem 0x00000000-0x00000fff]
2025-06-20 16:59:44 localhost shepherd[1]: Service kernel-variables-setup
started.
2025-06-20 16:59:44 localhost shepherd[1]: Service kernel-variables-setup
running with value #t.
2025-06-20 16:59:44 localhost shepherd[1]: Starting service
random-generator-setup...
2025-06-20 16:59:44 localhost linux: [ 0.038788] PM: hibernation: Registered
nosave memory: [mem 0x0009f000-0x0009ffff]
2025-06-20 16:59:44 localhost linux: [ 0.038789] PM: hibernation: Registered
nosave memory: [mem 0x000a0000-0x000effff]
2025-06-20 16:59:44 localhost linux: [ 0.038790] PM: hibernation: Registered
nosave memory: [mem 0x000f0000-0x000fffff]
2025-06-20 16:59:44 localhost linux: [ 0.038791] [mem 0x5dc00000-0xfeffbfff]
available for PCI devices
2025-06-20 16:59:44 localhost linux: [ 0.038793] Booting paravirtualized
kernel on KVM
2025-06-20 16:59:44 localhost linux: [ 0.038795] clocksource:
refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns:
7645519600211568 ns
...
2025-06-20 16:59:44 localhost linux: [ 0.236295] cblist_init_generic:
Setting adjustable number of callback queues.
2025-06-20 16:59:44 localhost linux: [ 0.236295] cblist_init_generic:
Setting shift to 0 and lim to 1.
2025-06-20 16:59:44 localhost linux: [ 0.236307] Performance Events: AMD PMU
driver.
2025-06-20 16:59:44 localhost linux: [ 0.236319] ... version: 0
2025-06-20 16:59:44 localhost linux: [ 0.236320] ... bit width:
48
2025-06-20 16:59:44 localhost shepherd[1]: Registering new logger for
random-generator-setup.
2025-06-20 16:59:44 localhost linux: [ 0.236321] ... generic registers:
4
2025-06-20 16:59:44 localhost linux: [ 0.236321] ... value mask:
0000ffffffffffff
...
2025-06-20 16:59:44 localhost linux: [ 0.268918] pci 0000:00:01.1: legacy
IDE quirk: reg 0x18: [io 0x0170-0x0177]
2025-06-20 16:59:44 localhost linux: [ 0.268919] pci 0000:00:01.1: legacy
IDE quirk: reg 0x1c: [io 0x0376]
2025-06-20 16:59:44 localhost linux: [ 0.269065] pci 0000:00:01.3:
[8086:7113] type 00 class 0x068000
2025-06-20 16:59:44 localhost linux: [ 0.269392] pci 0000:00:01.3: quirk:
[io 0x0600-0x063f] claimed by PIIX4 ACPI
2025-06-20 16:59:44 localhost shepherd[1]: Service random-generator-setup has
been started.
2025-06-20 16:59:44 localhost shepherd[1]: Service random-generator-setup
started.
2025-06-20 16:59:44 localhost shepherd[1]: Service random-generator-setup
running with value #t.
2025-06-20 16:59:44 localhost linux: [ 0.269400] pci 0000:00:01.3: quirk:
[io 0x0700-0x070f] claimed by PIIX4 SMB
2025-06-20 16:59:44 localhost linux: [ 0.269557] pci 0000:00:02.0:
[1b36:0100] type 00 class 0x030000
2025-06-20 16:59:44 localhost shepherd[1]: Starting service networking...
2025-06-20 16:59:44 localhost linux: [ 0.274591] pci 0000:00:02.0: reg 0x10:
[mem 0xf4000000-0xf7ffffff]
2025-06-20 16:59:44 localhost linux: [ 0.275865] pci 0000:00:02.0: reg 0x14:
[mem 0xf8000000-0xfbffffff]
2025-06-20 16:59:44 localhost linux: [ 0.276995] pci 0000:00:02.0: reg 0x18:
[mem 0xfc070000-0xfc071fff]
...
2025-06-20 16:59:44 localhost linux: [ 1.365623] e1000 0000:00:03.0 eth0:
Intel(R) PRO/1000 Network Connection
2025-06-20 16:59:44 localhost linux: [ 1.370623] e1000 0000:00:03.0 ens3:
renamed from eth0
2025-06-20 16:59:44 localhost linux: [ 1.732827] EXT4-fs (sda1): mounted
filesystem with ordered data mode. Quota mode: none.
2025-06-20 16:59:44 localhost linux: [ 2.722732] random: crng init done
... Here it becomes chronological
2025-06-20 16:59:44 localhost [ 3.030500] shepherd[1]: GNU Shepherd 1.0.3
(Guile 3.0.10, x86_64-pc-linux-gnu)
2025-06-20 16:59:44 localhost [ 3.030562] shepherd[1]: Starting service
root...
2025-06-20 16:59:44 localhost [ 3.030809] shepherd[1]: Service root started.
2025-06-20 16:59:44 localhost [ 3.030863] shepherd[1]: Service root running
with value #<<process> id: 1 command: #f>.
2025-06-20 16:59:44 localhost [ 3.031057] shepherd[1]: Service root has been
started.
2025-06-20 16:59:44 localhost [ 3.034142] shepherd[1]: Starting service
hostname-setup...
2025-06-20 16:59:44 localhost [ 3.034197] shepherd[1]: Service
hostname-setup started.
2025-06-20 16:59:44 localhost [ 3.034461] shepherd[1]: Service
hostname-setup running with value #t.
2025-06-20 16:59:44 localhost [ 3.034518] shepherd[1]: Service
hostname-setup has been started.
2025-06-20 16:59:44 localhost [ 3.035999] shepherd[1]: Starting service
mount-in-memory-fs...
2025-06-20 16:59:44 localhost [ 3.036057] shepherd[1]: Service
mount-in-memory-fs started.
2025-06-20 16:59:44 localhost [ 3.036388] shepherd[1]: Service
mount-in-memory-fs running with value #t.
2025-06-20 16:59:44 localhost [ 3.036447] shepherd[1]: Service
mount-in-memory-fs has been started.
2025-06-20 16:59:44 localhost [ 3.054568] shepherd[1]: Starting service
udev...
2025-06-20 16:59:44 localhost [ 3.093498] shepherd[1]: Registering new
logger for udev.
2025-06-20 16:59:44 localhost [ 3.116002] shepherd[1]: Registering new
logger for udev.
2025-06-20 16:59:44 localhost [ 3.187339] shepherd[1]: Registering new
logger for udev.
2025-06-20 16:59:44 localhost linux: [ 3.215368] input: Power Button as
/devices/LNXSYSTM:00/LNXPWRBN:00/input/input4
2025-06-20 16:59:44 localhost linux: [ 3.232540] ACPI: button: Power Button
[PWRF]
2025-06-20 16:59:44 localhost linux: [ 3.246655] sd 0:0:0:0: Attached scsi
generic sg0 type 0
2025-06-20 16:59:44 localhost linux: [ 3.247738] sr 1:0:0:0: Attached scsi
generic sg1 type 5
2025-06-20 16:59:44 localhost linux: [ 3.251667] input: PC Speaker as
/devices/platform/pcspkr/input/input5
2025-06-20 16:59:44 localhost linux: [ 3.281398] parport_pc 00:03: reported
by Plug and Play ACPI
2025-06-20 16:59:44 localhost linux: [ 3.281518] parport0: PC-style at
0x378, irq 7 [PCSPP,TRISTATE]
2025-06-20 16:59:44 localhost linux: [ 3.301153] powernow_k8: Power state
transitions not supported
2025-06-20 16:59:44 localhost linux: [ 3.378137] ACPI: bus type
drm_connector registered
2025-06-20 16:59:44 localhost linux: [ 3.404776] ppdev: user-space parallel
port driver
2025-06-20 16:59:44 localhost linux: [ 3.486541] ACPI: \_SB_.LNKB: Enabled
at IRQ 10
2025-06-20 16:59:44 localhost linux: [ 3.492591] qxl 0000:00:02.0: vgaarb:
deactivate vga console
2025-06-20 16:59:44 localhost linux: [ 3.494655] Console: switching to
colour dummy device 80x25
2025-06-20 16:59:44 localhost linux: [ 3.495068] [drm] Device Version 0.0
2025-06-20 16:59:44 localhost linux: [ 3.495070] [drm] Compression level 0
log level 0
2025-06-20 16:59:44 localhost linux: [ 3.495072] [drm] 12286 io pages at
offset 0x1000000
2025-06-20 16:59:44 localhost linux: [ 3.495073] [drm] 16777216 byte draw
area at offset 0x0
2025-06-20 16:59:44 localhost linux: [ 3.495074] [drm] RAM header offset:
0x3ffe000
2025-06-20 16:59:44 localhost linux: [ 3.495091] [drm] qxl: 16M of VRAM
memory size
2025-06-20 16:59:44 localhost linux: [ 3.495092] [drm] qxl: 63M of IO pages
memory ready (VRAM domain)
2025-06-20 16:59:44 localhost linux: [ 3.495092] [drm] qxl: 64M of Surface
memory size
2025-06-20 16:59:44 localhost linux: [ 3.498461] [drm] slot 0 (main): base
0xf4000000, size 0x03ffe000
2025-06-20 16:59:44 localhost linux: [ 3.498698] [drm] slot 1 (surfaces):
base 0xf8000000, size 0x04000000
2025-06-20 16:59:44 localhost linux: [ 3.500535] [drm] Initialized qxl 0.1.0
20120117 for 0000:00:02.0 on minor 0
2025-06-20 16:59:44 localhost linux: [ 3.502612] fbcon: qxldrmfb (fb0) is
primary device
2025-06-20 16:59:44 localhost linux: [ 3.514985] Console: switching to
colour frame buffer device 128x48
2025-06-20 16:59:44 localhost linux: [ 3.534724] qxl 0000:00:02.0: [drm]
fb0: qxldrmfb frame buffer device
2025-06-20 16:59:44 localhost [ 3.643887] shepherd[1]: Service udev has been
started.
2025-06-20 16:59:44 localhost [ 3.643958] shepherd[1]: Service udev started.
2025-06-20 16:59:44 localhost [ 3.646046] shepherd[1]: Service udev running
with value #t.
2025-06-20 16:59:44 localhost [ 3.646148] shepherd[1]: Starting service
keyboard-setup...
2025-06-20 16:59:44 localhost [ 3.750186] shepherd[1]: Service
keyboard-setup has been started.
2025-06-20 16:59:44 localhost [ 3.750248] shepherd[1]: Service
keyboard-setup started.
2025-06-20 16:59:44 localhost [ 3.751417] shepherd[1]: Service
keyboard-setup running with value #t.
2025-06-20 16:59:44 localhost [ 3.751506] shepherd[1]: Starting service
mount-in-memory-fs-step2...
2025-06-20 16:59:44 localhost [ 3.751807] shepherd[1]: Service
mount-in-memory-fs-step2 started.
2025-06-20 16:59:44 localhost [ 3.751878] shepherd[1]: Service
mount-in-memory-fs-step2 running with value #t.
2025-06-20 16:59:44 localhost [ 3.753542] shepherd[1]: Service
mount-in-memory-fs-step2 has been started.
2025-06-20 16:59:44 localhost [ 3.753654] shepherd[1]: Starting service
clock-setup...
2025-06-20 16:59:44 localhost linux: [ 3.791255] e1000: ens3 NIC Link is Up
1000 Mbps Full Duplex, Flow Control: RX
2025-06-20 16:59:44 localhost linux: [ 3.791588] IPv6:
ADDRCONF(NETDEV_CHANGE): ens3: link becomes ready
2025-06-20 16:59:44 localhost [ 4.469090] shepherd[1]: Service clock-setup
has been started.
2025-06-20 16:59:44 localhost [ 4.469215] shepherd[1]: Service clock-setup
started.
2025-06-20 16:59:44 localhost [ 4.470516] shepherd[1]: Service clock-setup
running with value #t.
2025-06-20 16:59:44 localhost [ 4.470640] shepherd[1]: Starting service
lvm2...
2025-06-20 16:59:44 localhost [ 4.471648] shepherd[1]: Service lvm2 started.
2025-06-20 16:59:44 localhost [ 4.471947] shepherd[1]: Service lvm2 running
with value #t.
2025-06-20 16:59:44 localhost [ 4.474070] shepherd[1]: Service lvm2 has been
started.
2025-06-20 16:59:44 localhost [ 4.474255] shepherd[1]: Starting service
checkroot...
2025-06-20 16:59:44 localhost [ 4.493280] shepherd[1]: Registering new
logger for checkroot.
2025-06-20 16:59:44 localhost [ 4.499054] shepherd[1]: [sh] fsck from
util-linux 2.41
2025-06-20 16:59:44 localhost [ 4.512264] shepherd[1]: [sh] /dev/sda1:
clean, 98380/327680 files, 1045202/1310464 blocks
2025-06-20 16:59:44 localhost [ 4.524805] shepherd[1]: Registering new
logger for checkroot.
2025-06-20 16:59:44 localhost linux: [ 4.535819] EXT4-fs (sda1): re-mounted.
Quota mode: none.
2025-06-20 16:59:44 localhost [ 4.538460] shepherd[1]: Service checkroot has
been started.
2025-06-20 16:59:44 localhost [ 4.538603] shepherd[1]: Service checkroot
started.
2025-06-20 16:59:44 localhost [ 4.540942] shepherd[1]: Service checkroot
running with value #t.
2025-06-20 16:59:44 localhost [ 4.541119] shepherd[1]: Starting service
checkfs...
2025-06-20 16:59:44 localhost [ 4.545450] shepherd[1]: [fsck] fsck from
util-linux 2.41
2025-06-20 16:59:44 localhost [ 4.546057] shepherd[1]: [fsck] Checking all
file systems.
2025-06-20 16:59:44 localhost [ 4.548674] shepherd[1]: Service checkfs has
been started.
2025-06-20 16:59:44 localhost [ 4.548840] shepherd[1]: Service checkfs
started.
2025-06-20 16:59:44 localhost [ 4.556793] shepherd[1]: Service checkfs
running with value #t.
2025-06-20 16:59:44 localhost [ 4.556939] shepherd[1]: Starting service
checkroot-bootclean...
2025-06-20 16:59:44 localhost [ 4.557313] shepherd[1]: Service
checkroot-bootclean started.
2025-06-20 16:59:44 localhost [ 4.557382] shepherd[1]: Service
checkroot-bootclean running with value #t.
2025-06-20 16:59:44 localhost [ 4.565002] shepherd[1]: Service
checkroot-bootclean has been started.
2025-06-20 16:59:44 localhost [ 4.565070] shepherd[1]: Starting service
load-kernel-modules...
2025-06-20 16:59:44 localhost [ 4.565415] shepherd[1]: Service
load-kernel-modules started.
2025-06-20 16:59:44 localhost [ 4.565484] shepherd[1]: Service
load-kernel-modules running with value #t.
2025-06-20 16:59:44 localhost [ 4.567805] shepherd[1]: Service
load-kernel-modules has been started.
2025-06-20 16:59:44 localhost [ 4.567882] shepherd[1]: Starting service
mountall...
2025-06-20 16:59:44 localhost [ 4.571050] shepherd[1]: Service mountall has
been started.
2025-06-20 16:59:44 localhost [ 4.571110] shepherd[1]: Service mountall
started.
... Remember that we had message "Service mountall running with value
#t." followed by messages about services mountall-bootclean,
kernel-variables-setup,
random-generator-setup, networking at he top of the file.
The dependencies order is: load-kernel-modules, mountall (to mount /var),
rsyslogd (shepherd syslog),
mountall-bootclean, kernel-variables-setup, random-generator-setup,
networking
Below, the formatting changes as shepherd syslog has kicked in
2025-06-20 16:59:44 localhost shepherd[1]: Registering new logger for
networking.
2025-06-20 16:59:44 localhost shepherd[1]: Service networking has been started.
2025-06-20 16:59:44 localhost shepherd[1]: Service networking started.
2025-06-20 16:59:44 localhost shepherd[1]: Service networking running with
value #t.
2025-06-20 16:59:44 localhost shepherd[1]: Starting service console-setup...
2025-06-20 16:59:44 localhost shepherd[1]: Service console-setup has been
started.
2025-06-20 16:59:44 localhost shepherd[1]: Service console-setup started.
2025-06-20 16:59:44 localhost shepherd[1]: Service console-setup running with
value #t.
2025-06-20 16:59:44 localhost shepherd[1]: Starting service login-helper...
2025-06-20 16:59:44 localhost shepherd[1]: Service login-helper started.
2025-06-20 16:59:44 localhost shepherd[1]: Service login-helper running with
value #t.
2025-06-20 16:59:44 localhost shepherd[1]: Service login-helper has been
started.
2025-06-20 16:59:44 localhost shepherd[1]: Starting service X11-common...
2025-06-20 16:59:44 localhost shepherd[1]: Service X11-common started.
...
===============================================
This can be misleading as to what happens in the system. Is there a way to
avoid that behaviour?
Sincerely.
--
Bernard
