Managing Logging in Systemd

The initialization daemon systemd has become the de facto standard in modern Linux systems and is already used in many popular distributions: Debian, RHEL/CentOS, and Ubuntu (as of ver. 15.04). Compared to the traditional syslog, systemd offers an entirely different approach to logging.
At its base you’ll find centralization; the journal component collects all of the system messages (messages from the kernel and from various services and applications). In this case, there’s no need to configure log distribution, instead the applications can just write to stdout and stderr, and journal automatically saves these messages. This setup is possible with Upstart, but Upstart saves all logs to a separate file, whereas systemd saves them in a binary base, greatly simplifying systemization and searches.

By saving logs as binary files, you also avoid the difficulties that come from using parsers for different kinds of logs. If necessary, logs can easily be converted to other formats (we’ll talk about this further below).
Journal can work either independently or alongside syslog.

To review saved logs, we use the journalctl. In this article, we’ll discuss the more subtle points of this tool.

Setting the Correct Time

One of the biggest drawbacks to syslog is that records are saved without taking time zones into consideration. This has been resolved in journal: when events are logged, either local or coordinated universal time (UTC) can be used. The time is set using the timedatectl utility.

A list of possible time zones can be viewed using the command:

$ timedatectl list-timezones

Time zones are set by running the following command:

$ timedatectl set-timezone 

Once you’ve set the time zone, it’s a good idea to make sure that everything is working properly:

$ timedatectl status
Local time: Thu 2015-07-30 11:24:15 MSK
Universal time: Thu 2015-07-30 08:24:15 UTC
RTC time: Thu 2015-07-30 08:24:15
Time zone: Europe/Moscow (MSK, +0300)
NTP enabled: no
NTP synchronized: no
RTC in local TZ: no
DST active: n/a

The very first line should show the current date and time.

Journalctl: Viewing Logs

Logs are viewed using the journalctl utility.
If the command journalctl is entered without any arguments, then the console will display the following enormous list:

-- Logs begin at Wed 2015-07-29 17:12:48 MSK, end at Thu 2015-07-30 11:24:15 MSK. --
Jul 29 17:12:48 host-10-13-37-10 systemd-journal[181]: Runtime journal is using 4.0M (max allowed 20.0M, trying to leave 30.0M free of 195.9M available → current limit 20.0M).
Jul 29 17:12:48 host-10-13-37-10 systemd-journal[181]: Runtime journal is using 4.0M (max allowed 20.0M, trying to leave 30.0M free of 195.9M available → current limit 20.0M).
Jul 29 17:12:48 host-10-13-37-10 kernel: Initializing cgroup subsys cpuset
Jul 29 17:12:48 host-10-13-37-10 kernel: Initializing cgroup subsys cpu
Jul 29 17:12:48 host-10-13-37-10 kernel: Initializing cgroup subsys cpuacct
Jul 29 17:12:48 host-10-13-37-10 kernel: Linux version 3.16.0-4-amd64 (debian-kernel@lists.debian.org) (gcc version 4.8.4 (Debian 4.8.4-1) ) #1 SMP Debian 3.16.7-ckt11-1+deb8u2 (2015-07-17)
Jul 29 17:12:48 host-10-13-37-10 kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-3.16.0-4-amd64 root=UUID=b67ea972-1877-4c5b-a328-29fc0d6c7bc4 ro console=tty1 console=ttyS0 video=640x480 consoleblank=0 panic=15 c

This is only a small fragment; the records go on and on.

Filtering Logs

journalctl has options for filtering logs and to quickly extract necessary information from them.

Viewing Logs from the Latest Boot

With the -b option, all of the logs collected since the latest boot can be viewed:

$ journalctl -b

Viewing Logs from the Last Session

Information on previous sessions can be viewed with journalctl. It’s worth keeping in mind that all Linux distributions support saving information on previous sessions by default; sometimes the option just needs to be activated.

This can be done by opening the configuration file journald.conf, finding the [Journal] section, and changing the storage parameter value to persistent:

$ sudo nano /etc/systemd/journald.conf
...
[Journal]
Storage=persistent

A list of previous boots can be viewed with command:

$ journalctl --list-boots

0 9346310348bc4edea250555dc046b30c Thu 2015-07-30 12:39:49 MSK—Thu 2015-07-30 12:39:59 MSK

The printout consists of four columns. The first shows the boot serial number, the second its ID, the third the date, and then time. To view a log for a specific boot, you can use identifiers from either the first or second column.

$ journalctl -b 0

or

$ journalctl -b 9346310348bc4edea250555dc046b30c

Filtering by Date and Time

Journalctl can also view logs for a specific period of time. This is done with the since and until options. Let’s say we have to review logs starting from 17:15 on 20 July 2015. To do this, we’ll run the command:

$ journalctl --since "2015-07-20 17:15:00"

If no date is entered for since, the console will print logs starting from the current date. If a date is entered, but not the time, the default time 00:00:00 will be used. Seconds also do not need to be entered (in this case, the default value 00 is used).

The following intuitive formula can also be used:

