7.1 System Logging
Most system programs write their diagnostic output as messages to the syslog service. The traditional syslogd daemon performs this service by waiting for messages and, upon receiving one, sending it to an appropriate channel, such as a file or a database. On most contemporary systems, journald (which comes with systemd) does most of the work. Though we’ll concentrate on journald in this book, we’ll also cover many aspects of the traditional syslog.
The system logger is one of the most important parts of the system. When something goes wrong and you don’t know where to start, it’s always wise to check the log. If you have journald, you’ll do this with the journalctl command, which we’ll cover in Section 7.1.2. On older systems, you’ll need to check the files themselves. In either case, log messages look like this:
Aug 19 17:59:48 duplex sshd[484]: Server listening on 0.0.0.0 port 22.
A log message typically contains important information such as the process name, process ID, and timestamp. There can also be two other fields: the facility (a general category) and severity (how urgent the message is). We’ll discuss those in more detail later.
Understanding logging in a Linux system can be somewhat challenging due to varied combinations of older and newer software components. Some distributions, such as Fedora, have moved to a journald-only default, while others run a version of the older syslogd (such as rsyslogd) alongside journald. Older distributions and some specialized systems may not use systemd at all and have only one of the syslogd versions. In addition, some software systems bypass standardized logging altogether and write their own.
7.1.1 Checking Your Log Setup
You should inspect your own system to see what sort of logging is installed. Here’s how:
- Check for journald, which you almost certainly have if you’re running systemd. Although you can look for journald in a process listing, the easiest way is to simply run
journalctl. If journald is active on your system, you’ll get a paged list of log messages. - Check for rsyslogd. Look for rsyslogd in a process listing, and look for /etc/rsyslog.conf.
- If you don’t have rsyslogd, check for syslog-ng (another version of syslogd) by looking for a directory called /etc/syslog-ng.
Continue your tour by looking in /var/log for logfiles. If you have a version of syslogd, this directory should contain many files, most created by your syslog daemon. However, there will be a few files here that are maintained by other services; two examples are wtmp and lastlog, the logfiles that utilities such as last and lastlog access in order to get login records.
In addition, there may be further subdirectories in /var/log containing logs. These nearly always come from other services. One of them, /var/log/journal, is where journald stores its (binary) logfiles.
7.1.2 Searching and Monitoring Logs
Unless you have a system without journald or you’re searching a logfile maintained by some other utility, you’ll look through the journal. With no arguments, the journalctl access tool is like a fire hose, giving you all of the messages in the journal, starting with the oldest (just as they would appear in a logfile). Mercifully, journalctl defaults to using a pager such as less to display messages so your terminal won’t be flooded. You can search messages with the pager and reverse the message time order with journalctl -r, but there are much better ways of finding logs.
To get full access to the journal messages, you need to run journalctl either as root or as a user belonging to the adm or systemd-journal groups. The default user on most distributions has access.
In general, you can search individual fields of journals just by adding them to the command line; for example, run journalctl _PID=8792 to search for messages from process ID 8792. However, the most powerful filtering features are more general in nature. You can specify one or more if you need multiple criteria.
Filtering by Time
The -S (since) option is among the most useful in narrowing in on a specific time. Here’s an example of one of the easiest and most effective ways to use it:
$ journalctl -S -4h
The -4h part of this command may look like an option, but in reality, it’s a time specification telling journalctl to search for messages from the past four hours in your current time zone. You can also use a combination of a specific day and/or time:
$ journalctl -S 06:00:00
$ journalctl -S 2020-01-14
$ journalctl -S '2020-01-14 14:30:00'
The -U (until) option works the same way, specifying a time up to which journalctl should retrieve messages. However, it’s often not as useful because you’ll typically page or search through messages until you find what you need, then just quit.
Filtering by Unit
Another quick and effective way to get at relevant logs is to filter by systemd unit. You can do this with the -u option, like this:
$ journalctl -u cron.service
You can normally omit the unit type (.service in this case) when filtering by unit.
If you don’t know the name of a particular unit, try this command to list all units in the journal:
$ journalctl -F _SYSTEMD_UNIT
The -F option shows all values in the journal for a particular field.
Finding Fields
Sometimes you just need to know which field to search. You can list all available fields as follows:
$ journalctl -N
Any field beginning with an underscore (such as _SYSTEMD_UNIT from the previous example) is a trusted field; the client that sends a message cannot alter these fields.
Filtering by Text
A classic method of searching logfiles is to run grep over all of them, hoping to find a relevant line or spot in a file where there might be more information. Similarly, you can search journal messages by regular expression with the -g option, as in this example, which will return messages containing kernel followed somewhere by memory:
$ journalctl -g 'kernel.*memory'
Unfortunately, when you search the journal this way, you get only the messages that match the expression. Often, important information might be nearby in terms of time. Try to pick out the timestamp from a match, and then run journalctl -S with a time just before to see what messages came around the same time.
The -g option requires a build of journalctl with a particular library. Some distributions do not include a version that supports -g.
Filtering by Boot
Often, you’ll find yourself looking through the logs for messages around the time when a machine booted or just before it went down (and rebooted). It’s very easy to get the messages from just one boot, from when the machine started until it stopped. For example, if you’re looking for the start of the current boot, just use the -b option:
$ journalctl -b
You can also add an offset; for example, to start at the previous boot, use an offset of -1.
$ journalctl -b -1
You can quickly check whether the machine shut down cleanly on the last cycle by combining the -b and -r (reverse) options. Try it; if the output looks like the example here, the shutdown was clean:
$ journalctl -r -b -1
-- Logs begin at Wed 2019-04-03 12:29:31 EDT, end at Fri 2019-08-02 19:10:14
EDT. --
Jul 18 12:19:52 mymachine systemd-journald[602]: Journal stopped
Jul 18 12:19:52 mymachine systemd-shutdown[1]: Sending SIGTERM to remaining
processes...
Jul 18 12:19:51 mymachine systemd-shutdown[1]: Syncing filesystems and block
devices.
Instead of an offset like -1, you can also view boots by IDs. Run the following to get the boot IDs:
$ journalctl --list-boots
-1 e598bd09e5c046838012ba61075dccbb Fri 2019-03-22 17:20:01 EDT—Fri 2019-04-12
08:13:52 EDT
0 5696e69b1c0b42d58b9c57c31d8c89cc Fri 2019-04-12 08:15:39 EDT—Fri 2019-08-02
19:17:01 EDT
Finally, you can display kernel messages (with or without selecting a particular boot) with journalctl -k.
Filtering by Severity/Priority
Some programs produce a large number of diagnostic messages that can obscure important logs. You can filter by the severity level by specifying a value between 0 (most important) and 7 (least important) alongside the -p option. For example, to get the logs from levels 0 through 3, run:
$ journalctl -p 3
If you want only the logs from a specific set of severity levels, use the .. range syntax:
$ journalctl -p 2..3
Filtering by severity sounds like it may save a lot of time, but you might not find much use for it. Most applications don’t generate large amounts of informational data by default, though some include configuration options to enable more verbose logging.
Simple Log Monitoring
One traditional way to monitor logs is to use tail -f or the less follow mode (less +F) on a logfile to see messages as they arrive from the system logger. This isn’t a very effective regular system monitoring practice (it’s too easy to miss something), but it’s useful for examining a service when you’re trying to find a problem, or get a closer look at startup and operation in real time.
Using tail -f doesn’t work with journald because it doesn’t use plaintext files; instead, you can use the -f option to journalctl to produce the same effect of printing logs as they arrive:
$ journalctl -f
This simple invocation is good enough for most needs. However, you may want to add some of the preceding filtering options if your system has a fairly constant stream of log messages not related to what you’re looking for.
7.1.3 Logfile Rotation
When you’re using a syslog daemon, any log message that your system records goes into a logfile somewhere, which means you need to delete old messages occasionally so that they don’t eventually consume all of your storage space. Different distributions do this in different ways, but most use the logrotate utility.
The mechanism is called log rotation. Because a traditional text logfile contains the oldest messages at the beginning and the newest at the end, it’s quite difficult to remove just the older messages from a file to free up some space. Instead, a log maintained by logrotate is divided into many chunks.
Say you have a logfile called auth.log in /var/log containing the most recent log messages. Then there’s an auth.log.1, auth.log.2, and auth.log.3, each with progressively older data. When logrotate decides that it’s time to delete some old data, it “rotates” the files like this:
- Removes the oldest file, auth.log.3.
- Renames auth.log.2 to auth.log.3.
- Renames auth.log.1 to auth.log.2.
- Renames auth.log to auth.log.1.
The names and some details vary across distributions. For example, the Ubuntu configuration specifies that logrotate should compress the file that’s moved from the “1” position to the “2” position, so in the previous example, you would have auth.log.2.gz and auth.log.3.gz. In other distributions, logrotate renames the logfiles with a date suffix, such as -20200529. One advantage of this scheme is that it’s easier to find a logfile from a specific time.
You might be wondering what happens if logrotate performs a rotation around the same time that another utility (such as rsyslogd) wants to add to the logfile. For example, say the logging program opens the logfile for writing but doesn’t close it before logrotate performs the rename. In this somewhat unusual scenario, the log message would be written successfully, because in Linux, once a file is open, the I/O system has no way to know it was renamed. But note that the file the message appears in will be the file with the new name, such as auth.log.1.
If logrotate has already renamed the file before the logging program attempts to open it, the open() system call creates a new logfile (such as auth.log), just as it would if logrotate weren’t running.
7.1.4 Journal Maintenance
The journals stored in /var/log/journal don’t need rotation, because journald itself can identify and remove old messages. Unlike traditional log management, journald normally decides to delete messages based on how much space is left on the journal’s filesystem, how much space the journal should take as a percentage of the filesystem, and what the maximum journal size is set to. There are other options for log management, such as the maximum allowed age of a log message. You’ll find a description of the defaults as well as the other settings in the journald.conf(5) manual page.
7.1.5 A Closer Look at System Logging
Now that you’ve seen some of the operational details of syslog and the journal, it’s time to step back a bit and look at the reasons why and how logging works the way it does. This discussion is more theoretical than hands-on; you can skip to the next topic in the book without a problem.
In the 1980s, a gap was starting to emerge: Unix servers needed a way to record diagnostic information, but there was no standard for doing so. p. 174 When syslog appeared with the sendmail email server, it made enough sense that developers of other services readily adopted it. RFC 3164 describes the evolution of syslog.
The mechanism is fairly simple. A traditional syslogd listens and waits for messages on Unix domain socket /dev/log. One additional powerful feature of syslogd is the ability to listen on a network socket in addition to /dev/log, enabling client machines to send messages across a network.
This makes it possible to consolidate all syslog messages from an entire network onto one logging server, and for this reason, syslog became very popular with network administrators. Many network devices, such as routers and embedded devices, can act as syslog clients, sending their diagnostic messages to a server.
Syslog has a classic client-server architecture, including its own protocol (currently defined in RFC 5424). However, the protocol wasn’t always standard, and earlier versions didn’t accommodate much structure beyond some basics. Programmers using syslog were expected to come up with a descriptive, yet clear and brief, log message format for their own applications. Over time, the protocol added new features while still trying to maintain as much backward compatibility as possible.
Facility, Severity, and Other Fields
Because syslog sends messages of various types from different services to different destinations, it needs a way to classify each message. The traditional method is to use encoded values of facility and severity that were usually (but not always) included in a message. In addition to file output, even very old versions of syslogd were capable of sending important messages to consoles and directly to particular logged-in users based on the messages’ facility and severity—an early tool for system monitoring.
The facility is a general category of service, identifying what sent the message. Facilities include services and system components such as kernel, mail system, and printer.
The severity is the urgency of the log message. There are eight levels, numbered 0 through 7. They’re usually referred to by name, although the names aren’t very consistent and have varied across implementations:
0: emerg 4: warning
1: alert 5: notice
2: crit 6: info
3: err 7: debug
The facility and severity together make up the priority, packaged as one number in the syslog protocol. You can read all about these fields in RFC 5424, learn how to specify them in applications in the syslog(3) manual page, and learn how to match them in the rsyslog.conf(5) manual page. p. 175 However, you might run into some confusion when translating them to the journald world, where the severity is referred to as the priority (for example, when you run journalctl -o json to get machine-readable log output).
Unfortunately, when you start to examine the details of the priority part of the protocol, you’ll find that it hasn’t kept pace with changes and requirements in the rest of the OS. The severity definition still holds up well, but the available facilities are hardwired and include seldom-used services such as UUCP, with no way to define new ones (only a number of generic local0 through local7 slots).
We’ve already talked about some of the other fields in log data, but RFC 5424 also includes a provision for structured data, sets of arbitrary key-value pairs that application programmers can use to define their own fields. Though these can be used with journald with some extra work, it’s much more common to send them to other kinds of databases.
The Relationship Between Syslog and journald
The fact that journald has completely displaced syslog on some systems might have you asking why syslog remains on others. There are two main reasons:
- Syslog has a well-defined means of aggregating logs across many machines. It is much easier to monitor logs when they are on just one machine.
- Versions of syslog such as rsyslogd are modular and capable of output to many different formats and databases (including the journal format). This makes it easier to connect them to analysis and monitoring tools.
By contrast, journald emphasizes collecting and organizing the log output of a single machine into a single format.
When you want to do something more complicated, journald’s capability of feeding its logs into a different logger offers a high degree of versatility. This is especially true when you consider that systemd can collect the output of server units and send them to journald, giving you access to even more log data than what applications send to syslog.
Final Notes on Logging
Logging on Linux systems has changed significantly during its history, and it’s a near-certainty that it will continue to evolve. At the moment, the process of collecting, storing, and retrieving logs on a single machine is well defined, but there are other aspects of logging that aren’t standardized.
First, there’s a dizzying array of options available when you want to aggregate and store logs over a network of machines. Instead of a centralized log server simply storing logs in text files, the logs can now go into databases, and often the centralized server itself is replaced by an internet service.
Next, the nature of how logs are consumed has changed. At one time, logs were not considered to be “real” data; their primary purpose was a resource that the (human) administrator could read when something went wrong. However, as applications have become more complex, logging needs have grown. These new requirements include the capability to search, extract, display, and analyze the data inside the logs. Although we have many ways of storing logs in databases, tools to use the logs in applications are still in their infancy.
Finally, there’s the matter of ensuring that the logs are trustworthy. The original syslog had no authentication to speak of; you simply trusted that whatever application and/or machine sending the log was telling the truth. In addition, the logs were not encrypted, making them vulnerable to snooping on the network. This was a serious risk in networks that required high security. Contemporary syslog servers have standard methods of encrypting a log message and authenticating the machine where it originates. However, when you get down to individual applications, the picture becomes less clear. For example, how can you be sure that the thing that calls itself your web server actually is the web server?
We’ll explore a few somewhat advanced authentication topics later in the chapter. But for now, let’s move on to the basics of how configuration files are organized on the system.