System Logging
Most of the time, your Linux computer will work just fine. From time to time, however, your program won’t start, or system components will break. When this is the case, you’ll need all the help that you can get. Assuming that you’ve already used the available command documentation that is on your computer, such as man and --help, you’ll need to find out now what exactly is happening when you try to accomplish your task. That brings us to system logging.
Understanding Logging
One of the items that you will like on Linux—once you’ll understand how it works—is the way that Linux handles system logging. Logging on Linux is extensive, and you’ll be able to tell it to send log messages anywhere you want. The result is not only a bunch of files that are created in /var/log, but in many cases also more important messages that are written to the virtual consoles on your computer as well as log information that is made available through the systemctl command. Think about the virtual consoles that Linux works with; for instance, just while installing, several consoles are available through which you can monitor the output of different commands.
Note In Chapter 2, you read how to activate a virtual console, using Ctrl+Alt+F1 up to Ctrl+Alt+F6. On most distributions, even the graphical console is a virtual console, which is available using the Ctrl+Alt+F7 keystroke.
Behind all these messages is often a process with the name syslog. This process is configured to monitor what happens on your computer. It does that by watching the messages that the commands you use are generating. syslog captures these messages and sends them to a destination, which is often a file, but as mentioned can also be a virtual console on your computer.
Syslog has different implementations. The early version of syslog is just called “syslog”. This logging process has been enhanced and replaced with the more flexible rsyslog service. On occasion you’ll also find syslog-ng which is taking care of logging. On current Linux distributions, rsyslog is the de facto standard though. It is completely backwards compatible with the old syslog service, but offers many new features as well, which will be discussed later in this chapter. As rsyslog is the current standard for logging system information, in this chapter I will focus on its working.
Apart from the rsyslog process that captures the messages and directs them somewhere, there is also the command or process that generates the messages. Not all of these are handled by rsyslog, the Apache web service for instance is taking care of its own logging. The reason for many services to take care of their own logging, is that even the newer rsyslog has always been bound by backwards compatibility, with the result that filtering information for specific services is rather limited.
With the release of systemd as the default service manager, a new log system has been introduced as well. It has the name systemd-journald, and often is referred to as just journald. This service grasps log information that is generated by all items that are started through systemd and provides a generic interface to get access to that information. When typing systemctl status on any service, you’ll by default see the most recent information that has been logged by that service. Listing 10-1 shows an example, where log information for the sshd process is shown. Journald also has its own interface to get access to information, which is provided through the journalctl command.
Listing 10-1. Displaying log information using systemctl status
Apart from the logging that is done for services as described above, you might on occasion want your regular commands to be more verbose as well. For this purpose, many commands support the -v option to make them more verbose.
A random example of this is the cp command , which by default does not show you what it is doing. However, if you add the -v option to it, it shows exactly what it is doing, even if it just succeeds in copying the file. Listing 10-2 gives an example of this.
Then there are also the commands that you run from a graphical interface. Normally, they don’t show what they are trying to do. However, if you find out what the name and exact location of the command are, and you try running the command from a command line instead of just clicking its icon, you’ll be surprised by how much output the command gives. In Listing 10-3, you can see what running the Gnome file explorer Nautilus from the command line looks like. Notice that doing so also displays any error messages about networking that you would never see when starting the command the normal way.
Most commands, however, write to the system log to indicate that something is wrong. Before discussing the workings of this system log, the next section explains more about the log files it writes and how you can monitor them. Before getting into that, Table 10-1 provides an overview of the different ways to get log information out of commands and services.
Table 10-1. Methods for showing log information
|
Command verbosity |
Use -v with many commands |
|
Rsyslog |
Generic solution that writes information to files in /var/log and other destinations |
|
Direct logging |
Some services don’t use rsyslog, but write information directly to log files in /var/log |
|
Journald |
Integrated component of systemd that writes information to the journal. This information is accessed through the systemctl status and the journalctl commands. |
There is no standardization between different Linux distributions as to where information should be logged to. What is sure is that you’ll find all of the log files that are written in the /var/log directory. On many distributions /var/log/messages is the most important destination for log files, but you’ll find other log destinations as well, such as /var/log/system. Log files are just text files, so you can read them as you would any other text file—open it with less, for instance, or watch the last couple of lines with the tail command. A particularly useful way of monitoring the content of these files, however, is through tail -f, in which -f stands for follow. When invoked in this way, tail opens the last ten lines of the log file and automatically shows new lines as they are created. This technique is particularly useful when trying to understand what exactly a command or service is doing. As it shows you real-time information, you’ll see immediately whether something doesn’t work out, which allows you also to take action straight away.
When watching log files, many people tend to forget that there are more than just /var/log/messages. Have a look at the log files that exist on your computer and try to understand what they are used for. For instance, did you know that most computers write a log entry not only for every single mail message they receive, but also for every failed attempt to send an e-mail? This information, which is useful when trying to understand why sending an e-mail doesn’t work, is not written to /var/log/messages. Hence, have a look at the contents of /var/log and see what other files you need to know about to find all log information that commands on your computer are generating. Later in this chapter you’ll learn how rsyslog is configured to specify which destination log information should be written to. Listing 10-4 gives an impression of what the contents of /var/log looks like on my computer.
Configuring the syslog Service
As mentioned before, rsyslog is the default service for logging on most current Linux distributions. It allows administrators to specify what services should log which type of information to which destination. These three items are referred to as the facility (which service), the priority (the severity level that should be logged) and the destination (where the information should be logged to). Apart from these, rsyslogd can be configured with modules to further fine-tune the working of the log services. Modules are used for advanced configurations and for that reason are not discussed in this chapter.
The main rsyslog configuration file is /etc/rsyslog.cond. Apart from this file, you’ll find the /etc/rsyslog.d directory. The contents of this directory is added to the configuration that is specified in /etc/rsyslog.conf, which allows RPM or Debian packages to extent the configuration without modifying the contents of the /etc/rsyslog.conf file. Listing 10-5 shows what the contents of the rsyslog.conf looks like.
The most important part of the rsyslog.conf configuration file is in the RULES section. In here the three elements facility, priority and destination are used to specify where information should be sent to
Facilities are a fixed part of rsyslog and you cannot easily add to them. The following facilities are available in syslog:
- auth: Facility that handles events related to authentication.
- authpriv: Facility that handles events related to authentication, as does auth. There is no difference between auth and authpriv.
- cron: Facility that handles messages generated by the cron subsystem (see Chapter 9 for more information about cron).
- daemon: Log messages that are generated by a daemon. No further subdivision can be made for system processes, with the exception of the daemons that have their own facility, such as ftp and mail.
- kern: Kernel-related messages. This facility also defines messages that are generated by the iptables kernel firewall.
- lpr: Messages related to the legacy lpr printing system.
- mail: Messages related to handling mail messages.
- mark: For internal use only. The syslog process can place a marker in syslog periodically. If your computer doesn’t log a lot, this can help you make sure that logging is still enabled.
- news: Messages related to the Network News Transport Protocol (NNTP)–related services.
- security: Generic security-related messages.
- syslog: Messages that are related to the syslog process itself.
- user: User-related messages.
- uucp: Messages that are generated by the legacy Unix to Unix Copy Protocol (UUCP).
- local0-local7: Facilities that you can use for all other services. To use these facilities, you need to configure the service in its configuration file to log to the local facility. Consult the documentation for the service for more information on how to do this.
When writing log messages, the facilities produce messages with a given priority. When a priority is referred to, messages with this priority and all higher priorities are written to the destination that is specified. The following priorities are defined in syslog, listed in ascending order:
- debug: Relates to debug information. This gives you detailed information on everything the facility is doing. In general, this level of information is useful for programmers only in that it tells you exactly what system and library calls the facility performs.
- info: Gives all “normal” information about what the process is doing. This gives you information about files that are open, for instance, but does not give extensive information about system and library calls.
- notice: Gives information about noncritical errors. For instance, this can refer to a file that should exist, but because it didn’t, it was created automatically.
- warn/warning: Give information about warnings that occurred when executing the process. Both warn and warning have the same meaning, but warning is deprecated. This means you can still use it, as Linux will understand it, but because it’s “old school,” so you shouldn’t use it anymore. A warning defines a situation where normal functionality is disrupted, but the facility still operates.
- err/error: Give information about errors. Typically, err-level messages are about situations that interrupt normal functioning of the facility. The use of error is deprecated. Use err instead.
- crit: Gives information about critical situations that endanger normal operation of your computer.
- alert: Gives information about a situation that will cause your computer to stop.
- emerg/panic: Indicate normal operation of your computer has stopped. The use of panic is deprecated. Use emerg instead.
To define log events, in rsyslog.conf you’ll refer to a facility combined with a priority. If no other exceptions are defined, the priority you mention includes all higher priorities as well. For instance, the following would refer to informational messages generated by the kernel and messages with a higher priority as well:
kern.info
You can also refer to multiple facilities in one line by specifying them in a comma- separated list. For instance, the following refers to both informational messages related to the kernel and informational messages related to the cron process:
kern,cron.info
Alternatively, you can refer to all facilities by using an asterisk, as in the following example line:
*.crit
When referring to a priority, normally by just mentioning the priority you will include all higher priorities as well. If you want to define what should happen just in case the specified priority occurs, use an equals sign, as in the following example line, which handles messages related to mail and not to messages with a higher priority:
mail.=info
You can also include a statement to exclude a priority and every priority beyond it by putting an exclamation mark in front of the name of the priority:
mail.!info
When a log event happens, an action is performed on it. This action typically means that a message is sent somewhere. In syslog, the available actions are also well defined. Multiple facilities and priorities can be specified in one line to log to the same destination. Listing 10-5 includes several examples of this. You can send log messages to the following:
- Regular file: When mentioning the name of a file, log messages are written to that file. You must specify this file name as an absolute path name. To prevent syslog from writing every single message to the configuration file immediately, you can put a - sign in front of the file name. This means that changes are buffered first before they are written to the actual configuration file. In Listing 10-5, this is used to handle logging of messages that have a debug status. The ; sign in this listing is used as the delimiter, and the sign makes sure that the next part is interpreted as belonging to the same line:
*.=debug;
auth,authpriv.none;
news.none;mail.none -/var/log/debug - Named pipe: By logging to a named pipe, you can pipe log messages to a device. To use a named pipe, you should put a pipe symbol in front of the device name. The following example from /etc/syslog.conf shows how to log to the xconsole device using a named pipe:
daemon.*;mail.*;
news.err;
*.=debug;*.=info;
*.=notice;*.=warn |/dev/xconsole - Terminal or console: If the file that you’ve specified as the actual log destination is a tty, syslog will handle it as a tty and log messages in real time to it. A very common tty to use for this purpose is /dev/console.
- Remote machine: A very useful feature that you can use with syslog is the option to configure one computer as the log host for all computers in the network. On this computer, you will see the name of the machine from which a message comes in the log files. To send log messages to a remote computer, you must meet two conditions:
- Start syslog with the remote logging feature enabled. By default, the syslog process does not accept messages that come from other hosts. You can enable remote logging on the syslog process by starting it with the -r option. This tells your current machine that it should accept log messages coming from other machines.
- In syslog.conf, specify the name of the machine you want to log to as the log destination by putting an @ sign in front of the machine name. For instance, you would use @RNA to log messages to a machine with the name RNA. This machine name must be resolvable if you want this to work.
- User: You can send messages directly to a user, who will receive this message in real time if he or she is logged in. To do this, just use the name of the user or a comma- separated list of multiple users. For instance, the following would make sure that all messages generated by the kernel and having a status of critical and higher are sent directly to the root user:
kern.crit root - Everyone logged in: If the log message is critical (for instance, because it disrupts all functionality of the system), it makes sense to send a message to all users who are currently logged in. To do this, specify an asterisk as the log destination.
EXERCISE 10-1: CONFIGURING RSYSLOG
In this exercise you’ll learn how to configure rsyslog to send all messages that are generated to the file /var/log/all.
- Open the /etc/rsyslog.conf file with an editor.
- Locate the RULES section, and add the following line:
*.* /var/log/all - Type systemctl restart rsyslog. Restarting the service is mandatory to make the changes effective.
- Type logger HELLO
- Type tail -f /var/log/all. You should see a line that has been added, displaying the text HELLO at the end of the /var/log/all file.
Some years ago, syslog-ng has been introduced as the successor of the legacy syslog system. Even if most distributions have moved to rsyslog as the new next generation system logger, you may encounter syslog-ng as well. The following section describes how it is worked and configured.
In syslog-ng facilities, priorities and log destinations are also used; read the preceding section if you need to know more about these. The way they are used, however, is much different from standard syslog. In Listing 10-6, you see an example of syslog-ng.conf, which defines how logging should be handled.
Caution On SUSE Linux, you’ll find the files /etc/syslog-ng/syslog-ng.conf and /etc/syslog-ng/syslog-ng.conf.in. You should make all modifications to the /etc/syslog-ng/syslog-ng. conf.in file, and after making the modifications, run the SuSEconfig command to write them to /etc/ syslog-ng/syslog-ng.conf. This procedure is used because an update procedure to SUSE may alter the syslog-ng.conf file, which may cause you to lose all changes that you’ve made to it.
In a syslog-ng configuration, three elements are combined in the log statement to define where messages are logged to:
- source: Defines where messages are accepted from
- filter: Specifies what exactly the log message should match
- destination: Indicates where the message must be written to
To understand what’s happening on your syslog-ng configuration, it makes sense to read the configuration file bottom up: at the bottom of the file, you’ll find the log statement that defines how logging should be handled, and in the upper parts of the configuration file, you can find the different elements that make up this definition. Following is an example of such a log statement:
log { source(src); filter(f_warn); destination(warn); };
In this example, the first part that you see is the source specification, which is defined as (src). This refers to a definition that is made earlier in the same file, which you can see here:
source src {
#
# include internal syslog-ng messages
# note: the internal() source is required!
#
internal();
#
# the following line will be replaced by the
# socket list generated by SuSEconfig using
# variables from /etc/sysconfig/syslog:
#
unix-dgram("/dev/log");
#
# uncomment to process log messages from network:
#
#udp(ip("0.0.0.0") port(514));
};
As you can see, the src definition by default accepts two sources: messages that are generated internally and messages for which the operating system uses the /dev/log device to process them. This definition handles all messages that are generated by your computer, but does not accept any messages from other computers. However, you may also include these easily. To accept messages from all computers, make sure the following line is enabled:
udp(ip("0.0.0.0") port(514));
Alternatively, you can refer to messages that come from one host or a range of hosts by mentioning the IP address of the host or the range from which you want this machine to accept messages. For instance, you could enable messages from all IP addresses in the network 192.168.1.0 by using the following:
udp(ip("192.168.1.0") port(514));
Looking back at the example, the second part of the log definition defines the filter, which in this case is f_warn, as shown here:
filter f_warn { level(warn, err, crit) and not filter(f_iptables); };
In a filter definition, you can indicate what level the message should come from and also what facility should generate the message. As you can see in the preceding example, you can also tell the filter not to handle messages that come from another specific filter. Filters in syslog-ng are very flexible. This is because you can also use a match statement, which uses a regular expression to tell syslog-ng to look for specific text. Following is an example of this:
filter f_acpid { match('^[acpid]:'); };
In this filter, a match is used to look for a regular expression. The regular expression defines that syslog-ng should handle all lines that start with the text [acpid], which enables you in this case to specify a specific log target for the acpid service. When building syslog-ng configurations, you will in particular like this match functionality.
As the last part of your syslog-ng configuration, you’ll have to specify where to send the messages. You do this by defining a log destination. Following is an example of a destination:
destination newscrit { file("/var/log/news/news.crit"
owner(news) group(news)); };
In syslog-ng destinations, you can use all log destinations that you’ve also seen in syslog. But here also, it is possible to be very specific. For instance, you can see that the example code defines not only the name of the file that syslog-ng has to write, but also the user owner and group assignments for that file.
Tip Syslog-ng may look intimidating when you first start working with it. If you know it a little better, you will find out that it is not that hard. I recommend you to study the example syslog-ng.conf file thoroughly, because it has all the examples you need to build your own configuration.
Sending Logs Yourself with logger
Also very useful when handling logs is the logger command. This command sends messages to syslog by default, which makes it a useful command to include in scripts where no default logging is available. You can tell logger to use a certain priority, but normally you won’t; if used in a syslog-ng environment, you’ll just employ a matching filter to handle messages that are generated by the logger command. Using this command is very simple. For example, the following would write a message to your syslog:
logger hi
When using logger, you may like the option to mark every line you write to the log files with a specific tag. This makes it easier for you to recognize such lines later on. To do this, use the option -t tag. For instance, the command logger -t blah hi would tag the message hi in the log file with blah, which makes it easier for you to grep on messages that you’ve written with logger.
Rotating Old Log Files
Logging is good, but if your system writes too many log files, it can become rather problematic.
As a solution to this, you can configure the logrotate service. The logrotate service runs as a daily cron job and checks its configuration files to see whether any rotation has to occur. In these configuration files, you can configure when a new log file should be opened and, if that happens, what exactly should happen to the old log file: for example, whether should it be compressed or just deleted, and if it is compressed, how many versions of the old file should be kept.
logrotate works with two different kinds of configuration files. The main configuration file is /etc/logrotate.conf. In this file, generic settings are defined to tune how logrotate should do its work. You can see the contents of this file in Listing 10-7.
The code in Listing 10-7 includes some important keywords. Table 10-2 describes these keywords.
Table 10-2. logrotate Options
|
Option |
Description |
|---|---|
|
weekly |
This option specifies that the log files should be created on a weekly basis. |
|
rotate 4 |
This option makes sure that four old versions of the file are saved. If the rotate option is not used, old files are deleted. |
|
create |
The old file is saved under a new name and a new file is created. compress Use this option to make sure the old log files are compressed. compresscmd This option specifies the command that should be used for creating the compressed log files. |
|
uncompresscmd |
Use this command to specify what command to use to uncompress compressed log files. |
|
include |
This important option makes sure that the content of the directory /etc/logrotate.d is included. In this directory, files exist that specify how to handle some individual log files. |
As you have seen, the logrotate.conf configuration file includes some generic code to specify how log files should be handled. In addition to that, most log files have a specific logrotate configuration file in /etc/logrotate.d/.
The content of the service-specific configuration files in /etc/logrotate.d is in general more specific than the contents of the generic logrotate.conf. In Listing 10-8, you can see what the configuration script that handles log files for /var/log/ntp looks like.
Listing 10-8 demonstrates some additional options. Table 10-3 gives an overview of these options and their meaning.
Table 10-3. Options in Service-Specific logrotate Files
|
Option |
Description |
|---|---|
|
dateext |
Uses the date as extension for old versions of the log files. |
|
maxage |
Specifies the number of days after which old log files should be removed. |
|
rotate |
Specifies the number of times a log file should be rotated before being removed or mailed to the address specified in the mail directive. |
|
size |
Logs files that grow bigger than the size specified here. |
|
notifempty |
Does not rotate the log file when it is empty. |
|
missingok |
If the log file does not exist, goes on to the next one without issuing an error message. |
|
copytruncate |
Truncates the old log file in place after creating a copy, instead of moving the old file and creating a new one. This is useful for services that cannot be told to close their log files. |
|
postrotate |
Specifies some commands that should be executed after performing the logrotate on the file. |
|
endscript |
Denotes the end of the configuration file. |
Like the preceding example for the ntp log file, all other log files can have their own logrotate file. You can even create logrotate files for files that are not log files at all! More options are available when creating such a logrotate file; for a complete overview, check the man pages.
EXERCISE 10-2: CONFIGURING LOG ROTATION
In exercise 10-1 you have configured rsyslog to write all messages that are logged to the file /var/log/all. In this exercise you’ll learn how to rotate that file based on specific criteria.
- Open a root shell and use cd /etc/logrotate.d to go to the directory that contains log rotate files for specific services.
- Type cp syslog all to copy the default syslog file to a new file with the name all. If you don’t have a file with the name syslog, you can pick another file at your convenience.
- Open the file with an editor and make sure it has the following contents:
/var/log/all {
daily
missingok
rotate 1
compress
delaycompress
copytruncate
minsize 100k
} - Notice that you won’t see the changes effective immediately. Logrotate is automatically scheduled through the cron service, and by default runs once a day.
- Use ls -l /var/log/all to look at the current date and time stamp of the file.
- To manually trigger a rotation, type logrotate /etc/logrotate.conf. Notice that it still is unlikely to see any effect, as the file doesn’t meet the criteria for rotation yet.
With the release of systemd, a new logging service has been introduced as well. This is the journald service. Journald is not meant to replace rsyslog, but it is complementary to rsyslog. The main purpose of rsyslog is to log information that is generated by specific events and services and write that information to files in /var/log. Also, rsyslog allows you to set up a central log service in your network.
Journald is used to provide more information about working of services. It provides you with real-time information, which by default is cleared when your machine is restarted. Using journald allows you to query for specific information about services and their current operational state.
The easiest interface to information that is logged by journald, is through the systemctl status command, which you have seen before. This command automatically shows the last five lines that have been logged for a specific systemd unit file. Journald also has the journalctl command, that opens a pager in which you can read recent log messages. The pager is based on the less command, so to see the most recent lines that have been added to the log, use G to go to the bottom of the command output.
The journalctl also has many options to filter specific items out of the log. If the bash-completion package has been installed, you can easily use tab key command completion to work with these options. Listing 10-9 shows what the default options are, as shown by bash command line completion.
Particularly useful in the options listed above, is the _SYSTEMD_UNIT option. Using this option allows you to get the information you need about a specific systemd unit. Use for instance journalctl _SYSTEMD_UNIT=sshd.service to see all that has been logged by the SSH service recently.
EXERCISE 10-3: DISCOVERYIN JOURNALCTL OPTIONS
In this exercise you’ll learn how to work with different journalctl options.
- Type journalctl. You’ll see the contents of the journal since your server last started, starting at the beginning of the journal. The contents is shown in less, so you can use common less commands to walk through the file.
- Type journalctl -f. This opens the live view mode of journalctl, which allows you to see new messages scrolling by in real time. Use Ctrl-C to interrupt.
- Type journalctl -n 20. The -n 20 option displays the last 20 lines of the journal (just like tail -n 20).
- Now type journalctl -p err. This command shows errors only.
- If you want to view journal messages that have been written in a specific time period, you can use the --since and --until commands. Both options take the time parameter in the format YYYY-MM-DD hh:mm:ss. Also, you can use yesterday, today and tomorrow as parameters. So type journalctl --since yesterday to show all messages that have been written since yesterday.
- journalctl allows you to combine different options as well, so if you want to show all messages with a priority err that have been written since yesterday, use journalctl --since yesterday -p err.
- If you need as much detail as possible, use journalctl -o verbose. This shows different options that are used when writing to the journal (see listing 13-3). All of these options can be used to tell the journalctl command which specific information you’re looking for. Type for instance journalctl _SYSTEMD_UNIT=sshd.service to show more information about the sshd systemd unit.
Summary
In this chapter, you’ve learned how to handle logging. First, you’ve learned where you can find the default log files on your system and how you can have a look at them. Next, you’ve learned how to create your own rsyslog or syslog-ng configuration. You have also learned you how to configure log rotation to make sure that your computer’s file system is not filled completely with log files by accident. At the end of this chapter you have read how journald and journalctl add another interface to get relevant information out of the system log files. The following commands have been covered in this chapter:
- rsyslog: Legacy process used for logging files
- syslog-ng: Newer process that offers more clever log services
- tail -f /var/log/messages: The way to see what’s happening in /var/log/messages, the most important log file on your computer
- logger: Useful tool that lets you write messages to syslog
- logrotate: Command that helps you to prevent log files from growing too big and rotate them after a certain amount of time or once a given size has been reached
- journalctl: Versatile command that helps you getting information from the systemd related journald service.
In the next chapter, you’ll learn how to configure networking on your computer.