System logs greatly aid sysadmins in keeping the system running like a well-oiled machine. Since an ounce of prevention is better than a pound of cure, monitoring system logs can help to anticipate problems and prevent breakdowns. One needs some knowledge of the system log architecture, however, to do this.
Processes and the operating system kernel need to be able to record a log of events that happen. These logs can be useful for auditing the system and for troubleshooting. By convention, the /var/log directory is where these logs are stored permanently.
A standard logging system based on the Syslog protocol is built into Red Hat Enterprise Linux (RHEL). Many programs use this system to record events and organise them into log files. In RHEL 7, syslog messages are handled by two services — systemd-journald and rsyslog.
The systemd-journald daemon provides an improved log management service that collects messages from the kernel, the early stages of the boot process, standard output and the error of daemons as they start up and run the syslog. It writes these messages to a structured journal of events that, by default, does not persist between reboots. This allows syslog messages and events that are missed out by the syslog to be collected in one central database. The syslog messages are also forwarded by systemd-journald to rsyslog for further processing.
The rsyslog service then sorts the syslog messages by type (or facility) and priority, and writes them to persistent files in the /var/log directory. The /var/log directory holds various system and service-specific log files maintained by rsyslog, as shown in Table 1.
Reviewing syslog files
Many programs use the Syslog protocol to log events of the system. Each log message is categorised by a facility (the type of message) and a priority (the severity of the message). The facilities that are available are documented by the rsyslog.conf(5) man page. The eight priorities are also standardised and ranked, as shown in Table 2.
The rsyslogd service uses the facility and prioritisation of log messages to determine how to handle them. This is configured by the file /etc/rsyslog.conf and by *.conf files in /etc/rsyslog.d. Programs and administrators can change rsyslogd configuration in a way that it will not be overwritten by updates to rsyslogd by putting customised files with a .conf suffix in the /etc/rsyslog.d directory.
The Rules section of /etc/rsyslog.conf contains directives that define where log messages are saved. The left side of each line indicates that the facility and severity of the log message directive matches. The rsyslog.conf file can utilise the character * as a wild card in the facility and the severity fields, where it either stands for all the facilities or all the severities. The right side of each line indicates what file the log message is to be saved in. Log messages are always saved in files in the /var/log directory.
Note: Log files are maintained by the rsyslog service, and the /var/log directory contains a variety of log files specific to certain services. For example, the Apache Web server or Samba write their own log files into a corresponding sub-directory of the /var/log directory.
A message handled by rsyslog can appear in multiple different log files. To prevent this, the severity field can be set to None, which means that none of the messages directed to this facility are added to a specific log file.
Instead of logging syslog messages to a file, they can be printed to the terminals of all logged-in users. In the default rsyslog.conf file, this is done for all messages that have emerg priority. A sample of the Rules section of rsyslog.conf is shown in Figure 1.
Note: The rsyslog.conf file is documented by the man page of rsyslog.conf (5) and there is extensive documentation in /usr/share/doc/rsyslog-*/manual.html in Red Hat Enterprise Linux 7.
Log file rotation
Logs are rotated by the logrotate utility to keep them from filling the file system containing /var/log. When a log file is rotated, it is renamed with an extension indicating the date on which it was rotated — the old /var/log/messages file may become /var/log/messages-20180630 if it is rotated on June 30, 2018. Once the old log file is rotated, a new log file is created and the service that writes to it is notified.
After a certain number of rotations, typically after four weeks, the old log file is discarded to free disk space. A cron job runs the logrotate program daily to see if any logs need to be rotated. Most log files are rotated weekly, but logrotate rotates some faster or slower, or when they reach a certain size. Configuration of logrotate is not covered in this article but you can check out the logrotate (8) man page.Analyse a syslog entry
The system log written by rsyslog starts with the oldest message on the top and the newest message at the end of the log file. All log entries in the log file managed by rsyslog are recorded in a standard format. An example is shown below, which is a sample taken from the /var/log/secure log file.
- Feb 21 20:11:48: Indicates the time stamp when the log entry was recorded.
- localhost: Indicates the host from where the log message was sent.
- sshd[1433]: Indicates the program or process that sent the log message.
- Failed password for student from 172.25.8.10 port 59344 ssh2: Indicates the actual message sent.
Monitoring a log file with a tail
To reproduce problems and issues, it is helpful to monitor more log files for events. The tail –f /path/to/file command outputs the last ten lines of the file specified, and continues to output new lines as they get written to the monitored file.
To monitor for failed login attempts on one terminal, run ssh from one machine to another with the wrong password and list it as shown in Figure 2.
Send a syslog message with a logger
The logger command can send messages to the rsyslog service. By default, it sends the message to the facility user with a severity notice (user.notice) unless specified otherwise, with the –p option. It is especially useful to test changes to the rsyslog configuration.
To send a message to rsyslogd that gets recorded in the /var/log/boot.log file, execute the following command:
# logger –p local 7.notice “Log entry created on test7”
Reviewing system journal entries (finding events with journalctl)
The systemd journal stores logging data in a structured, indexed binary file. This data includes extra information about the log event. For syslog events, this can include the facility and priority of the original message.
Important: In Red Hat Enterprise Linux 7, the systemd journal is stored in /run/log, by default, and its contents are cleared after reboot. The setting can be changed by the systems administrator.
The journalctl command shows the full system journal, starting from the oldest log entry, when run as the root user. The output is shown in Figure 3.
The journalctl command highlights in bold text the messages of priority notice or warning; messages of priority error and higher are highlighted in red.
The key to successfully using the journal for troubleshooting and auditing is to limit the journal searches to only show relevant output. By default, journalctl –n shows the last ten log entries. It takes an optional parameter for how many of the last log entries should be displayed. To display the last five log entries, run the following command:
# journalctl –n 5.
When troubleshooting problems, it is useful to filter the output of the journal on the basis of the priority of journal entries. journalctl –p takes either the name or the number of the known priority levels, and shows the given levels and all higher level entries. The priority levels known to journalctl are debug, info, notice, warning, err, crit, alert and emerg.
To filter the output of the journalctl command to only list any log entry of priority err or above, run the following command:
# journalctl –p err
Similar to the tail –f command, journalctl –f outputs the last ten lines of the journal and continues to output new journal entries as they get written to the journal.
When looking for specific events, it is useful to limit the output to a specific time frame. The journalctl command has two options to limit the output to a specific time range, the –since and –until options. Both options take a time parameter in the format YYYY-MM-DD hh:mm:ss. If the date is omitted, the command assumes the current date, and if the time is omitted, the whole day, starting at 00:00:00, is assumed. Both options take yesterday, today and tomorrow as valid parameters in addition to the date and time field.
The output of all journal entries recorded today can be shown using the following command:
# journalctl --since today.
To output the journal entries from June 10, 2018 20:30:00 to June 13, 2018 12:00:00:, use the following command:
# journalctl --since “2018-06-10 20:30:00” --until “2018-06-13 12:00:00.
In addition to the visible content of the journal, there are fields attached to log entries that can only be seen when verbose output is turned on. All of the displayed extra fields can be used to filter the output of a journal query. This is useful to reduce the output of complex searches for certain events in the journal.
Among the more useful options to search for lines relevant to a particular process or event are:
- _COMM: The name of the command
- _EXE: The path to the executable for the process
- _PID: The PID of the process
- _UID: The UID of the process
- _SYSTEMD_UNIT: The system unit that started the process
More than one of these can be combined. For example, the following query shows all journal entries related to processes started by the system unit file sshd.service, which also have the PID 1182:
#journalctl _SYSTEMD_UNIT=sshd.service _PID=1182
Note: For a list of commonly used journal fields, consult the man page of system.journal-fields (7) using the man command.
Preserving the systemd journal (storing the system journal permanently)
By default, the systemd journal is kept in /run/log/journal, which means it is cleared when the system reboots. The journal is a new mechanism in RHEL 7 and for most installations, a detailed journal that starts with the last boot is sufficient.
If the directory /var/log/journal exists, the journal will log to that directory instead. The advantage of this is the historic data will be available immediately at boot. However, even with a persistent journal, not all dates will be kept forever. The journal has a built-in log rotation mechanism that will get triggered on a monthly basis. In addition, by default, the journal will not be allowed to become larger than 10 per cent of the file system it is on, or leave less than 15 per cent of the file system free. These values can be tuned in /etc/system/journal.conf and the current limits on the size of the journal are logged when the system-journald process starts, as can be seen in the output of the journalctl command.
The systemd journal can be made persistent by creating the directory /var/log/journal as the user root, with the following command:
# mkdir /var/log/journal
Ensure that the /var/log/journal directory is owned by the root user and systemd-journal, and has the permissions 2755.
#chown root:systemd-journal /var/log/journal. #chmod 2755 /var/log/journal
A reboot of the system on sending the special signal USR1 as the root user to the systemd-journald process is required.
# killall –USR1 systemd-journald.
Since the systemd journal is now persistent across reboots, journalctl –b can reduce the output by only showing the log messages since the last boot of the system.
# journalctl –b
Note: When debugging a system crash with a persistent journal, it is usually required to limit the journal query to the reboot before the crash happened. The –b option can be accompanied by a negative number indicating how many prior system boots the output should be limited to. For example, Journalctl –b -1 limits the output to the previous boot.
