Administering Oracle Linux 7: Part 3 – The systemd Journal
This article is Part 3 of a series that explains how to administer Oracle Linux 7. This article focuses on how to configure and administer the systemd journal.
Introduction to the systemd Journal
Oracle Linux 7 provides a good framework for handling system messages: rsyslog. But in this article, we will explore how to manage messages coming from the kernel by using the systemd journal (also called systemd-journald), which provides a better method for collecting and organizing the messages that occur after the system boots.
The systemd journal gathers event messages in a single indexed database. By default, these event messages (saved in the /run/log/journal directory) are not persistent, and they are cleared after a reboot, though it is possible to change this behavior and keep all messages persistently by creating the /var/log/journal directory.
Furthermore, another advantage of using the /var/log/journal directory is to have access to messages during the boot process for a time specified according to parameters in the /etc/systemd/journald.conf file, as shown below:
[root@target ~]# more /etc/systemd/journald.conf
[Journal]
#Storage=auto
#Compress=yes
#Seal=yes
#SplitMode=login
#SyncIntervalSec=5m
#RateLimitInterval=30s
...According to default values from this file, messages can’t leave less the 15 percent of the file system free or take more than 10 percent of the file system.
Because it is advantageous to use the /var/log/journal directory, it’s recommended that you create it, as shown in the following commands:
[root@target ~]# mkdir /var/log/journal
[root@target ~]# chmod 2755 /var/log/journal
[root@target ~]# chown root:systemd-journal /var/log/journal
[root@target ~]# systemctl restart systemd-journaldTo exam the content of this directory, execute the following commands:
[root@target ~]# ls -al /var/log/journal/4b2c3503d92b46d39c4f71a40716fee3/system.journal
-rw-r-----. 1 root systemd-journal 8388608 Apr 26 02:30 /var/log/journal/4b2c3503d92b46d39c4f71a40716fee3/system.journal
[root@target ~]# file /var/log/journal/4b2c3503d92b46d39c4f71a40716fee3/system.journal
/var/log/journal/4b2c3503d92b46d39c4f71a40716fee3/system.journal: dataExploring the systemd Journal
To exam the system messages in the systemd journal, execute the following command:
[root@target ~]# journalctl
-- Logs begin at Sat 2015-04-25 01:32:44 BRT, end at Sat 2015-04-25 01:40:01 BRT. --
Apr 25 01:32:44 target systemd-journal[61]: Runtime journal is using 8.0M (max
184.6M, leaving 277.0M of free 1.7G, current limit 184.6M).
Apr 25 01:32:44 target systemd-journal[61]: Runtime journal is using 8.0M (max
184.6M, leaving 277.0M of free 1.7G, current limit 184.6M).
Apr 25 01:32:44 target kernel: Initializing cgroup subsys cpuset
Apr 25 01:32:44 target kernel: Initializing cgroup subsys cpu
...As all messages since the beginning of bootare shown (older messages appear first). We can filter to list only some messages, for example, only the last ten messages:
[root@target ~]# journalctl -n 10
-- Logs begin at Sat 2015-04-25 01:32:44 BRT, end at Sat 2015-04-25 01:40:01 BRT. --
Apr 25 01:35:27 target systemd[1]: Started Hostname Service.
Apr 25 01:35:28 target gnome-session[2733]: (tracker-miner-fs:3155): GLib-
CRITICAL **: g_timer_continue: assertion `timer->active == FALSE'
Apr 25 01:35:34 target kernel: TCP: lp registered
Apr 25 01:35:39 target systemd-logind[647]: Removed session c1.
Apr 25 01:35:44 target fprintd[2721]: ** Message: No devices in use, exit
Apr 25 01:36:12 target realmd[2716]: quitting realmd service after timeout
Apr 25 01:36:12 target realmd[2716]: stopping service
Apr 25 01:40:01 target systemd[1]: Starting Session 2 of user root.
Apr 25 01:40:01 target systemd[1]: Started Session 2 of user root.
Apr 25 01:40:01 target CROND[3325]: (root) CMD (/usr/lib64/sa/sa1 1 1)To list the last lines and any subsequent messages (similar to the tail –f command), run this:
[root@target ~]# journalctl -f
-- Logs begin at Sun 2015-04-26 01:32:31 BRT. --
Apr 26 01:33:47 target systemd[1]: Started Hostname Service.
Apr 26 01:33:47 target gnome-session[2713]: Window manager warning: Log level 16:
STACK_OP_ADD: window 0x1e00001 already in stack
Apr 26 01:33:47 target gnome-session[2713]: Window manager warning: Log level 16:
...To show messages that were registered yesterday, execute the following (another option would be to show messages that were registered today using today):
[root@target ~]# journalctl --since yesterday
-- Logs begin at Sun 2015-04-26 01:32:31 BRT, end at Sun 2015-04-26 01:40:01 BRT. --
Apr 26 01:32:31 target systemd-journal[61]: Runtime journal is using 8.0M (max
184.6M, leaving 277.0M of free 1.7G, current limit 184.6M).
Apr 26 01:32:31 target systemd-journal[61]: Runtime journal is using 8.0M (max
184.6M, leaving 277.0M of free 1.7G, current limit 184.6M).
...Sometimes it’s necessary to gather messages for a specified period of minutes, hours, and days. For example, to show all messages from April 26 01:35:00 to April 26 2015 01:50:00, run the following command:
[root@target ~]# journalctl --since "2015-04-26 01:35:00" --until "2015-04-26 01:50:00"
-- Logs begin at Sun 2015-04-26 01:32:31 BRT, end at Sun 2015-04-26 01:50:01 BRT. --
Apr 26 01:40:01 target systemd[1]: Starting Session 2 of user root.
Apr 26 01:40:01 target systemd[1]: Started Session 2 of user root.
Apr 26 01:40:01 target CROND[3415]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Apr 26 01:47:04 target dhclient[1278]: DHCPREQUEST on ens33 to 192.168.64.254
port 67 (xid=0xb268974)
Apr 26 01:47:04 target NetworkManager[827]: DHCPREQUEST on ens33 to
192.168.64.254 port 67 (xid=0xb268974)
Apr 26 01:47:04 target dhclient[1278]: DHCPACK from 192.168.64.254
(xid=0xb268974)
Apr 26 01:47:04 target NetworkManager[827]: DHCPACK from 192.168.64.254
(xid=0xb268974)
Apr 26 01:47:04 target dhclient[1278]: bound to 192.168.64.128 -- renewal in 813
seconds.
Apr 26 01:47:04 target NetworkManager[827]: bound to 192.168.64.128 -- renewal in
813 seconds.
...Personally, I like to use the following very smart way to collect messages from a specific executable or daemon
[root@target ~]# ps aux | grep crond
root 680 0.0 0.0 126284 1692 ? Ss 01:32 0:00 /usr/sbin/crond -n
root 4622 0.0 0.0 112628 968 pts/0 R+ 02:00 0:00 grep --color=auto crond
[root@target ~]# journalctl _EXE=/usr/sbin/crond
-- Logs begin at Sun 2015-04-26 01:32:31 BRT, end at Sun 2015-04-26 02:00:01 BRT. --
Apr 26 01:32:50 target crond[680]: (CRON) INFO (RANDOM_DELAY will be scaled with
factor 71% if used.)
Apr 26 01:32:44 target crond[680]: (CRON) INFO (running with inotify support)
Apr 26 01:55:01 target CROND[3644]: (pcp) CMD (
/usr/libexec/pcp/bin/pmlogger_check -C)In addition to _EXE, the journalctl command accepts other variants, such as _PID (process ID), _COMM (the command), _SYSTEMD_UNIT (among units, there is the service unit), and _UID (user ID).
There are other ways to filter the output, for example, by using priority levels such as info, notice, warning, err, crit, alert, and emerg (the same levels exist in the syslog framework). For example, to list only the messages with the warning priority level and above, execute this:
[root@target ~]# journalctl -p warning
-- Logs begin at Sun 2015-04-26 01:32:31 BRT, end at Sun 2015-04-26 01:34:30 BRT. --
Apr 26 01:32:31 target kernel: ACPI: RSDP 00000000000f6b80 00024 (v02 PTLTD )
Apr 26 01:32:31 target kernel: ACPI: XSDT 00000000bfee35a4 0005C (v01 INTEL
440BX 06040000 VMW 01324272)
Apr 26 01:32:31 target kernel: ACPI: FACP 00000000bfefee98 000F4 (v04 INTEL
440BX 06040000 PTL 000F4240)
...The journalctl command brings us other surprises, such the ability to show the hidden attributes associated with messages, as shown below:
[root@target ~]# journalctl _EXE=/usr/sbin/crond -o verbose
-- Logs begin at Sun 2015-04-26 01:32:31 BRT, end at Sun 2015-04-26 02:10:01 BRT. --
Sun 2015-04-26 01:32:50.504078 BRT [s=671c9891102345b08896fcd684548b58;i=6c5;b=535253a8c69246c3a61c957fde4f1078;m=13
43f14;t=514991f41b76a;x=
PRIORITY=6
_UID=0
_GID=0
_SYSTEMD_SLICE=system.slice
_BOOT_ID=535253a8c69246c3a61c957fde4f1078
_MACHINE_ID=4b2c3503d92b46d39c4f71a40716fee3
_HOSTNAME=target
_CAP_EFFECTIVE=1fffffffff
_TRANSPORT=syslog
SYSLOG_FACILITY=9
SYSLOG_IDENTIFIER=crond
SYSLOG_PID=680
MESSAGE=(CRON) INFO (RANDOM_DELAY will be scaled with factor 71% if used.)
_PID=680
_COMM=crond
...If we already have created the /var/log/journal directory, we can run the following command to list only messages from the last system boot:
[root@target ~]# journalctl -b
-- Logs begin at Sun 2015-04-26 01:32:31 BRT, end at Sun 2015-04-26 02:26:33 BRT. --
Apr 26 01:32:31 target systemd-journal[61]: Runtime journal is using 8.0M (max
184.6M, leaving 277.0M of free 1.7G, current limit 184.6M).
Apr 26 01:32:31 target systemd-journal[61]: Runtime journal is using 8.0M (max
184.6M, leaving 277.0M of free 1.7G, current limit 184.6M).
Apr 26 01:32:31 target kernel: Initializing cgroup subsys cpuset
Apr 26 01:32:31 target kernel: Initializing cgroup subsys cpu
Apr 26 01:32:31 target kernel: Linux version 3.8.13-55.1.5.el7uek.x86_64 (mockbuild@ca-build56.us.oracle.com) (gcc version 4.8.2 20140120 (R
Apr 26 01:32:31 target kernel: Command line: BOOT_IMAGE=/vmlinuz-3.8.13-55.1.5.el7uek.x86_64 root=/dev/mapper/ol-root ro crashkernel=auto vc
Apr 26 01:32:31 target kernel: Disabled fast string operationsAfter a few days, it would feasible to gather information about past boots by executing commands such as journalctl –b -2 (two boots before).
Exploring the journald and rsyslogd Daemons
The journald daemon is a very important resource for tracing potential problems on the system, and all gathered data by journald is forwarded to the /run/systemd/journal/syslog directory. Such data is analyzed and processed by the rsyslogd daemon, which usually (it isn’t a rule) save its messages in the /var/log directory. Because the amount of information can be huge, a limit can be established by the logrotate daemon (from the logrotate package), which has a main configuration file (/etc/logrotate.conf) and automatically rotates logs according this configuration file and other configuration files that exist in the /etc/logrotate.d directory. The logrotate service is usually scheduled as a cron task to clean up logs.
The main configuration file of the rsyslogd daemon is the /etc/rsyslog.conf file shown below:
[root@target ~]# more /etc/rsyslog.conf
...
#### RULES ####
# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.* /dev/console
# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none /var/log/messages
# The authpriv file has restricted access.
authpriv.* /var/log/secure
# Log all the mail messages in one place.
mail.* -/var/log/maillog
# Log cron stuff
cron.* /var/log/cron
# Everybody gets emergency messages
*.emerg :omusrmsg:*
# Save news errors of level crit and higher in a special file.
uucp,news.crit /var/log/spooler
# Save boot messages also to boot.log
local7.* /var/log/boot.log
...Other supplemental configuration files can exist in the /etc/rsyslogd.d directory, as shown below:
[root@target ~]# ls -al /etc/rsyslog.d/
-rw-r--r--. 1 root root 2564 Feb 4 2014 gluster.conf.example
-rw-r--r--. 1 root root 49 Jan 13 06:57 listen.conf
-rw-r--r--. 1 root root 291 May 4 2014 spice-vdagentd.confSimilar to the old syslogd daemon, the syntax of the /etc/rsyslog.conffile is as follows:
facility. serveritydestination
The facility selector specifies the subsystem, and it can hold the following values: kern, user, mail, daemon, atuh, syslog, lpr, news, uucp, cron, authpriv, ftp, and local0-7.
The severity selector determines the priority, and it can be any of the following: debug (7), info (6), notice (5), warning (4), err (3), crit (2), alert (1) , and emerg(0). The lower the number the higher the priority, but there is a special value named none that means none of messages coming from the specified facility will be inserted into the log file.
Take the next example, which comes from /etc/rsyslog.conf file above:
cron.* /var/log/cronIn this case, every message coming from the cron subsystem, independent of its priority, is directed to the /var/log/cron log file.
Another good example follows:
mail.err /var/log/email_errorsIn this case, any message coming from the mail subsystem with a priority equal to err or higher (crit, alert, and emerg) will be logged in the /var/log/email_errors file.
An example about logging to the network follows:
*.crit @192.168.1.92The line above means the every message from any subsystem will be logged to the network and the destination host will be 192.168.1.92. It is important to mention that there must be an entry for the remote system (192.168.1.92) in the /etc/rsyslog.conf file to handle this kind of message with priority crit or higher. In addition, the administrator needs to open the firewall on the destination system for receiving messages from the source system that is sending messages. To accomplish this, execute the following commands on the destination host:
[root@target2 ~]# firewall-cmd --list-all
public (default, active)
interfaces: ens33 virbr0 virbr0-nic
sources:
services: dhcpv6-client lime ssh
ports:
masquerade: no
forward-ports:
icmp-blocks:
rich rules:
[root@target2 ~]# firewall-cmd --zone=public --add-port=514/tcp
success
[root@target2 ~]# firewall-cmd --list-all
public (default, active)
interfaces: ens33 virbr0 virbr0-nic
sources:
services: dhcpv6-client lime ssh
ports: 514/tcp
masquerade: no
forward-ports:
icmp-blocks:
rich rules:A suitable hint is that every change in the rsyslog configuration file must be followed by a restart action of its service, as shown below:
[root@target ~]# systemctl restart rsyslog
[root@target ~]# systemctl status rsyslog
rsyslog.service - System Logging Service
Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled)
Active: active (running) since Sun 2015-04-26 18:44:28 BRT; 5s ago
Main PID: 13319 (rsyslogd)
CGroup: /system.slice/rsyslog.service
└─13319 /usr/sbin/rsyslogd -n
Apr 26 18:44:28 target systemd[1]: Starting System Logging Service...
Apr 26 18:44:28 target systemd[1]: Started System Logging Service.Returning to the log rotation issue, the main configuration file is /etc/logrotate.conf:
[root@target ~]# more /etc/logrotate.conf | grep -v '^#|^As general rules from the configuration file above, we have the following:
weekly specifies to rotate log file weekly. Other possible values would be daily, monthly, and yearly.
rotate 4 specifies that the last four weeks of history be kept.
create creates new files after rotating the old ones.
dateext appends the date as a suffix for each rotated log.
Usually, we see other options such as compress (enable compression of rotated log files), mail <address> (mail rotated logs to a specific address), and maillast (mail log files when they are close to their expiration date).
During a troubleshooting procedure, rsyslogd can be run in debugging mode, as shown below:
[root@target ~]# rsyslogd -dn
6289.131614038:7f893b3bb780: rsyslogd 7.4.7 startup, module path '', cwd:/root
6289.132879646:7f893b3bb780: caller requested object 'net', not found (iRet -3003)
6289.132900102:7f893b3bb780: Requested to load module 'lmnet'
6289.132911640:7f893b3bb780: loading module '/usr/lib64/rsyslog/lmnet.so'
6289.133091622:7f893b3bb780: module lmnet of type 2 being loaded (keepType=0).
6289.133102711:7f893b3bb780: entry point 'isCompatibleWithFeature' not present in module
...Additionally, we can verify the /etc/rsyslog.conf syntax by running the following command:
[root@target ~]# rsyslogd -N 1
rsyslogd: version 7.4.7, config validation run (level 1), master config /etc/rsyslog.conf
rsyslogd: End of config validation run. Bye.weekly rotate 4 create dateext include /etc/logrotate.d /var/log/wtmp { monthly create 0664 root utmp minsize 1M rotate 1 } /var/log/btmp { missingok monthly create 0600 root utmp rotate 1 }As general rules from the configuration file above, we have the following:
weekly specifies to rotate log file weekly. Other possible values would be daily, monthly, and yearly.
rotate 4 specifies that the last four weeks of history be kept.
create creates new files after rotating the old ones.
dateext appends the date as a suffix for each rotated log.
Usually, we see other options such as compress (enable compression of rotated log files), mail <address> (mail rotated logs to a specific address), and maillast (mail log files when they are close to their expiration date).
See Also
Here are some links to other things I’ve written:
- Alexandre Borges on Twitter
- Alexandre Borges’ personal blog
- “Exploring Installation Options and User Roles in Oracle Solaris 11“
- “Exploring Networking, Services, and the New Image Packaging System in Oracle Solaris 11“
- ZFS Series https://community.oracle.com/docs/DOC-914874
