smhk

Reading from and writing to journald in Python

These notes cover how to do the following with journald in Python:

  • Writing to journald
    • Writing custom fields
  • Reading from journald
    • Reading all recent entries
    • Reading custom fields
    • Filtering by the executable
    • Filtering by the systemd service (or “unit”)

I’m using Ubuntu 22.04 running inside a Virtual Machine.

Overview §

To demonstrate this, we’ll create a new Python package imaginatively named py_sysd_pkg (Python systemd package). Inside that we’ll add some functions for reading/writing journald entries, and hook them up to entry points using Poetry.

Create a Poetry Python package for testing §

Create the Python package using Poetry:

poetry new py_sysd_pkg

Add a write command §

Inside the Python package, create a basic write() function, which sends "Hello, world!" to journald:

py_sysd_pkg/main.py
from systemd import journal

def write():
    journal.send("Hello, world!")

Update pyproject.toml to add an entry point, so that we can do poetry run test-write to launch our write() command:

pyproject.toml
[tool.poetry.scripts]
test-write = "py_sysd_pkg.main:write"

Test the write command using journalctl §

Run the command:

poetry run test-write

Run journalctl, then press <shift>+g to jump to the bottom of the the log (and see the most recent entries):

Nov 29 11:12:26 squirrel-virtual-machine python[12609]: Hello, world!

Write custom fields §

Next we’ll update our write() command to write to some custom fields. As quoted from the journald man page (emphasis added):

[…] Primarily, field values are formatted UTF-8 text strings — binary encoding is used only where formatting as UTF-8 text strings makes little sense. New fields may freely be defined by applications, but a few fields have special meanings, which are listed below. […]

So we can define custom fields in our log entries, but some fields have special meanings, and so we should avoid those.

The journald.send() command lets our application define custom fields just by using uppercase keyword arguments. So to add the following custom fields:

  • FIELD2 (UTF-8)
  • FIELD3 (UTF-8)
  • BINARY (binary)

We can do:

py_sysd_pkg/main.py
from systemd import journal

def write():
    journal.send("Hello world")
    journal.send("Hello, again, world", FIELD2="Greetings!", FIELD3="Guten tag")
    journal.send("Binary message", BINARY=b"\xde\xad\xbe\xef")

Note the we use the b prefix to pass in bytes to the BINARY field, rather than a str. Later we’ll see the BINARY field comes back out again as bytes.

Then run poetry run test-write to execute the write() command, and run journalctl again to check the output:

Nov 29 11:15:43 squirrel-virtual-machine python[13325]: Hello world
Nov 29 11:15:43 squirrel-virtual-machine python[13325]: Hello, again, world
Nov 29 11:15:43 squirrel-virtual-machine python[13325]: Binary message

We can see the new log entries have been added, but our custom fields are not displayed. They have been logged (as we will see later), but are not shown in the default journalctl output.

Add a read command §

Now we’ll add some read commands. First, extend the Python code to add a basic read() command, which reads all the most recent journald entries:

py_sysd_pkg/main.py
from systemd import journal
from datetime import datetime, timedelta

def write():
    journal.send("Hello world")
    journal.send("Hello, again, world", FIELD2="Greetings!", FIELD3="Guten tag")
    journal.send("Binary message", BINARY=b"\xde\xad\xbe\xef")

def read():
    j = journal.Reader()
    j.seek_realtime(datetime.now() - timedelta(minutes=5))
    for entry in j:
        print(entry["MESSAGE"])

Update pyproject.toml to add a new entry point:

pyproject.toml
[tool.poetry.scripts]
test-write = "py_sysd_pkg.main:write"
test-read = "py_sysd_pkg.main:read"

Run the command to see if it prints the most recent logs:

$ poetry run test-read
Hello world
Hello, again, world
Binary message
pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
(root) CMD (   cd / && run-parts --report /etc/cron.hourly)
pam_unix(cron:session): session closed for user root
Window manager warning: last_user_time (4116618) is greater than comparison timestamp (4116617).  This most likely represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Window manager warning: W18 appears to be one of the offending windows with a timestamp of 4116618.  Working around...
Window manager warning: last_user_time (4129937) is greater than comparison timestamp (4129936).  This most likely represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Window manager warning: W18 appears to be one of the offending windows with a timestamp of 4129937.  Working around...
Window manager warning: last_user_time (4135593) is greater than comparison timestamp (4135592).  This most likely represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Window manager warning: W11 appears to be one of the offending windows with a timestamp of 4135593.  Working around...