$ journalctl ---since yesterday
$ journalctl --since 09:00 --until now
$ journalctl --since 10:00 --until "1 hour ago"

Filtering by Application and Service

To view logs for a specific application or service, we use the the -u option. For example:

$ journalctl -u nginx.service

The command will print out logs from the nginx web server.
We often have to view service logs for a specific period of time. This can be done using a command such as:

$ journalctl -u nginx.service --since yesterday

The -u option can also filter by date and time, for example:

$ journalctl -u nginx.service -u php-fpm.service —since today

This option lets you follow the interactions between various services and get information you wouldn’t otherwise be able to get by tracking the corresponding processes separately.

Filtering by Process, User, and Group

Logs can be viewed for any process by entering its identification number (PID) in the journalctl command, for example:

$ journalctl _PID=381

To view logs for processes run by a specific user or group, _UID and _GID are used respectively. Let’s say we have a web server that was launched by the user www-data. First, we determine the user’s ID:

$id -u www-data

33

Now we can view logs for all the processes launched by this user:

$ journalctl _UID=33

A list of users with records in the logs can be displayed by running:

$ journalctl -F _UID

A similar list of user groups can be viewed using the command:

$ journalctl -F _GUID

The journalctl command can use other filters. A list of available filters can be brought up using the command:

$ man systemd.journal-fields

Filtering by Path

Logs for processes can also be viewed by entering a path, for example:

$ journalctl /usr/bin/docker

This method may sometimes yield more detailed information (like records for all sub-processes).

Viewing Kernel Messages

To view kernel messages, we apply the -k or –dmesg option:

$ journalctl -k

This command displays all kernel message for the current boot. To view kernel messages for previous sessions, the -b option and one of the sessions’ identifiers (serial number or ID) must be given:

$ journalctl -k -b -2

Filtering Messages by Error Level

When troubleshooting failures, we often review logs to find critical error messages. For this very purpose, journalctl lets you filter by error level. To view system error messages, we use the -p option:

$ journalctl -p err -b

This command retrieves all system error messages.

These messages can be filtered by level. Journal uses the same error classification levels as syslog:

  • 0 — Emergency: system is unusable
  • 1 — Alert: action must be taken immediately
  • 2 — Critical: critical conditions
  • 3 — Error: error conditions
  • 4 — Warning: warning conditions
  • 5 — Notice: normal but significant condition
  • 6 — Informational: informational messages
  • 7 — Debug: debug-level messages

Error level codes are entered after the -p option.

Writing Logs to a Standard Output

Journalctl uses the external utility less to print log messages by default. In this case, standard utilities for processing text data (like grep) cannot be used. This problem can be easily resolved: by using the –no-pager option, all messages will be printed as a standard output:

$ journalctl --no-pager

Afterwards, they can be transferred to any utility for further processing or saved as a text file.

Choosing an Output Format

Using the -o option, we can convert log data to any format, making parsing and further processing easier. For example:

$ journalctl  -u nginx.service -o json

