New-style daemons in Python

Systemd introduced a new way of writing daemons, service programs in Unix. Previously, writing a Unix service required an elaborate setup process to prevent the system from accidentally killing the process. With systemd, a service can now be written as if it was running in the foreground, just like any other program. systemd takes care of running the program as a service.

Writing services tremendously simplified

A simple service program in Python might look like this:

#!/usr/bin/env python3
import time


while True:
    time.sleep(60)

The corresponding systemd service file to start this service, /etc/systemd/system/pythonservice.service, would look like this:

[Unit]
Description=Python Service


[Service]
ExecStart=/usr/local/bin/sample-service.py

Logging is just writing to standard output

As systemd intercepts output by the service and treats each line as output, logging can be as simple as using the print function. But Python includes a standard logging framework, and as libraries use this, it’s best to use it as well. Luckily, configuring the logging library to write to standard output is trivial:

#!/usr/bin/env python3

import logging
import time

logging.basicConfig(level="INFO")

while True:
    logging.info("Hi")
    time.sleep(60)

After starting the service using systemctl start, log output will start to appear in the journal:

$ sudo journalctl -u pythonservice
Jan 28 12:49:11 forcix systemd[1]: Started Python Service.
Jan 28 12:49:11 forcix sample-service.py[4095]: INFO:root:Hi
Jan 28 12:50:11 forcix sample-service.py[4095]: INFO:root:Hi

Log levels are supported as well

While standard output is a simple stream of lines, systemd supports prefixing lines with angle brackets and a number to define the log level they use. If such a prefix is not used, all lines are by default in the INFO level (which can be configured in the service file).

The logging module allows us to write our own handler to prefix the output with the appropriate marker:

#!/usr/bin/env python3

import logging
import sys
import time

def main():
    root_logger = logging.getLogger()
    root_logger.setLevel("INFO")
    root_logger.addHandler(SystemdHandler())

    while True:
        logging.debug("Debug")
        logging.info("Info")
        logging.warning("Warning")
        time.sleep(60)

class SystemdHandler(logging.Handler):
    # https://0pointer.de/public/systemd-man/sd-daemon.html
    PREFIX = {
        # EMERG <0>
        # ALERT <1>
        logging.CRITICAL: "<2>",
        logging.ERROR: "<3>",
        logging.WARNING: "<4>",
        # NOTICE <5>
        logging.INFO: "<6>",
        logging.DEBUG: "<7>",
        logging.NOTSET: "<7>"
    }

    def __init__(self, stream=sys.stdout):
        self.stream = stream
        logging.Handler.__init__(self)

    def emit(self, record):
        try:
            msg = self.PREFIX[record.levelno] + self.format(record) + "\n"
            self.stream.write(msg)
            self.stream.flush()
        except Exception:
            self.handleError(record)

main()

The messages are now interpreted correctly using the right log level in the journal.

Backtraces pose a problem

The only remaining problem now are backtraces. As systemd treats each line as a single log entry, and Python logs backtraces as multiple lines, further processing of the log messages can cause backtraces to be mangled and parts of them to be lost.

Jan 28 13:37:52 forcix systemd[1]: Started Python Service.
Jan 28 13:37:53 forcix sample-service.py[5312]: It broke
Jan 28 13:37:53 forcix sample-service.py[5312]: Traceback (most recent call last):
Jan 28 13:37:53 forcix sample-service.py[5312]:   File "/usr/local/bin/sample-service.py", line 14, in main
Jan 28 13:37:53 forcix sample-service.py[5312]:     0/0
Jan 28 13:37:53 forcix sample-service.py[5312]: ZeroDivisionError: division by zero

The solution is to simply replace newlines in the message with some escape character. There is no standard for this, so we have to pick something. Using the standard \n sequence seems as good a pick as any:

    def emit(self, record):
        try:
            msg = self.PREFIX[record.levelno] + self.format(record)
            msg = msg.replace("\n", "\\n")
            self.stream.write(msg + "\n")
            self.stream.flush()
        except Exception:
            self.handleError(record)

The backtrace now appears in a single log message:

Jan 28 13:39:06 forcix systemd[1]: Started Python Service.
Jan 28 13:39:06 forcix sample-service.py[5339]: It broke\nTraceback (most recent call last):\n  File "/usr/local/bin/sample-service.py", line 14, in main\n    0/0\nZeroDivisionError: division by zero

A service in 50 lines

What we did in this article was to write a new-style daemon in Python, with full support of log levels and single-line backtraces, in under 50 lines. The largest complexity came from the need to encode log levels. If log levels or single-line backtraces aren’t of any concern, the service can be condensed to fewer than 12 lines.

Starting with this setup, it’s easy to use more features provided by systemd for new-style daemons, like automated restart on failure, the security settings, or even socket activation.

The Loggly and SolarWinds trademarks, service marks, and logos are the exclusive property of SolarWinds Worldwide, LLC or its affiliates. All other trademarks are the property of their respective owners.