Yes, that works. It shows the logs from our previous command, plus some other logs entries from other services.

Read the custom fields §

Next, let’s extend the read() function to also print the custom fields FIELD2, FIELD3 and BINARY:

py_sysd_pkg/main.py
# ...

def read():
    j = journal.Reader()
    j.seek_realtime(datetime.now() - timedelta(minutes=10))
    for entry in j:
        print(entry["MESSAGE"])

        for field in ("FIELD2", "FIELD3", "BINARY"):
            if field in entry:
                print(f"{field} = {entry[field]}")

Let’s run the updated command and check if the custom fields are printed:

$ poetry run test-read
Hello world
Hello, again, world
FIELD2 = Greetings!
FIELD3 = Guten tag
Binary message
BINARY = b'\xde\xad\xbe\xef'
pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
(root) CMD (   cd / && run-parts --report /etc/cron.hourly)
pam_unix(cron:session): session closed for user root
Window manager warning: last_user_time (4116618) is greater than comparison timestamp (4116617).  This most likely represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Window manager warning: W18 appears to be one of the offending windows with a timestamp of 4116618.  Working around...
Window manager warning: last_user_time (4129937) is greater than comparison timestamp (4129936).  This most likely represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Window manager warning: W18 appears to be one of the offending windows with a timestamp of 4129937.  Working around...
Window manager warning: last_user_time (4135593) is greater than comparison timestamp (4135592).  This most likely represents a buggy client sending inaccurate timestamps in messages such as _NET_ACTIVE_WINDOW.  Trying to work around...
Window manager warning: W11 appears to be one of the offending windows with a timestamp of 4135593.  Working around...

Yup, we can see our custom fields are being printed. Note that the binary data is printed as bytes rather than a str.

Read and filter on the executable §

So far we’ve been reading all the journald entries. It will be more useful if we can filter to read only the entries we care about. One way is to filter by executable, e.g. find all logs generated by a specific instance of Python.

To filter by the executable, first we need to find the full path to the executable. To do so, view the log in JSON format (pretty-printed so that it is easier to read).

journalctl -o json-pretty

Then find the _EXC field for our log entry. This contains the full path to the executable, which we need for filtering:

{
        "_MACHINE_ID" : "33bc1116507e48e485dd1c2349f34250",
        "_UID" : "1000",
        "_SYSTEMD_USER_SLICE" : "app-org.gnome.Terminal.slice",
        "_GID" : "1000",
        "_SYSTEMD_INVOCATION_ID" : "8f444f3a-ddd6-4098-985a-f09d5ba836e1",
        "_BOOT_ID" : "37e336ad066846788762df9dd3434383",
        "_SYSTEMD_SLICE" : "user-1000.slice",
        "FIELD3" : "Guten tag",
        "_SELINUX_CONTEXT" : "unconfined\n",
        "SYSLOG_IDENTIFIER" : "python",
        "MESSAGE" : "Hello, again, world",
        "__REALTIME_TIMESTAMP" : "1701256543054758",
        "_TRANSPORT" : "journal",
        "CODE_FUNC" : "main",
        "_SOURCE_REALTIME_TIMESTAMP" : "1701256543054751",
        "CODE_LINE" : "5",
        "_PID" : "13325",
        "_SYSTEMD_USER_UNIT" : "vte-spawn-d1a8d554-f8ca-445e-9fdc-86d284a72df3.scope",
        "_HOSTNAME" : "squirrel-virtual-machine",
        "FIELD2" : "Greetings!",
        "_SYSTEMD_OWNER_UID" : "1000",
        "_CMDLINE" : "/home/squirrel/.cache/pypoetry/virtualenvs/use-systemd-0J3MkRb1-py3.10/bin/python -c \"import sys; from importlib import import_module; sys.argv = ['/home/squirrel/.cache/pypoetry/virtualenvs/use-systemd-0J3MkRb1-py3.10/bin/test-write']; sys.exit(import_module('py_sysd_pkg.main').main())\"",
        "__MONOTONIC_TIMESTAMP" : "3904063052",
        "_SYSTEMD_CGROUP" : "/user.slice/user-1000.slice/user@1000.service/app.slice/app-org.gnome.Terminal.slice/vte-spawn-d1a8d554-f8ca-445e-9fdc-86d284a72df3.scope",
        "_AUDIT_SESSION" : "2",
        "__CURSOR" : "s=57eb79e4c2ce4fc68f8ee7a9ba5059b1;i=c3d;b=37e336ad066846788762df9dd3434383;m=e8b3464c;t=60b48a7ebaba6;x=eaf2eb0bee48821d",
        "_CAP_EFFECTIVE" : "0",
        "_AUDIT_LOGINUID" : "1000",
        "_COMM" : "python",
        "_EXE" : "/home/squirrel/.pyenv/versions/3.10.12/bin/python3.10",
        "CODE_FILE" : "/home/squirrel/projects/py_sysd_pkg/py_sysd_pkg/main.py",
        "_SYSTEMD_UNIT" : "user@1000.service"
}

