xanmanning / alarm-fake-hwclock

Fake HWClock script for RPi Arch Linux Arm (replicates Raspbian's fake-hwclock)
Other
36 stars 11 forks source link

systemd service or timer cause multiple failed start of other systemd service #13

Open solsticedhiver opened 5 years ago

solsticedhiver commented 5 years ago

When I run and enable fake-hwclock.service, I am seeing in my log a lot of dependany cycle found by auditd an then failed start of many systemd service.

This leads to many criticial failure, the worse being systemd-journald not logging anything.

Here an execprt of what I am seeing in my logs (volatile log in /run because nothing is written to disk, ever)

[...]
févr. 11 07:29:57 ymir systemd[1]: /usr/lib/systemd/system/auditd.service:12: PIDFile= references path below legacy directory /var/run/, updating /va>
févr. 11 07:29:57 ymir systemd[1]: sysinit.target: Found ordering cycle on systemd-timesyncd.service/start
févr. 11 07:29:57 ymir systemd[1]: sysinit.target: Found dependency on systemd-tmpfiles-setup.service/start
févr. 11 07:29:57 ymir systemd[1]: sysinit.target: Found dependency on systemd-journal-flush.service/start
févr. 11 07:29:57 ymir systemd[1]: sysinit.target: Found dependency on systemd-journald.service/start
févr. 11 07:29:57 ymir systemd[1]: sysinit.target: Found dependency on fake-hwclock.service/start
févr. 11 07:29:57 ymir systemd[1]: sysinit.target: Found dependency on fake-hwclock.timer/start

févr. 11 07:29:57 ymir kernel: snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
févr. 11 07:29:57 ymir systemd-modules-load[205]: Inserted module 'snd_bcm2835'
févr. 11 07:29:57 ymir systemd[211]: systemd-udev-trigger.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir kernel: media: Linux media interface: v0.10
févr. 11 07:29:57 ymir kernel: Linux video capture interface: v2.00
févr. 11 07:29:57 ymir kernel: bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
févr. 11 07:29:57 ymir systemd[214]: lvm2-lvmetad.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd-fsck[206]: fsck terminated by signal PIPE.
févr. 11 07:29:57 ymir systemd[217]: systemd-remount-fs.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir kernel: EXT4-fs (sda2): re-mounted. Opts: (null)
févr. 11 07:29:57 ymir systemd[220]: systemd-random-seed.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd[221]: systemd-update-utmp.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd[222]: systemd-tmpfiles-setup-dev.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd[223]: systemd-udevd.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir kernel: bcm2835-rng 3f104000.rng: hwrng registered
févr. 11 07:29:57 ymir systemd-journald[377]: Missed 3 kernel messages
[...]
févr. 11 07:29:57 ymir systemd-journald[377]: Missed 1 kernel messages
févr. 11 07:29:57 ymir systemd[262]: systemd-rfkill.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd[263]: systemd-sysctl.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd-sysctl[263]: Couldn't write '2' to 'net/ipv6/conf/wlan0/use_tempaddr', ignoring: No such file or directory
févr. 11 07:29:57 ymir systemd[264]: sys-kernel-config.mount: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd-sysctl[263]: Couldn't write '2' to 'net/ipv6/conf/wlan1/use_tempaddr', ignoring: No such file or directory
févr. 11 07:29:57 ymir systemd-sysctl[263]: Couldn't write '2' to 'net/ipv6/conf/wlan2/use_tempaddr', ignoring: No such file or directory
févr. 11 07:29:57 ymir systemd-sysctl[263]: Couldn't write '2' to 'net/ipv6/conf/br0/use_tempaddr', ignoring: No such file or directory
févr. 11 07:29:57 ymir kernel: usb 1-1.2: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
févr. 11 07:29:57 ymir systemd[267]: boot.mount: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir kernel: FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
févr. 11 07:29:57 ymir systemd[266]: systemd-networkd.service: Failed to connect stdout to the journal socket, ignoring: Connection refused
févr. 11 07:29:57 ymir systemd[268]: systemd-fsck@dev-disk-by\x2duuid-7f84c0de\x2dxxxxx\x2xxxxxx\x2xxxxxx\x2xxxxxxxxxxxx.service: Failed to connect std>

and possibly others

my guess is that it IS NOT a good idea to include a .timer service inside the .serivce file at all.

On a rpi3 running archlinux-arm, with root on an external SSD via usb.

Fincer commented 3 years ago

@solsticedhiver

Yeah, 2 years after your initial report, this is still an issue and not fixed. The current systemd unit file implementation of alarm-fake-hwclock tend to break multiple critical systemd service initializations, causing unexpected loop cycles for them, causing chain of failure events for multiple critical systemd services.

For instance, in my case, because of fake-hwclock.service, one of failing services is systemd-tmpfiles-setup.service. Due to this failure many critical system daemons, such as MariaDB database server daemon, end up into failure state, too.

I understand the interest of starting fake-hwclock as early as possible but the current process is not clean, and the current systemd implementation can't be recommended for any critical Linux systems. To put it simple: fix systemd service files, and please, do proper stress tests for them.

I ended up replacing the systemd files as follows:

fake-hwclock.service

[Unit]
Description=Update hardware clock time
Documentation=man:fake-hwclock(8)

[Service]
Type=oneshot
ExecStart=/usr/bin/fake-hwclock
ExecStop=/usr/bin/fake-hwclock

fake-hwclock.timer

[Unit]
Description=Update hardware clock time

[Timer]
OnBootSec=0s
OnUnitActiveSec=1min

[Install]
WantedBy=timers.target

I have changed the timer to run in 1 minute intervals, since the process itself does not take CPU processing time at all.

Not sure, but one might want to take a look at time-set.target and time-sync.target, too.

The above changes as a patch:

--- a/systemd/fake-hwclock.service      2021-01-22 22:36:03.958161099 +0200
+++ b/systemd/fake-hwclock.service      2021-01-22 22:38:22.498863654 +0200
@@ -1,15 +1,8 @@
 [Unit]
-Description=Fake Hardware Clock
+Description=Update hardware clock time
 Documentation=man:fake-hwclock(8)
-DefaultDependencies=no
-Before=systemd-journald.service
-Conflicts=shutdown.target
-Wants=fake-hwclock.timer

 [Service]
-Type=simple
+Type=oneshot
 ExecStart=/usr/bin/fake-hwclock
 ExecStop=/usr/bin/fake-hwclock
-
-[Install]
-WantedBy=local-fs-pre.target
--- a/systemd/fake-hwclock.timer        2021-01-22 22:36:07.275806325 +0200
+++ b/systemd/fake-hwclock.timer        2021-01-22 22:37:49.834665426 +0200
@@ -1,6 +1,9 @@
 [Unit]
-Description=Update fake hardware clock time
-PartOf=fake-hwclock.service
+Description=Update hardware clock time

 [Timer]
-OnUnitActiveSec=15m
+OnBootSec=0s
+OnUnitActiveSec=1min
+
+[Install]
+WantedBy=timers.target

Feel free to create a PR.

Marietto2008 commented 3 years ago

I've just got the same problem :

Screenshot from 2021-04-09 16-50-25

Screenshot from 2021-04-09 16-50-36

this is the scenario :

qemu-system-aarch64 -M virt -m 3072 -smp 2 -cpu host,aarch64=off -enable-kvm \ -kernel /home/zi/Desktop/Work/I9/arm32/vmlinuz-4.19.0-14-armmp-lpae -initrd /home/zi/Desktop/Work/I9/arm32/initrd.img-4.19.0-14-armmp-lpae -append 'root=/dev/vda2' \ -device usb-ehci -device usb-kbd -device usb-mouse -usb -serial stdio \ -device virtio-gpu-pci,virgl=on,xres=1024,yres=768 -display sdl,gl=on \ -drive if=none,file=/home/zi/Desktop/Work/I9/arm32/hda.qcow2,format=qcow2,id=hd \ -device virtio-blk-device,drive=hd -netdev user,id=mynet \ -device virtio-net-device,netdev=mynet \ -bios edk2-arm-code.fd \

(buster upgraded to bullseye)

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# qemu-nbd -c /dev/nbd0 /home/ziomario/Scrivania/Dati/Data/Nano/I9/arm32/hda.qcow2

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# ls /media/ziomario/e2f8b41a-d163-426b-a484-26fdb336f871 bin dev home lost+found mnt proc run srv tmp var boot etc lib media opt root sbin sys usr

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# find /media/ziomario/e2f8b41a-d163-426b-a484-26fdb336f871 -name fake-hwclock.service

I haven't the file fake-hwclock.service inside the qcow2 debian bullseye system file.

Fincer commented 3 years ago

I finally ended up using a simple wrapper configuration:

> /usr/lib/systemd/system/fake-hwclock.service

[Unit]
Description=Update hardware clock time
Documentation=man:fake-hwclock(8)

[Service]
Type=simple
ExecStart=/usr/bin/fake-hwclock-looper 5

# Disable start/stop status messages
LogLevelMax=alert

[Install]
WantedBy=multi-user.target
> /usr/bin/fake-hwclock-looper

#!/bin/env sh

while true; do
  sleep ${1}
  /usr/bin/fake-hwclock
done

I purposefully avoid Systemd timer file here since journal would be filled with unnecessary service start/stop information.

Marietto2008 commented 3 years ago

how can I patch this error ?

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# qemu-nbd -c /dev/nbd0 /home/ziomario/Scrivania/Dati/Data/Nano/I9/arm32/hda.qcow2

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# ls /media/ziomario/e2f8b41a-d163-426b-a484-26fdb336f871 bin dev home lost+found mnt proc run srv tmp var boot etc lib media opt root sbin sys usr

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# find /media/ziomario/e2f8b41a-d163-426b-a484-26fdb336f871 -name fake-hwclock.service

root@Z390-AORUS-PRO:/home/ziomario/Scrivania/antmicro# find /media/ziomario/e2f8b41a-d163-426b-a484-26fdb336f871 -name fake-hw*

I haven't any fake-hw* file inside the qcow2 debian bullseye system file. should I create it from scratch ?

PS : I have created the same files that u have suggested,but the error is still there : @Fincer

pulkomandy commented 3 years ago

This should be fixed now with #14 .