108.2 System logging

Weight: 4

Candidates should be able to configure rsyslog. This objective also includes configuring the logging daemon to send log output to a central log server or accept log output as a central log server. Use of the systemd journal subsystem is covered. Also, awareness of syslog and syslog-ng as alternative logging systems is included.

Objectives

• Basic configuration of rsyslog.
• Understanding of standard facilities, priorities and actions.
• Query the systemd journal.
• Filter systemd journal data by criteria such as date, service or priority.
• Configure persistent systemd journal storage and journal size.
• Delete old systemd journal data.
• Retrieve systemd journal data from a rescue system or file system copy.
• Understand interaction of rsyslog with systemd-journald.
• Configuration of logrotate.
• Awareness of syslog and syslog-ng.

Terms

/etc/rsyslog.conf, /var/log/, logger, logrotate, /etc/logrotate.conf, /etc/logrotate.d/, journalctl, systemd-cat, /etc/systemd/journald.conf, /var/log/journal/

How logging works

Logs are files where the system writes down what happens, in time order, from the moment it boots. Failed logins, service errors, a disk that disappeared, a cron job that ran: it all ends up in a log. When something breaks, the logs are the first place to look.

If every program handled its own logs, each one would invent its own format and its own location, and you could never keep them under control. So Unix uses a central logging service: programs hand their messages to one daemon, and that daemon decides where each message goes.

There have been three classic logging daemons, and you need to know their names:

• syslog, the original.
• syslog-ng, "syslog new generation".
• rsyslog, "the rocket-fast system for log processing". It became the most popular and is the one you configure on the exam.

All three write text files, normally under /var/log/, so you read them with ordinary tools like less, grep and tail. Today most distributions also run the systemd logger, systemd-journald. It keeps its logs in binary files that you read with journalctl. The two usually run side by side, and you will learn both.

This is how a message becomes a log line:

   kernel           services            your scripts
      |                 |                  (logger)
      v                 v                     v
  /dev/kmsg         /dev/log  (special socket files)
      \                 |                    /
       +-------------- rsyslogd ------------+
                           |
      reads its rules in /etc/rsyslog.conf and /etc/rsyslog.d/
                           |
       +-------------------+--------------------+
       v                   v                    v
  /var/log/<file>    logged-in users     a central log server

1. Applications, services and the kernel write their messages into special files, such as /dev/log (a socket) or /dev/kmsg.
2. rsyslogd reads the messages from there.
3. Its rules decide where each message goes: usually a file in /var/log/, sometimes a user's screen or another machine.

Kernel messages are handled by a separate daemon, klogd, which works together with rsyslogd. Because it is separate, klogd can still record a kernel crash even when everything else has fallen over.

The kernel ring buffer: dmesg

The kernel prints many messages early in boot, before rsyslogd is running and before the disks are even ready. It keeps them in memory, in the kernel ring buffer. The buffer has a fixed size, so when it fills up, the oldest messages disappear to make room for new ones.

dmesg prints the ring buffer. The output is long, so you usually filter it with grep. For example, to see what the kernel said about USB devices:

root@debian:~# dmesg | grep "usb"
[    1.241182] usbcore: registered new interface driver usbfs
[    1.241188] usbcore: registered new interface driver hub
[    1.250968] usbcore: registered new device driver usb
[    1.339754] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 4.19
[    1.339756] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1

The number in brackets is the time in seconds since the kernel started. The last lines often show what just happened:

$ dmesg | tail
[    3.221093] usb 1-1: new high-speed USB device number 2
[    5.882014] EXT4-fs (sda1): mounted filesystem with ordered data mode

Log rotation with logrotate

Logs grow forever unless something trims them. Log rotation does two jobs: it stops old logs from filling the disk, and it keeps each file a manageable size so you can actually read it. The tool for this is logrotate.

The usual naming is a number added to the end of the file. Here is a log after a few weeks:

root@debian:~# ls /var/log/messages*
/var/log/messages  /var/log/messages.1  /var/log/messages.2.gz  /var/log/messages.3.gz  /var/log/messages.4.gz

At the next rotation, every file moves down one place:

messages.4.gz   -> deleted
messages.3.gz   -> messages.4.gz
messages.2.gz   -> messages.3.gz
messages.1      -> messages.2.gz   (compressed now)
messages        -> messages.1      (messages starts again, empty)

So last week's messages are in messages.1, the week before in messages.2.gz, and so on. Read the compressed ones with zless, zcat or zgrep without unpacking them first.

logrotate is not a daemon. Cron runs it once a day through the script /etc/cron.daily/logrotate, and it reads its main configuration from /etc/logrotate.conf:

root@debian:~# cat /etc/logrotate.conf
# see "man logrotate" for details

# global options do not affect preceding include directives

# rotate log files weekly
weekly

# keep 4 weeks worth of backlogs
rotate 4

# create new (empty) log files after rotating old ones
create