Copy the value of the _EXE field, and add a new read_only_python() command which filters upon that value:

py_sysd_pkg/main.py
# ...

def read_only_python():
    j = journal.Reader()
    j.add_match("_EXE=/home/squirrel/.pyenv/versions/3.10.12/bin/python3.10")
    for entry in j:
        print(entry["MESSAGE"])

Update pyproject.toml with a new entry point:

pyproject.toml
[tool.poetry.scripts]
test-write = "py_sysd_pkg.main:write"
test-read = "py_sysd_pkg.main:read"
test-read-only-python = "py_sysd_pkg.main:read_only_python"

Test the new command:

$ poetry run test-read-only-python
Hello, world!
Hello world
Hello, again, world
Binary message

Much better - it only prints out messages from our executable.

Create a systemd service using Poetry §

Assuming your Python code is being run as a systemd service, a more useful approach is to filter by systemd service (or “unit”).

If you don’t already have a Python systemd service, follow these steps to create a service called example-service. For the next section we’ll assume this service has been started, run for a few seconds and logged to journald, then stopped.

View the logs for a systemd service in Python §

Assuming our service is called example-service, add a read_only_service() function which filters by the systemd unit example-service.service. In our case, some of the journal entries from this service also use the custom field MY_COUNTER:

py_sysd_pkg/main.py
# ...

def read_only_service():
    j = journal.Reader()
    j.add_match("_SYSTEMD_UNIT=example-service.service")
    for entry in j:
        if "MY_COUNTER" in entry:
            print(f"MESSAGE={entry['MESSAGE']}, MY_COUNTER={entry['MY_COUNTER']}")
        else:
            print(f"MESSAGE={entry['MESSAGE']}")

Update pyproject.toml to add an entry point for the read_only_service() function with a test-read-only-service command:

pyproject.toml
[tool.poetry.scripts]
test-write = "py_sysd_pkg.main:write"
test-read = "py_sysd_pkg.main:read"
test-read-only-python = "py_sysd_pkg.main:read_only_python"
test-read-only-service = "py_sysd_pkg.main:read_only_service"

Run the command to test if we can read journald entries from that service:

$ poetry run test-read-only-service
MESSAGE=starting up
MESSAGE=example message, MY_COUNTER=1701262851.4286916
MESSAGE=example message, MY_COUNTER=1701262852.430438
MESSAGE=example message, MY_COUNTER=1701262853.4319665
# ...
MESSAGE=example message, MY_COUNTER=1701262886.4927928
MESSAGE=example message, MY_COUNTER=1701262887.4942982
MESSAGE=example message, MY_COUNTER=1701262888.495936

That worked! We’re printing out only the entries for the example-service.service systemd unit. Additionally, we’re printing the MY_COUNTER field if it exists.

Conclusion §

Lots more filtering is possible, and the code could be improved, but this provides a simple starting point for using journald from Python.