Score:0

How to ensure output from "tee" is shown when used in a script run under systemd

vn flag

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 echos (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?

Ginnungagap avatar
gu flag
Have you tried looking at what happens if you don't use `tee` and just let it go to the journal only? Do you get complete output then?
vn flag
@Ginnungagap yeah, if I remove the `tee` I do see all of the output. Adding this to the list of things I've tried in my post.
mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.