# use date as a suffix of the rotated file
#dateext

# uncomment this if you want your log files compressed
#compress

# packages drop log rotation information into this directory
include /etc/logrotate.d

# system-specific logs may also be configured here.

The last important line is include /etc/logrotate.d. Each package drops its own rules into that directory. Rules there are local, and local definitions take precedence over global ones. This is the rule that rsyslog installs for one of its logs:

root@debian:~# cat /etc/logrotate.d/rsyslog
/var/log/messages
{
        rotate 4
        weekly
        missingok
        notifempty
        compress
        delaycompress
        sharedscripts
        postrotate
                invoke-rc.d rsyslog rotate > /dev/null
        endscript
}

Another package rule, for apt:

# /etc/logrotate.d/apt
/var/log/apt/term.log {
  rotate 12
  monthly
  compress
  missingok      # no error if the log is absent
  notifempty     # skip rotation if the log is empty
}

What each directive means:

Directive	Meaning
weekly, monthly	how often to rotate
rotate 4 (rotate N)	keep 4 (N) old files, delete anything older
missingok	if the log file is missing, do not complain, move on
notifempty	do not rotate the log if it is empty
compress	compress rotated files with gzip
delaycompress	wait one cycle before compressing, so the newest old file stays plain text (useful when a program keeps writing to the old file for a while)
create 0640 www-data adm (create MODE OWNER GROUP)	after rotating, create a new empty log with this mode, owner and group
sharedscripts	run the scripts once, even when the rule matches many files (like /var/log/mail/*)
postrotate ... endscript	commands to run after rotating, usually telling the service to reopen its log (prerotate runs before)

That explains the listing above: rotate 4 plus compress with delaycompress gives you messages.1 in plain text and older files as .gz.

Log files in /var/log

Logs are variable data, so they live in /var/log/. When something goes wrong and you do not know where to start, list that directory sorted by time:

root@debian:~# ls -ltrh /var/log/

The newest files are at the bottom, so you see at once which program just wrote something.

The system logs to know (names from Debian; other distributions may differ a little):

File	Holds
/var/log/auth.log	authentication: logins, sudo, cron jobs, failed login attempts
/var/log/syslog	almost everything rsyslogd receives, when no more specific file is set
/var/log/messages	informative messages from services (not the kernel). On a central log server, also the default place for logs from remote clients
/var/log/kern.log	kernel messages
/var/log/daemon.log	background services (daemons)
/var/log/debug	debug information from programs
/var/log/mail.log	the mail server, for example postfix
/var/log/Xorg.0.log	the graphics card and the X server
/var/run/utmp, /var/log/wtmp	successful logins (read with last, who)
/var/log/boot.log	messages from the boot process
/var/log/btmp	failed logins, for example someone guessing passwords over ssh (read with lastb)
/var/log/faillog	failed authentication attempts (read with faillog)
/var/log/lastlog	date and time of each user's most recent login

Distributions add their own, such as /var/log/dpkg.log on Debian for package installs.

Some services keep their own logs in their own directory:

Directory	Service	Typical files
/var/log/cups/	the CUPS printing system	access_log, error_log, page_log
/var/log/apache2/ or /var/log/httpd/	the Apache web server	access.log, error_log
/var/log/mysql/	the MySQL database	error_log, mysql.log, mysql-slow.log
/var/log/samba/	Samba (Windows file sharing)	log.nmbd, log.smbd

Reading logs

Most log files belong to root, so read them as root or with sudo. The usual tools:

Tool	Use
less, more	scroll through a log one page at a time
zless, zmore	the same, for logs compressed with gzip by logrotate
tail	the last 10 lines. tail -f keeps the file open and prints new lines as they arrive
head	the first 10 lines, or head -5 for 5
grep	only the lines that contain a word

tail -f is the one you will use most. Run it in one terminal while you test something in another:

root@debian:~# tail -f /var/log/messages

grep pulls out one program's messages:

root@debian:~# grep "dhclient" /var/log/syslog
Sep 13 11:58:48 debian dhclient[448]: DHCPREQUEST of 192.168.1.4 on enp0s3 to 192.168.1.1 port 67
Sep 13 11:58:49 debian dhclient[448]: DHCPACK of 192.168.1.4 from 192.168.1.1
Sep 13 11:58:49 debian dhclient[448]: bound to 192.168.1.4 -- renewal in 1368 seconds.

Every line has the same parts:

Sep 13 11:58:49  debian    dhclient  [448]  DHCPACK of 192.168.1.4 from 192.168.1.1
     |              |          |        |                 |
 timestamp      hostname    program    PID          the message

A few logs are binary, not text, so less shows garbage. Each has its own reader:

Log	Read it with
/var/log/wtmp	who or w
/var/log/btmp	utmpdump /var/log/btmp or last -f /var/log/btmp
/var/log/faillog	faillog -a
/var/log/lastlog	lastlog

root@debian:~# who
root     pts/0        2020-09-14 13:05 (192.168.1.75)
root     pts/1        2020-09-14 13:43 (192.168.1.75)

root@debian:~# utmpdump /var/log/btmp
Utmp dump of /var/log/btmp
[6] [01287] [    ] [dave    ] [ssh:notty    ] [192.168.1.75    ] [192.168.1.75    ] [2019-09-07T19:33:32,000000+0000]

root@debian:~# lastlog | less
Username         Port     From             Latest
root                                       Never logged in
daemon                                     Never logged in
carol            pts/1    192.168.1.75     Sat Sep 14 13:43:06 +0200 2019
dave             pts/3    192.168.1.75     Mon Sep  2 14:22:08 +0200 2019

The btmp line says that user dave failed to log in over ssh from 192.168.1.75. Many lines like that from one address usually mean someone is guessing passwords.

rsyslog configuration

The main file is /etc/rsyslog.conf. rsyslog also reads every *.conf file in /etc/rsyslog.d/. The file has three sections.

MODULES loads extra features. imuxsock collects local messages and imklog collects kernel messages. The imudp and imtcp lines, commented out by default, are what let rsyslog receive logs from other machines on port 514:

#################
#### MODULES ####
#################

module(load="imuxsock") # provides support for local system logging
module(load="imklog")   # provides kernel logging support
#module(load="immark")  # provides --MARK-- message capability

# provides UDP syslog reception
#module(load="imudp")
#input(type="imudp" port="514")

# provides TCP syslog reception
#module(load="imtcp")
#input(type="imtcp" port="514")

GLOBAL DIRECTIVES sets general things, such as the owner and permissions of new log files, and the line that includes /etc/rsyslog.d/:

###########################
#### GLOBAL DIRECTIVES ####
###########################

#
# Set the default permissions for all log files.
#
$FileOwner root
$FileGroup adm
$FileCreateMode 0640
$DirCreateMode 0755
$Umask 0022

#
# Where to place spool and state files
#
$WorkDirectory /var/spool/rsyslog

#
# Include all config files in /etc/rsyslog.d/
#
$IncludeConfig /etc/rsyslog.d/*.conf

RULES is the important part. Each rule says which messages to pick and what to do with them:

###############
#### RULES ####
###############

auth,authpriv.*          /var/log/auth.log
*.*;auth,authpriv.none   -/var/log/syslog
#cron.*                  /var/log/cron.log
daemon.*                 -/var/log/daemon.log
kern.*                   -/var/log/kern.log
lpr.*                    -/var/log/lpr.log
mail.*                   -/var/log/mail.log
user.*                   -/var/log/user.log

mail.info                -/var/log/mail.info
mail.warn                -/var/log/mail.warn
mail.err                 /var/log/mail.err

*.=debug;\
        auth,authpriv.none;\
        news.none;mail.none     -/var/log/debug

*.emerg                  :omusrmsg:*

A rule has this shape:

facility.priority     action
\_______________/
     selector

Facilities

The facility says which part of the system the message came from. Each has a keyword and a number:

Number	Keyword	Source
0	kern	the Linux kernel
1	user	user programs
2	mail	the mail system
3	daemon	system daemons
4, 10	auth, authpriv	security and authorization
5	syslog	rsyslogd itself
6	lpr	the printing system
7	news	network news
8	uucp	UUCP (Unix-to-Unix Copy)
9, 15	cron	the clock daemon (cron)
11	ftp	the FTP server
12	ntp	the NTP time server
13	security	log audit
14	console	log alert
16 to 23	local0 to local7	free for your own use

Priorities

The priority (also called severity) says how important the message is. In increasing order:

debug  info  notice  warning  err  crit  alert  emerg

The table goes from most to least important:

Code	Keyword	Meaning
0	emerg (old name panic)	the system is unusable
1	alert	action must be taken immediately
2	crit	critical conditions
3	err (old name error)	error conditions
4	warning (old name warn)	warning conditions
5	notice	normal, but worth noticing
6	info	informational
7	debug	debug details

A priority also selects everything more important than itself. This catches people in the exam. cron.notice does not mean "only notice". It means notice, warning, err, crit, alert and emerg.

Reading a selector

You write	It means
*	any facility, or any priority
mail.err	mail messages at err or higher
local3.=alert	the = means only this priority, nothing higher
auth,authpriv.*	a comma joins facilities that share one priority
*.*;auth,authpriv.none	a semicolon joins selectors. .none excludes a facility
\ at the end of a line	the rule continues on the next line

Actions

The action says what to do with the matching messages:

Action	Example	Result
a file	/var/log/auth.log	write the message to that file
a file with -	-/var/log/syslog	the same, but do not force each line to disk at once (fewer disk writes)
a user name	carol	show the message on that user's screen, if logged in
all users	:omusrmsg:*	show it to everyone who is logged in
@ or @@ and a host	@192.168.1.100	send the message to a remote log server, which decides where to store it

Two more examples:

kern.panic   @192.168.1.100     # send kernel panics to a central log server
*.*          /var/log/messages  # everything, every level, to one file
cron.*              -/var/log/cron.log
local3.=alert /var/log/alert.log

Now you can read the rules above line by line:

• auth,authpriv.* /var/log/auth.log: every auth and authpriv message, at any priority, goes to auth.log.
• *.*;auth,authpriv.none -/var/log/syslog: everything from every facility goes to syslog, except auth and authpriv (they hold private data).
• mail.err /var/log/mail.err: mail messages at err, crit, alert or emerg.
• *.=debug;... -/var/log/debug: debug messages only, from every facility except auth, authpriv, news and mail.
• *.emerg :omusrmsg:*: an emergency from anywhere is shown on every logged-in user's screen.

After you change /etc/rsyslog.conf, restart the daemon so it reads the new rules:

root@debian:~# systemctl restart rsyslog

logger: write to the log yourself

logger sends a message into the logging system from the command line. It is handy in scripts, and for testing whether a new rule works. The message goes to /var/log/syslog:

carol@debian:~$ logger this comment goes into "/var/log/syslog"
carol@debian:~$ tail -1 /var/log/syslog
Sep 17 17:55:33 debian carol: this comment goes into /var/log/syslog

A priority can be set with -p:

# logger Testing my tool
# logger -p local1.emerg "Nothing emergency for sure"
# tail -1 /var/log/syslog
2023-06-30T06:13:27 debian root: Testing my tool

-t adds a tag in place of your user name, so your messages are easy to find. You will see it at work in the central log server test below.

rsyslog as a central log server

With many servers, you do not want to log in to each one to read its logs. Instead, every machine sends its logs to one central log server. This example uses two machines:

   client                                   central log server
   debian, 192.168.1.4                      suse-server, 192.168.1.6

   rule: *.* @@suse-server:514 ------TCP port 514-----> imtcp module listening
                                                        logs go to /var/log/messages,
                                                        or to the template you choose

On the server

Make sure rsyslog is running:

root@suse-server:~# systemctl status rsyslog
● rsyslog.service - System Logging Service
   Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2019-09-17 18:45:58 CEST; 7min ago
     Docs: man:rsyslogd(8)
           http://www.rsyslog.com/doc/
 Main PID: 832 (rsyslogd)
    Tasks: 5 (limit: 4915)
   CGroup: /system.slice/rsyslog.service
           └─832 /usr/sbin/rsyslogd -n -iNONE

Turn on receiving. openSUSE keeps this in /etc/rsyslog.d/remote.conf. On other systems, uncomment the imtcp or imudp lines in /etc/rsyslog.conf. Uncomment the lines that load the TCP module and start the TCP server on port 514:

# ######### Receiving Messages from Remote Hosts ##########
# TCP Syslog Server:
# provides TCP syslog reception and GSS-API (if compiled to support it)
$ModLoad imtcp.so                # load module
##$UDPServerAddress 10.10.0.1    # force to listen on this IP only
$InputTCPServerRun 514           # Starts a TCP server on selected port

# UDP Syslog Server:
#$ModLoad imudp.so               # provides UDP syslog reception
##$UDPServerAddress 10.10.0.1    # force to listen on this IP only
#$UDPServerRun 514               # start a UDP syslog server at standard port 514

Restart rsyslog and check that it now listens on port 514:

root@suse-server:~# systemctl restart rsyslog
root@suse-server:~# netstat -nltp | grep 514
tcp        0      0 0.0.0.0:514     0.0.0.0:*     LISTEN      2263/rsyslogd
tcp6       0      0 :::514          :::*          LISTEN      2263/rsyslogd

Open the port in the firewall:

root@suse-server:~# firewall-cmd --permanent --add-port 514/tcp
success
root@suse-server:~# firewall-cmd --reload
success

By default, the clients' logs land in the server's /var/log/messages, mixed with the server's own messages. To give each client its own directory, add a template and a filter to the configuration:

$template RemoteLogs,"/var/log/remotehosts/%HOSTNAME%/%$NOW%.%syslogseverity-text%.log"
if $FROMHOST-IP=='192.168.1.4' then ?RemoteLogs
& stop

• The template named RemoteLogs builds the file name from the message. The words between % signs are properties: %HOSTNAME% is the client's name, %$NOW% is today's date, and %syslogseverity-text% is the priority as a word. So each client gets a directory, and each priority gets its own file per day.
• The filter checks the sender's IP address. If it is the client, the message is written using the template.
• & stop stops there, so the message is not also copied to /var/log/messages.

Restart rsyslog again on the server.

On the client

The client needs only one line, added at the end of /etc/rsyslog.conf: send everything to the server on port 514. Here @@ is used because the server listens on TCP. The client can find suse-server by name because the line 192.168.1.6 suse-server was added to its /etc/hosts:

*.* @@suse-server:514

Then restart rsyslog on the client:

root@debian:~# systemctl restart rsyslog

Test it

On the server, the new directory appears with one file per priority:

root@suse-server:~# ls /var/log/remotehosts/debian/
2019-09-17.info.log   2019-09-17.notice.log

Watch one of them on the server while you send a test message from the client:

carol@debian:~$ logger -t DEBIAN-CLIENT Hi from 192.168.1.4

root@suse-server:~# tail -f /var/log/remotehosts/debian/2019-09-17.notice.log
2019-09-17T21:01:41+02:00 debian anacron[1766]: Anacron 2.3 started on 2019-09-17
2019-09-17T21:01:41+02:00 debian anacron[1766]: Normal exit (0 jobs run)
2019-09-17T21:04:21+02:00 debian DEBIAN-CLIENT: Hi from 192.168.1.4

The client's message arrived on the server.

The systemd journal: journald

On systemd systems, the logging service is systemd-journald. It collects messages from many places: the kernel, system services, the standard output and standard error of every service, and the kernel audit system. It stores them in one structured, indexed journal. Compared to text logs, the journal:

• keeps all logs in one place,
• does not need logrotate (it manages its own size),
• can be turned off, kept in memory only, or kept on disk.

The journal is binary. less and grep cannot read it directly. You read it with journalctl.

systemd-journald is a normal service, so systemctl shows its status:

root@debian:~# systemctl status systemd-journald
● systemd-journald.service - Journal Service
     Loaded: loaded (/lib/systemd/system/systemd-journald.service; static)
     Active: active (running) since Fri 2023-06-30 05:28:50 EDT; 52min ago
TriggeredBy: ● systemd-journald-dev-log.socket
             ● systemd-journald-audit.socket
             ● systemd-journald.socket
       Docs: man:systemd-journald.service(8)
             man:journald.conf(5)
   Main PID: 261 (systemd-journal)
     Status: "Processing requests..."
     CGroup: /system.slice/systemd-journald.service
             └─261 /lib/systemd/systemd-journald

Its configuration file is /etc/systemd/journald.conf. Every line is commented out at first: what you see are the built-in defaults. To change one, remove the #, set the value, and restart the service. These are the lines that matter for the exam:

[Journal]
#Storage=auto
#Compress=yes
#SystemMaxUse=
#SystemKeepFree=
#SystemMaxFileSize=
#SystemMaxFiles=100
#RuntimeMaxUse=
#RuntimeKeepFree=
#RuntimeMaxFileSize=
#RuntimeMaxFiles=100
#MaxRetentionSec=
#MaxFileSec=1month
#ForwardToSyslog=yes
#ForwardToKMsg=no
#ForwardToConsole=no
#ForwardToWall=yes

You can also put settings in drop-in files, /etc/systemd/journald.conf.d/*.conf.

Querying the journal

You need to be root (or use sudo) to see the whole journal. With no options, journalctl prints everything, oldest first, through a pager:

root@debian:~# journalctl
-- Logs begin at Sat 2019-10-12 13:43:06 CEST, end at Sat 2019-10-12 14:19:46 CEST. --
Oct 12 13:43:06 debian kernel: Linux version 4.9.0-9-amd64 (debian-kernel@lists.debian.org)
Oct 12 13:43:06 debian kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-4.9.0-9-amd64 root=UUID=b6be6117-5226-4a8a-bade-2db35ccf4cf4 ro quiet
(...)

That is far too much, so you add options:

Option	Shows
-r	reverse order, newest first
-f	the newest entries, then keeps printing new ones as they arrive, like tail -f
-e	jumps to the end of the journal inside the pager
-n 5, --lines=5	only the 5 newest lines (10 if you give no number)
-k, --dmesg	only kernel messages, the same as dmesg

root@debian:~# journalctl -n 3
Oct 12 14:45:57 debian sudo[1375]: pam_unix(sudo:session): session closed for user root
Oct 12 14:48:39 debian sudo[1378]:    carol : TTY=pts/0 ; PWD=/home/carol ; USER=root ; COMMAND=/bin/journalctl -e
Oct 12 14:48:39 debian sudo[1378]: pam_unix(sudo:session): session opened for user root by carol(uid=0)

Inside the pager you move like in less:

Key	Action
PageUp, PageDown, arrows	move around
>	go to the end
<	go to the beginning
/word then Enter	search forward
?word then Enter	search backward
n, N	next match, previous match

Filtering the journal

The real power of the journal is filtering. You can filter by boot, priority, time, program, unit or field, and you can combine filters.

By boot

--list-boots lists the boots the journal knows about. 0 is the current boot, -1 the one before, -2 the one before that:

root@debian:~# journalctl --list-boots
 0 83df3e8653474ea5aed19b41cdb45b78 Sat 2019-10-12 18:55:41 CEST—Sat 2019-10-12 19:02:24 CEST

-b shows only the current boot. -b -1 shows the previous boot. That only works if the journal is kept on disk, because a journal in memory is lost at every reboot:

root@debian:~# journalctl -b -1
Specifying boot ID has no effect, no persistent journal was found

By priority

-p uses the same priorities as rsyslog, and also includes everything more important:

root@debian:~# journalctl -b -0 -p err
-- No entries --

No messages at err or higher since this boot. Good news. (-b -0 is the current boot, so you can leave it out.)

By time

--since and --until take a date and time as YYYY-MM-DD HH:MM:SS. Leave out the time and midnight is used. Leave out the date and today is used:

root@debian:~# journalctl --since "19:00:00" --until "19:01:00"
-- Logs begin at Sat 2019-10-12 18:55:41 CEST, end at Sat 2019-10-12 20:10:50 CEST. --
Oct 12 19:00:14 debian systemd[1]: Started Run anacron jobs.
Oct 12 19:00:14 debian anacron[1057]: Anacron 2.3 started on 2019-10-12
Oct 12 19:00:14 debian anacron[1057]: Normal exit (0 jobs run)

You can also use relative times and keywords:

You write	It means
--since "2 minutes ago"	from two minutes ago until now
--since "-2 minutes"	the same thing
--since "10 minutes ago"	the last ten minutes
yesterday (as in --since yesterday)	midnight at the start of yesterday
today	midnight at the start of today
tomorrow	midnight at the start of tomorrow
now	this moment

root@debian:~# journalctl --since "today" --until "21:00:00"

By program

Give the full path of the program:

root@debian:~# journalctl /usr/sbin/sshd
-- Logs begin at Sat 2019-10-12 20:45:29 CEST, end at Sat 2019-10-12 21:54:49 CEST. --
Oct 12 21:16:28 debian sshd[1569]: Accepted password for carol from 192.168.1.65 port 34050 ssh2
Oct 12 21:16:28 debian sshd[1569]: pam_unix(sshd:session): session opened for user carol by (uid=0)

By unit

A unit is anything systemd manages, such as a service. -u shows the messages of one unit:

root@debian:~# journalctl -u ssh.service
-- Logs begin at Sun 2019-10-13 10:50:59 CEST, end at Sun 2019-10-13 12:22:59 CEST. --
Oct 13 10:51:00 debian systemd[1]: Starting OpenBSD Secure Shell server...
Oct 13 10:51:00 debian sshd[409]: Server listening on 0.0.0.0 port 22.
Oct 13 10:51:00 debian sshd[409]: Server listening on :: port 22.

systemctl list-units shows the units that are loaded, which helps you find the right name.

By field

Every journal entry carries fields, and you can filter on them with FIELD=value:

Field	Matches	Example
PRIORITY=	one priority, as a number from 0 to 7	journalctl PRIORITY=3 for err messages
SYSLOG_FACILITY=	facility as a number	journalctl SYSLOG_FACILITY=1 for user messages
_PID=	one process ID	journalctl _PID=1 for messages from systemd
_BOOT_ID=	one boot	journalctl _BOOT_ID=83df3e8653474ea5aed19b41cdb45b78
_TRANSPORT=	how the message arrived: kernel, syslog, journal, stdout, audit, driver	journalctl _TRANSPORT=kernel

root@debian:~# journalctl PRIORITY=3
-- Logs begin at Sun 2019-10-13 10:50:59 CEST, end at Sun 2019-10-13 14:30:50 CEST. --
Oct 13 10:51:00 debian avahi-daemon[314]: chroot.c: open() failed: No such file or directory

Combining filters

Different fields combine with AND. Only entries that match both are shown:

root@debian:~# journalctl PRIORITY=3 SYSLOG_FACILITY=0
-- No entries --

A + between them turns it into OR:

root@debian:~# journalctl PRIORITY=3 + SYSLOG_FACILITY=0

The same field given twice is also OR. This shows priority 1 and priority 3:

root@debian:~# journalctl PRIORITY=1 PRIORITY=3

You can mix options in one command too. A real-world check after a service fails: errors from ssh in the last hour.

root@debian:~# journalctl -u ssh.service -p err --since "1 hour ago"
$ journalctl -u ssh -p err --since "1 hour ago"
$ journalctl -b -n 50                           # this boot, last 50 lines (-n N)

systemd-cat: write to the journal yourself

systemd-cat is the journal's version of logger. It sends text to the journal in three ways:

carol@debian:~$ systemd-cat
This line goes into the journal.
^C
carol@debian:~$ echo "And so does this line." | systemd-cat
carol@debian:~$ systemd-cat echo "And so does this line too."
carol@debian:~$ systemd-cat -p emerg echo "This is not a real emergency."
# echo "This is my first test" | systemd-cat
# systemd-cat -p info uptime      # run uptime, log its output at info priority

1. With no arguments, it sends what you type until you press Ctrl+C.
2. With a pipe, it sends the output of the command before it.
3. With a command after it, it runs the command and sends its output (and errors).

-p sets the priority. Check the result:

carol@debian:~$ journalctl -n 4
Nov 13 23:14:39 debian cat[1997]: This line goes into the journal.
Nov 13 23:19:16 debian cat[2027]: And so does this line.
Nov 13 23:23:21 debian echo[2030]: And so does this line too.
Nov 13 23:26:48 debian echo[2034]: This is not a real emergency.

On most terminals, the emergency line is printed in bold red.

Journal storage: memory or disk

The journal can be stored in three ways:

Where	Directory	After a reboot
in memory (volatile)	/run/log/journal/<machine-id>/	lost
on disk (persistent)	/var/log/journal/<machine-id>/	kept
nowhere	none	nothing was kept

<machine-id> is a 32-character code that identifies the machine. It is stored in /etc/machine-id.

The default is decided by one directory. If /var/log/journal/ exists, the journal is kept on disk. If it does not exist, the journal stays in memory and is lost at every reboot:

carol@debian:~$ ls /run/log/journal/8821e1fdf176445697223244d1dfbd73/
system.journal

The file is binary. less warns you, so use journalctl instead:

root@debian:~# less /run/log/journal/9a32ba45ce44423a97d6397918de1fa5/system.journal
"/run/log/journal/9a32ba45ce44423a97d6397918de1fa5/system.journal" may be a binary file. See it anyway?

To switch to disk, create the directory and restart the journal:

root@debian:~# mkdir /var/log/journal/
root@debian:~# systemctl restart systemd-journald
root@debian:~# journalctl
(...)
Oct 05 21:33:49 debian systemd-journald[1768]: Journal started
Oct 05 21:33:49 debian systemd-journald[1768]: System journal (/var/log/journal/9a32ba45ce44423a97d6397918de1fa5) is 8.0M, max 1.1G, 1.1G free.
Oct 05 21:33:49 debian systemd[1]: Starting Flush Journal to Persistent Storage...

"System journal (/var/log/journal/...)" confirms it is now on disk. Besides system.journal, you will also find one file per logged-in user, such as user-1000.journal.

The cleaner way is the Storage= option in /etc/systemd/journald.conf:

Value	Behaviour
Storage=volatile	memory only, in /run/log/journal/ (created if needed)
Storage=persistent	on disk, in /var/log/journal/ (created if needed). Memory is used only early in boot or if the disk is not writable
Storage=auto	the default. Like persistent, but /var/log/journal/ is not created. If it is missing, memory is used
Storage=none	keep nothing. Forwarding to other places (like a syslog daemon or the console) still works

So to make the journal persistent: set Storage=persistent, save the file, and run systemctl restart systemd-journald. Note that if someone deletes /var/log/journal/ while Storage=auto is set, journald does not recreate it and quietly falls back to memory.

Journal size and deleting old data

Check how much space the journal uses:

root@debian:~# journalctl --disk-usage
Archived and active journals take up 24.0M in the filesystem.

By default, the journal uses at most 10% of the filesystem it lives on, and keeps at least 15% free. When it reaches the limit, the oldest entries are deleted. You change the limits in /etc/systemd/journald.conf. Options starting with System apply to the journal on disk. Options starting with Runtime apply to the journal in memory:

On disk	In memory	Controls	Default
SystemMaxUse=	RuntimeMaxUse=	the most space the journal may use, for example 500M	10% of the filesystem
SystemKeepFree=	RuntimeKeepFree=	space to always leave free for others	15% of the filesystem
SystemMaxFileSize=	RuntimeMaxFileSize=	the biggest one journal file may grow	1/8 of *MaxUse
SystemMaxFiles=	RuntimeMaxFiles=	the most archived files to keep	100

*MaxUse and *KeepFree can each go up to 4 GiB. journald respects both, so the smaller result wins. MaxRetentionSec= and MaxFileSec= limit by time instead of size. Remember to restart systemd-journald after you change anything.

To clean up by hand right now, vacuum the journal:

Option	Removes
--vacuum-time=1months	entries older than this. Units: s, m, h, days/d, weeks/w, months, years/y
--vacuum-size=100M	old files until the journal is below this size. Units: K, M, G, T
--vacuum-files=10	old files until only this many archived files remain

root@debian:~# journalctl --vacuum-time=1months
Deleted archived journal /var/log/journal/7203088f20394d9c8b252b64a0171e08/system@27dd08376f71405a91794e632ede97ed-0000000000000001-00059475764d46d6.journal (16.0M).
Deleted archived journal /var/log/journal/7203088f20394d9c8b252b64a0171e08/user-1000@e7020d80d3af42f0bc31592b39647e9c-000000000000008e-00059479df9677c8.journal (8.0M).

More examples:

# journalctl --vacuum-time=3months    # drop entries older than 3 months
# journalctl --vacuum-size=1G          # shrink the journal to 1G
# journalctl --vacuum-files=5          # keep only 5 archive files

Vacuuming only deletes archived files, never the active one being written. To include the active files, first run journalctl --rotate, which closes them and starts new ones. Three more options are worth knowing:

Option	Does
--flush	moves the journal from /run to /var (needs persistent storage)
--sync	writes all unwritten entries to disk now
--verify	checks the journal files for damage

Reading the journal of a broken system

Sometimes a machine will not boot, and you need its logs to find out why. You start it from a rescue system (a live USB stick), or you put its disk in another machine, and mount its root filesystem.

journalctl normally reads /var/log/journal/<machine-id>/ of the system it runs on. The rescue system has a different machine ID, so you must tell journalctl where to look. -D (or --directory) does that:

root@debian:~# journalctl -D /media/carol/faulty.system/var/log/journal/
-- Logs begin at Sun 2019-10-20 12:30:45 CEST, end at Sun 2019-10-20 12:32:57 CEST. --
oct 20 12:30:45 suse-server kernel: Linux version 4.12.14-lp151.28.16-default (geeko@buildhost) (...)
oct 20 12:30:45 suse-server kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-4.12.14-lp151.28.16-default root=UUID=7570f67f-4a08-448e-aa09-168769cb9289 splash=>
(...)

The host name in the output, suse-server, is the broken machine, not the rescue system. Other forms:

$ journalctl -D /mnt/var/log/journal/ec22e43962c64359b9b25cfa650b025b/
$ journalctl --root /mnt      # let journalctl find the journal under /mnt

Other useful options here:

Option	Does
--root /faulty.system/	give the mounted root directory, and journalctl finds the journal files under it
--file <file>	read one journal file, for example --file /var/log/journal/64319965bda04dfa81d3bc4e7919814a/user-1000.journal
-m, --merge	merge entries from all journals it can find, including remote ones

rsyslog and journald together

Most systems run both daemons. The journal collects everything first, and rsyslog still writes the familiar text files in /var/log/. There are two ways for the data to get from journald to rsyslog:

1. journald forwards it. With ForwardToSyslog=yes in /etc/systemd/journald.conf, journald passes each message to the socket /run/systemd/journal/syslog, where the syslog daemon reads it.
2. rsyslog reads the journal files directly, just like journalctl does. For this, Storage= must be anything except none.

journald can also forward to other places: ForwardToKMsg (the kernel ring buffer), ForwardToConsole (the system console) and ForwardToWall (the screens of all logged-in users).

Summary

Linux logs through one central service, so I always know where to look. Historically that was syslog, then syslog-ng, then rsyslog; rsyslog is the one I configure, and it writes text files under /var/log/, with klogd handling kernel messages. systemd adds journald, whose binary logs I read with journalctl. Messages from before rsyslog starts wait in the kernel ring buffer, which I read with dmesg | grep. When I need answers fast, I run ls -ltrh /var/log/ and tail -f the newest file, and I use zless for rotated .gz files. A few logs are binary, so I read wtmp with who, btmp with utmpdump or last -f, and the others with faillog -a and lastlog.

rsyslog's config is /etc/rsyslog.conf plus /etc/rsyslog.d/, split into MODULES, GLOBAL DIRECTIVES and RULES. A rule is facility.priority action. The priority picks that level and everything more important, = picks one level only, .none excludes a facility, and - in front of a file avoids forcing every write to disk. The action is a file, a user, :omusrmsg:* for everyone, or @ip (@ for UDP, @@ for TCP) and a host to send logs to a central server. To build a central log server I load imtcp or imudp on port 514, open the firewall, and optionally use a template so each client gets its own directory; the client needs just *.* @@server:514. I test any rule with logger -t.

logrotate keeps text logs small. Cron runs it daily, it reads /etc/logrotate.conf and the per-package files in /etc/logrotate.d/, and directives like rotate 4, weekly, compress, delaycompress, missingok, notifempty and postrotate decide how old files are numbered, compressed and finally deleted.

The systemd journal is binary, so I read it with journalctl: -f to follow, -n for the last lines, -k for the kernel, -b and --list-boots for boots, -p for priority, -u for a unit, --since and --until for time, and fields like _PID= that combine with AND, or with OR using +. I write test messages to it with systemd-cat. Storage depends on /var/log/journal/: without it the journal lives in /run/log/journal/ and dies at reboot, so I set Storage=persistent in /etc/systemd/journald.conf when I need history. I limit its size with SystemMaxUse and friends, check it with --disk-usage, and clean it with the --vacuum-* options: --vacuum-time, --vacuum-size or --vacuum-files. On a machine that will not boot, I mount its disk and read its journal with journalctl -D or --root. Finally, journald and rsyslog work together: ForwardToSyslog=yes hands every message on to rsyslog, which is why I usually have both the journal and the text files.