{ "__CURSOR" : "s=13a21661cf4948289c63075db6c25c00;i=116f1;b=81b58db8fd9046ab9f847ddb82a2fa2d;m=19f0daa;t=50e33c33587ae;x=e307daadb4858635", "__REALTIME_TIMESTAMP" : "1422990364739502", "__MONOTONIC_TIMESTAMP" : "27200938", "_BOOT_ID" : "81b58db8fd9046ab9f847ddb82a2fa2d", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_CAP_EFFECTIVE" : "3fffffffff", "_MACHINE_ID" : "752737531a9d1a9c1e3cb52a4ab967ee", "_HOSTNAME" : "desktop", "SYSLOG_FACILITY" : "3", "CODE_FILE" : "src/core/unit.c", "CODE_LINE" : "1402", "CODE_FUNCTION" : "unit_status_log_starting_stopping_reloading", "SYSLOG_IDENTIFIER" : "systemd", "MESSAGE_ID" : "7d4958e842da4a758f6c1cdc7b36dcc5", "_TRANSPORT" : "journal", "_PID" : "1", "_COMM" : "systemd", "_EXE" : "/usr/lib/systemd/systemd", "_CMDLINE" : "/usr/lib/systemd/systemd", "_SYSTEMD_CGROUP" : "/", "UNIT" : "nginx.service", "MESSAGE" : "Starting A high performance web server and a reverse proxy server...", "_SOURCE_REALTIME_TIMESTAMP" : "1422990364737973" }

Json objects can be presented in a more structured and comprehensible way by specifying the format as json-pretty or json-sse:

$ journalctl -u nginx.service -o json-pretty

{
    "__CURSOR" : "s=13a21661cf4948289c63075db6c25c00;i=116f1;b=81b58db8fd9046ab9f847ddb82a2fa2d;m=19f0daa;t=50e33c33587ae;x=e307daadb4858635",
    "__REALTIME_TIMESTAMP" : "1422990364739502",
    "__MONOTONIC_TIMESTAMP" : "27200938",
    "_BOOT_ID" : "81b58db8fd9046ab9f847ddb82a2fa2d",
    "PRIORITY" : "6",
    "_UID" : "0",
    "_GID" : "0",
    "_CAP_EFFECTIVE" : "3fffffffff",
    "_MACHINE_ID" : "752737531a9d1a9c1e3cb52a4ab967ee",
    "_HOSTNAME" : "desktop",
    "SYSLOG_FACILITY" : "3",
    "CODE_FILE" : "src/core/unit.c",
    "CODE_LINE" : "1402",
    "CODE_FUNCTION" : "unit_status_log_starting_stopping_reloading",
    "SYSLOG_IDENTIFIER" : "systemd",
    "MESSAGE_ID" : "7d4958e842da4a758f6c1cdc7b36dcc5",
    "_TRANSPORT" : "journal",
    "_PID" : "1",
    "_COMM" : "systemd",
    "_EXE" : "/usr/lib/systemd/systemd",
    "_CMDLINE" : "/usr/lib/systemd/systemd",
    "_SYSTEMD_CGROUP" : "/",
    "UNIT" : "nginx.service",
    "MESSAGE" : "Starting A high performance web server and a reverse proxy server...",
    "_SOURCE_REALTIME_TIMESTAMP" : "1422990364737973"
}

JSON log data can also be presented in the following formats:

  • cat — shows only the message field
  • export — binary format, suitable for transferring data or making backups
  • short — default syslog style output
  • short-iso — default format with ISO 8601 timestamps
  • short-monotonic — default format with monotonic timestamps
  • short-precise — default format with exact time (microsecond precision)
  • verbose — most detailed data format (includes otherwise hidden fields)

Viewing Information on Recent Events

We can view information on recent system events with the -n option:

$ journalctl -n

By default, information on the last ten events will be printed to the console. We can specify the number of events by entering a number after the -n option:

$ journalctl -n 20

Viewing Logs in Real-Time

Log messages can be viewed not only from saved files, but also in real-time. This is done using the -f option:

$ journalctl -f

Managing Logging

Determining Current Disk Usage

Logs grow over time, taking up more and more disk space. To view current log disk usage, we run the command:

$ journalctl --disk-usage
Journals take up 16.0M on disk.

Log Rotation

Log rotation can be configured using the –vacuum-size and –vacuum-time option.
The first sets a limit on the available disk space for saving logs (in our example, it’s 1 GB):

$ sudo journalctl --vacuum-size=1G

As soon as the log size exceeds this limit, unnecessary files will be automatically deleted.
The –vacuum-time option works similarly. It establishes the period of time that logs will be saved for until being automatically deleted:

$ sudo journalctl --vacuum-time=1years

Configuring Log Rotation in Configuration Files

Log rotation can also be configured by modifying the configuration file /etc/systemd/journal.conf, which includes the following parameters:

  • SystemMaxUse= the maximum amount of disk space logs can take up
  • SystemKeepFree= the maximum amount of disk space that should be free after logs are saved
  • SystemMaxFileSize= the maximum size a log should reach before being deleted
  • RuntimeMaxUse= the maximum amount of disk space logs can take up in the /run file system
  • RuntimeKeepFree= the amount of free space that should remain in the /run file system after logs are saved
  • RuntimeMaxFileSize= the maximum size a log should reach before being deleted from the /run file system

Central Log Storage

One of the most common tasks for a system administrator is setting up log retrieval from several machines and saving them to a central storage.
Systemd has been designed with special components for performing these very tasks: systemd-journal-remote, systemd-journal-upload, and systemd-journal-gatewayd.

Using the systemd-journal-remote command, you can accept logs from remote hosts and save them (the systemd-journal-gatewayd should be running on each of these hosts), for example:

$ systemd-journal-remote −−url https://some.host:19531/

By running this command, logs from https://some.host/ will be saved to var/log/journal/some.host/remote-some~host.journal.

Using the systemd-journal-remote command, you can also export all of the logs from a local machine to a separate directory, for example:

$ journalctl -o export | systemd-journal-remote -o /tmp/dir -

The systemd-journal-upload command is used to upload logs from a local machine to remote storage:

$ systemd-journal-upload --url https://some.host:19531/

As you can see from this example, the systemd family of tools for centralizing logging is fairly easy to use. Unfortunately, they are not included in all Linux distributions, only Fedora and ArchLinux.

Users of other distribution still have to transfer logs to syslog or rsyslog, which then get sent over the network. Another solution to the issue of centralized logging was put forth by the developers of journal2gelf, which is included in the official systemd repository: journalctl outputs in JSON format, which gets converted to GELF, and is then transferred by the application for log collection and analysis by Graylog. The solution isn’t especially convenient, but for the time being, there aren’t any better options; all that’s left is to wait until these tools gets added to the distributions.

Conclusion

As we can see from our review, systemd journal is a flexible and comfortable tool for gathering system and application data. This flexibility and convenience is attributed firstly to the centralized approach to logging and secondly to that fact that it automatically writes detailed metadata to logs. Using journalctl, you can view logs to get necessary information for analyzing the operation of and errors from various system components.

If you have any questions or anything to add, please feel free to do so in the comments section. We will talk more about systemd and its components in future posts.