GPO ( Grupo de Profissionais Oracle )
A maior comunidade Oracle do Brasil !

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.

Read Part I
Read Part II

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-journald

To 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: data

Exploring 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 operations

After 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.conf

Similar 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/cron

In 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_errors

In 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.92

The 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 '^#|^$'

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).

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.

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

Share

You may also like...

Deixe um comentário

O seu endereço de e-mail não será publicado. Campos obrigatórios são marcados com *