journal-brief crashes on a particular entry (short.py:67:format:KeyError: 'MESSAGE')

[PorcelainMouse]

I've noticed that, sometimes, journal-brief crashes while processing journal entries. I originally thought something had changed in journal-brief since I built my configuration file, and that the format of the config file had changed, causing an error. But, after some research, I'm pretty sure it's not that, and is actually a message that is causing the error. First, here is the error:

short.py:67:format:KeyError: 'MESSAGE'

Traceback (most recent call last):
  File "/usr/bin/journal-brief", line 33, in <module>
    sys.exit(load_entry_point('journal-brief==1.1.8', 'console_scripts', 'journal-brief')())
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/journal_brief/cli/main.py", line 320, in run
    CLI().run()
  File "/usr/lib/python3.11/site-packages/journal_brief/cli/main.py", line 308, in run
    jfilter.format(sys.stdout)
  File "/usr/lib/python3.11/site-packages/journal_brief/filter.py", line 295, in format
    stream.write(formatter.format(entry) or '')
                 ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.11/site-packages/journal_brief/format/short.py", line 67, in format
    return self.FORMAT.format(**entry)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
KeyError: 'MESSAGE'

Local variables in innermost frame:
self: <journal_brief.format.short.ShortEntryFormatter object at 0x7f6f344a8b90>
entry: {'SYSLOG_FACILITY': 4, '_UID': 0, '_BOOT_ID': UUID('<hidden>'), '_MACHINE_ID': UUID('<hidden>'), '_HOSTNAME': '<hidden>', '_GID': 0, '_SYSTEMD_SLICE': 'system.slice', 'PRIORITY': 3, 'TID': '3365', 'SYSLOG_IDENTIFIER': 'systemd-logind[3365]', '_TRANSPORT': 'journal', '_PID': 3365, '_COMM': 'systemd-logind', '_EXE': '/usr/lib/systemd/systemd-logind', '_CMDLINE': '/usr/lib/systemd/systemd-logind', '_CAP_EFFECTIVE': '24420020f', '__REALTIME_TIMESTAMP': '<hidden>', '__MONOTONIC_TIMESTAMP': journal.Monotonic(timestamp=datetime.timedelta(seconds=24396, microseconds=660266), bootid=UUID('<hidden>')), '__CURSOR': 's<hidden>'}

I had trouble finding the message, though. No such message exists at the REALTIME_TIMESTAMP and the cursor doesn't show any journal entries from systemd-logind. In fact, the system was not running at that timestamp. However, one second prior to the given timestamp, the system initiated a shutdown, and systemd-logind reports these messages:

<hidden> <hidden> systemd-logind[3365]: Power key pressed short.
<hidden> <hidden> systemd-logind[3365]: Powering Off...

So, I wonder if there is a problem processing '...' in messages? Either that, or it's just corrupt data in the journal and that's all there is to it.

[kpfleming]

There is no MESSAGE key in the entry dictionary, and journal-brief assumes it will always be present. Somehow systemd-logind managed to create a journald entry with no textual content.

It should be straightforward to teach journal-brief how to handle these, there would just need to be a decision made about how they should be emitted.

[PorcelainMouse]

Ah, okay, that makes sense.