Needle in a Haystack

Syslog, the default logging mechanism on Unix and Linux, dates from the early 1980s and was originally developed by Eric Allman – initially for Sendmail. Later, the tool established itself as a universal solution for logging system and error messages of all kinds. Among Linux distributions, Syslog was the generally accepted standard for many years. But while Syslog was marching to triumph, it revealed a number of weaknesses:

• The protocol does not provide authentication; anyone can generate spoofed log entries for any application.
• Syslogd transmits all messages in plain text, and anyone can read them.
• The timestamp does not contain any information about the time zone.
• As its transport protocol, Syslog uses the connectionless UDP, which does not guarantee that all messages arrive.
• Browsing the log files is a relatively complicated process, requiring tools that search for text patterns.
• The metadata that the Syslog protocol stores is incomplete.
• You can't log binary data.
• Syslog is only one of several logs on Linux, and the user must separately access UTMP/WTMP, Lastlog, audit, kernel logs, and firmware logs, as well as a variety of application-specific logs.
• Log rotation and compression are available but not flexible. Rotation only applies to fixed intervals but does not include disk utilization, and compression usually only works during rotation.

The Syslog protocol was first standardized in 2001 in RFC 3164. Developers soon created alternatives that corrected some of the weaknesses, including Syslog-ng and Rsyslog. Syslog-ng supports dozens of features that go beyond the old Syslog daemon's feature set; however, some of these features – including encryption, multi-line messages, and failover on the client side – only exist in a commercial premium edition.

Rsyslog is also far more powerful than its role model Syslog, supporting a variety of data sources and allowing message translation to other formats. However, a third alternative has stepped into the ring with Syslog and its children: Journald, the systemd logging component.

How the Journal Works

The creators of the systemd logging component had lofty goals. They wanted to fix the shortcomings of earlier tools, but they also wanted a simple and reliable solution that didn't need maintenance. Other objectives were portability, security, and performance. The developers wanted a design that delivered tight integration into the overall system and harmonized with existing logging systems.

The solution differed considerably from the previous Syslog daemon. Applications no longer hand over one formatted line for each entry to the logging system. Many entries are key-value pairs separated by line breaks. Entries can contain both well-known and application-specific pairs. The values are usually strings, but they can also contain binary data.

The logging service itself adds some metadata (e.g., timestamps, hostname, service name, PID, UID, and so on), which means this information can no longer be spoofed by a client.

Messages added by the system begin with an underscore (Listing 1). All fields that make up a log entry are stored as individual objects and referenced by all log messages that need them. Nothing is stored twice on disk, which saves so much space that the new system does not use significantly more disk space than the classic Syslog, even though it stores far more metadata.

Messages from non-privileged users are stored in individual journal files, which the user can read. However, log entries for system services are only accessible to root and the users of a group specifically assigned rights for the information. Context is not lost because the client transparently merges all messages that a specific user is permitted to read to create a large virtual log file. Recurring events, such as "User logged in" can be marked with a 128-bit message ID, thus allowing for quick filtering with similar events.

The Journal daemon automatically rotates log files when certain size limits are exceeded. Rotation ensures that the system does not exceed a predetermined disk utilization level. In addition, a single client is limited to a maximum number of log messages in a certain period. This maximum is correlated with the free disk space: If the disk is empty, the Journal daemon is generous, but if it is almost full, the daemon only allows a few messages per client.

An attacker who does successfully break into a system often tries to cover the tracks by manipulating the system logs. The plain-text format of the old Syslog daemon made this obfuscation very simple. But Journald maintains a cryptographic hash of all messages and a hash of the preceding entry, which creates a chain in which the last entry can easily authenticate all preceding entries. Log manipulation is thus easily recognized.

Wheat and Chaff

Along with systemd journal's numerous advantages for saving log messages are some additional improvements for admins who need to browse the entries. The key for searching in the logs is the journalctl command. If you call this command without any further parameters as the root user, you will see a list of all existing messages, starting with the oldest. This list looks quite similar, at first glance, to the old /var/log/messages file. On closer inspection, however, you can already see some initial improvements (Listing 2):

• Lines with a priority of Error or higher are highlighted in red.
• Lines with a priority of Notice/Warning are shown in bold type.
• Timestamps are converted to the local time zone.
• The output is automatically paged with less.
• All stored data is output, including data from rotated logfiles.

Because it is better to avoid working as the root user, systemd additionally grants access to all logs to members of the adm group.

Searching through all the log entries is not very efficient. The journal thus provides powerful tools for filtering the logs. The simplest filter is:

journalctl -b

This command shows all the entries since the last boot. In addition, admins can restrict the output to logs with a particular priority using the -p parameter:

journalctl -b -p err

If the computer is rarely booted, the -b parameter is not very helpful. In that case, it is better to explicitly specify the time period:

journalctl -since=yesterday

If a longer period is required, you can enter --since or --until along with a date, optionally including a time:

journalctl --since=2015-11-15 --until="2015-11-16 20:59:59"

You might need to do more than just search for messages within a certain time period. One typical example is searching for all messages for a particular service (or systemd service unit). You can combine these additional filters with the date or time:

journalctl -u mysqld --since 9:00 --until 10:00

Journalctl implicitly filters by _SYSTEMD_UNIT. But, what are the names of the other services, or systemd units, whose messages you might also want to filter out? To find out, type:

journalctl -F _SYSTEMD_UNIT

The -F parameter tells the command to list all the different values taken by the metadata parameter specified in the current log. If you want to see all the metadata ever recorded, instead of individual entries, use:

journalctl -o verbose -n

See Listing 3 for sample output.

The database containing the log entries is already automatically indexed with all the additional metadata fields (they all start with an underscore, as mentioned previously) and can be directly searched for their values. For example:

journalctl _UID=1000

or:

journalctl _EXE=/usr/bin/gnome-session

You can combine these search parameters. Journalctl logically ORs all the parameters. You could also exclusively OR the search parameters, which is equivalent to saying either/or. You can use the plus sign for an exclusive OR (Listing 4). This command discovers all the log entries that either originate from the user with the UID 1000 on the local host or the user with the UID 1100 on the host mercury.

Conclusions

Systemd journal goes far beyond the traditional Syslog, offering a centralized, space-saving, and safe logging mechanism that automatically enriches the logs with a wealth of useful metadata. At the same time, the systemd journal has advanced search options that make it easy to home in on interesting messages.

A simple authentication mechanism ensures intelligent log rotation. The journal can also handle binary data and convert the timestamp to a local value. These advanced features place the systemd journal in a strong position to compete with the old Syslog and other logging alternatives.