Re: Service output missing from journal?

[Lennart Poettering <lennart@xxxxxxxxxxxxxx>]

eOn So, 03.07.22 19:29, Uwe Geuder (systemd-devel-ugeuder@xxxxxxxxxxx) wrote:

> Hi!
>
> When I run the command given below on a current Fedora CoreOS system
> (systemd 250 (v250.6-1.fc36)) I get a result I absolute cannot understand.
> Can anybody help me with what is wrong there?
>
> $ systemd-run --user sh -c 'while true; do echo foo; df -h /var/log/journal/; echo $?; sleep 3; done'
> Running as unit: run-r9a155474889b4d40a1ac119823bdc2bf.service
> $ journalctl --user -f -u run-r9a155474889b4d40a1ac119823bdc2bf
> [ ... similar lines redacted ... ]
> Jul 03 15:25:08 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:11 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:11 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:14 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:14 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:17 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:17 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:20 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:20 ip-172-31-8-116 sh[366941]: Filesystem      Size  Used Avail Use% Mounted on
> Jul 03 15:25:20 ip-172-31-8-116 sh[366941]: /dev/nvme0n1p4  9.5G  8.1G  1.5G  86% /var
> Jul 03 15:25:20 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:23 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:23 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:26 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:26 ip-172-31-8-116 sh[366900]: 0
> Jul 03 15:25:29 ip-172-31-8-116 sh[366900]: foo
> Jul 03 15:25:29 ip-172-31-8-116 sh[366900]: 0
> [...]
>
> So the output from the df command appears in the journal pretty rarely,
> appearingly at random intervals. When I run the same loop on the
> command line the output occurs every time.
>
> The problem was originally noted in a somewhat loaded system. However,
> above reproducer (including the 2 echo commands and a shorter sleep)
> shows the same problem even on an idling machine.

https://github.com/systemd/systemd/issues/2913

Lennart

--
Lennart Poettering, Berlin