I have a script that I'm running under systemd
which has some debug logs that I'd like to send to both stdout (which should end up in the system journal, viewable with journalctl
) as well as to a log file on my filesystem.
Typically I'd reach for tee
to accomplish this (write to stdout and files), and it works fine when I run the script on its own (I see all my logs on my console as well as in my log file), but when I run it under systemd
I'm missing a bunch of the output from tee
in the system journal (although all logs are present in the log file).
I've tried a few things that haven't solved the problem:
stdbuf
(as suggested here for forcing line buffered output) in my ExecStart=
in my service file.
StandardOutput=journal+console
in my service file (DefaultStandardOutput
is unset in /etc/systemd/system.conf
, so it has the default value of journal
).
- Removed the
tee
, so the echo
just writes directly to stdout. When I do this I do see all of the logs in the system journal (but I lose my log file). I guess I could make my own tee
with a function that does two echo
s (once to the logfile, once to stdout), but that feels kind of hacky. I would prefer to use tee
, which already exists for this purpose...
I've reproduced this issue on the Manjaro and Ubuntu (systemd 249 (249.4-2-manjaro)
and systemd 245 (245.4-4ubuntu3.5)
), but I can't reproduce it on Debian 11 (systemd 247 (247.3-6)
). I don't see any glaring difference in any of my configs under /etc/systemd
between the working Debian system and the non-working Manjaro system. I'm not sure what other system configurations could be affecting this...
I have full repro instructions over here.
My script
Lives at /tmp/tee_test.sh
.
#!/bin/bash
LOGFILE=/tmp/testtee.log
echo > "$LOGFILE"
echo "i like pie" | tee -a "$LOGFILE"
i=2
while :; do
echo "i shall eat $i slices of pizza" | tee -a "$LOGFILE"
((i++))
sleep 1
done
My systemd unit
Lives at ~/.config/systemd/user/tee_test.service
and is loaded with systemctl --user daemon-reload
each time I change it.
[Unit]
Description=Test teeing under systemd
[Service]
# same result with either of the following two variants
ExecStart=/tmp/tee_test.sh
# ExecStart=stdbuf -i0 -o0 -e0 /tmp/tee_test.sh
# same result with or without this guy
StandardOutput=journal+console
[Install]
WantedBy=default.target
Logs in system journal
Viewing with journalctl --user -x -u tee_test.service
. I only see a subset of the logs.
Oct 20 09:49:03 grinchel systemd[2678]: Started Test teeing under systemd.
░░ Subject: A start job for unit UNIT has finished successfully
░░ Defined-By: systemd
░░ Support: https://forum.manjaro.org/c/support
░░
░░ A start job for unit UNIT has finished successfully.
░░
░░ The job identifier is 8193.
Oct 20 09:49:26 grinchel tee_test.sh[399363]: i shall eat 25 slices of pizza
Oct 20 09:49:40 grinchel tee_test.sh[400047]: i shall eat 39 slices of pizza
Oct 20 09:49:48 grinchel tee_test.sh[400430]: i shall eat 47 slices of pizza
Oct 20 09:49:49 grinchel tee_test.sh[400496]: i shall eat 48 slices of pizza
Oct 20 09:49:50 grinchel tee_test.sh[400529]: i shall eat 49 slices of pizza
Oct 20 09:49:51 grinchel tee_test.sh[400595]: i shall eat 50 slices of pizza
Oct 20 09:50:14 grinchel tee_test.sh[401790]: i shall eat 73 slices of pizza
Oct 20 09:50:27 grinchel systemd[2678]: Stopping Test teeing under systemd...
Logs in log file
In my log file I see all of the logs.
i like pie
i shall eat 2 slices of pizza
i shall eat 3 slices of pizza
i shall eat 4 slices of pizza
i shall eat 5 slices of pizza
i shall eat 6 slices of pizza
i shall eat 7 slices of pizza
[...many similar lines snipped -- they ARE all present in sequence as expected...]
i shall eat 84 slices of pizza
i shall eat 85 slices of pizza
i shall eat 86 slices of pizza
Any ideas what's going on here? How can I make sure that all of the output from tee
shows up in my system journal?