journal filling up with Condition check messages

[bjoe2k4]

systemd version the issue has been seen with

systemd 245.2-2

Used distribution

Archlinux x86_64

Expected behaviour you didn't see

journal staying resonably quiet, just like in systemd 244 and earlier.

Mär 21 23:19:23 archlinux systemd[1]: Started Test.
Mär 21 23:19:23 archlinux echo[415]: Test
Mär 21 23:19:23 archlinux systemd[1]: test.service: Succeeded.

Unexpected behaviour you saw
For every start of a service, all the the conditions of services which are part of sysinit.target and are not checked green on systemctl list-dependencies sysinit.target are logged over and over again, increasing the journal size manyfold. Strangely, this seems to happen not every time.

Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in First Boot Wizard being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in Store a System Token in an EFI Variable being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Mär 21 23:19:23 archlinux systemd[1]: Started Test.
Mär 21 23:19:23 archlinux echo[415]: Test
Mär 21 23:19:23 archlinux systemd[1]: test.service: Succeeded.
Mär 21 23:23:16 archlinux systemd[1]: Started Test.
Mär 21 23:23:16 archlinux systemd[1]: test.service: Succeeded.
Mär 21 23:23:16 archlinux echo[427]: Test
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in First Boot Wizard being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in Store a System Token in an EFI Variable being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Mär 21 23:23:23 archlinux systemd[1]: Started Test.
Mär 21 23:23:23 archlinux echo[433]: Test
Mär 21 23:23:23 archlinux systemd[1]: test.service: Succeeded.
Mär 21 23:23:38 archlinux systemd[1]: Started Test.
Mär 21 23:23:38 archlinux echo[438]: Test
Mär 21 23:23:38 archlinux systemd[1]: test.service: Succeeded.

Steps to reproduce the problem
Install a minimal Archlinux (i.e. using pacstrap /mnt base linux) and create a simple service.

[Unit]
Description=Test Service

[Service]
ExecStart=/usr/bin/echo "Test"

Start it couple of times.

Related Issue on Archlinux Forums: https://bbs.archlinux.org/viewtopic.php?pid=1893101#p1893101

[mbiebl]

Might be related to #15091

[geissonator]

Noticed this over in OpenBMC as well. We upgraded to systemd 245 (245.5+) and now have things like this filling up our journal when we boot a system:

Feb 17 14:10:51 localhost systemd[1]: Finished Remount the squashfs and ubi volumes after a reboot.
Feb 17 14:10:51 localhost systemd[1]: Starting OpenPower Software Update Manager...
Feb 17 14:10:51 localhost systemd[1]: Started OpenPower Software Update Manager.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in Huge Pages File System being skipped.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in POSIX Message Queue File System being skipped.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in Create list of static device nodes for the current kernel being skipped.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in FUSE Control File System being skipped.
Feb 17 14:10:51 localhost systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Create System Users being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Bind mount volatile /var/cache being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Bind mount volatile /var/lib being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Bind mount volatile /var/spool being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Rebuild Journal Catalog being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Feb 17 14:10:52 localhost systemd[1]: Condition check resulted in Update is Completed being skipped.
Feb 17 14:10:52 localhost systemd[1]: Starting Create a ubi volume for pnor patches...
Feb 17 14:10:52 localhost systemd[1]: Starting Set U-Boot environment variable...
Feb 17 14:10:52 localhost systemd[1]: Starting Updates symlinks for active PNOR version...
Feb 17 14:10:52 localhost systemd[1]: Starting Phosphor Version Software Manager...
Feb 17 14:10:53 localhost systemd[1]: obmc-vpnor-updatesymlinks.service: Succeeded.
Feb 17 14:10:53 localhost systemd[1]: Finished Updates symlinks for active PNOR version.

[bjoe2k4]

@poettering What is the recommended procedure to get this flaw fixed? Unless both me and @geissonator are doing something wrong of course.

The pull causing this seems to be #14086, which has been reverted by both debian and fedora. Archlinux maintainers are reluctant to revert this as well since there is apparently radio silence concerning an upstream solution.

Does #14086 still look correct to you? Maybe it needs to be reverted here as well!

#15401 seems to describe the same issue.

[bjoe2k4]

Can someone please add this issue to the v246 milestone, just to make sure it doesn't get lost. Thanks :-)