How do I properly redirect stdout/stderr from a systemd service on Raspbian?

Question

I set up a service on Raspbian (Jessie) using systemd to make it start after boot. The daemon config looks like this:

[Unit]
After=multi-user.target

[Service]
Type=idle
User=root
ExecStart=/bin/sh -c "exec /home/pi/sources/mydaemon.py >> /home/pi/mydaemon.log 2>&1"

[Install]
WantedBy=multi-user.target

That redirection >> isn't working. I have tried most of the options available to the StandardOutput and StandardError but they never end up printing my script's output to /var/log/daemon.log and journalctl -u mydaemon.service only shows messages about the service being started and stopped.

I'm not doing anything funny with file descriptors from within the script currently. I just want my print() or logging.info() statements to show up somewhere I can read them. Any ideas?

(Just to be clear, the daemon does have to run as root. Could that have something to do with my printing problem?)

Solution 1

Normally you just run a service directly (make sure it's executable has a shebang line):

 ExecStart=/home/pi/sources/mydaemon.py

And use the default redirection of StandardOutput= to the systemd journal, so you can read the logs with journalctl -u mydaemon.service.

Systemd nicely controls the file growth and file rotation of the log for you.

It is unrelated that your service runs as root.

If you don't see any log output with the above, also check the entire log for nearby logs that might be attributed to your service:

 journalctl

This is necessary because there's a known issue when some last lines of logging just before a script exists might not be attributed to the script. This would be especially noticeable for a script that just runs a fraction of a second before exiting.

Solution 2

I needed to run python with the -u parameter to ensure messages were not buffered.

With these lines, the print lines gets added to the journal immediately:

StandardOutput=journal+console
ExecStart=/home/pengman/scripts/mqtt_monitor/venv/bin/python -u home/pengman/scripts/mqtt_monitor/src/mqtt_monitor.py

(I am running inside a virtualenv, but that shouldn't matter)

Solution 3

Accepted answer from @mark-stosberg is on the money and correct. I wanted to expand his answer a bit and the comments are too short.

The systemd-journald.service man-page mentions this in the STREAM LOGGING section:

The systemd service manager invokes all service processes with standard output and standard error connected to the journal by default. This behaviour may be altered via the StandardOutput=/StandardError= unit file settings, see systemd.exec(5) for details.

So in @eric's original unit file, in order to get the output to /home/pi/mydaemon.log you could do this in the unit file

ExecStart=/usr/bin/python -u /home/pi/sources/mydaemon.py
StandardOutput=file:/home/pi/mydaemon.log
StandardError=inherit

Note the value of StandardError. This is from the systemd.exec(5) manpage, and it means to hook stderr to the same handle as stdout, much like 2>&1 in shell syntax.

Also, if you want the log to update immediately, you must tell Python not to buffer the output (with it's -u switch). That's why I changed the ExecStart= as well. When streaming python output (whether in systemd or from the shell) the output is buffered by default and the file won't be updated until the buffer flushes or the process ends.

---

UPDATE 20190411 - Raspbian's earlier version of systemd does not accept the file:/ target for StandardOutput (thanks @nak for pointing this out), so my answer doesn't really work for the OP question as regards Raspbian (I tested in openSUSE Tumbleweed). This SO question "How to redirect output of systemd service to a file" has details for alternative ways to do it with older systemd.

Comments

[Eric]

This seems to be working only part of the time. I don't know what's wrong with systemd or journalctl on Raspbian Jessie, but I suspect there's an issue interfering with logging. My script tweets, so I know when it gets activated, but the print statements in the script don't usually show up in the journal.

[Eric]

In conjunction with your answer, I'm going to try this method from within my script to see if I have better luck (explicitly sending messages to the journal) stackoverflow.com/questions/34588421/…

[Dominik Fretz]

That was it for me

[harperville]

Are you still using StandardOutput= in the systemd service file or are you using the Python systemd.journal module inside your script?

[Pengman]

harperville, I have StandardOutput set in the service file. I have updated the answer to include that information.

[nak]

This fails for me on Raspbian Stretch released 2018-11-13 with the follow error: "Failed to parse output specifier, ignoring: file:"

[mike]

I don't have a recent Raspbian Stretch to play with. The file:/path was added in Systemd 236 you might want to check which version is in Stretch. Jessie was 215.