How to use syslog

This is part of the Semicolon&Sons Code Diary - consisting of lessons learned on the job. You're in the logging category.

Last Updated: 2021-05-16

This article covers not just syslog, but also close alternatives like:

What's the big deal with Syslog?

Many software projects support sending data to syslog, which is more a standard than a program. This facilitates centralization of logged information from many programs, allowing better monitoring and security on your systems.

Basic API

The most basic syslog API can be seen in man 3 (i.e. the C library functions)

void syslog(int priority, const char *format, ...);

What does this all mean?

Configuration

The configuration file for your syslog (or syslog alternative) will found as a direct child of the /etc folder

$ vim /etc/syslog.conf
# FYI: It would be rsyslog.conf for rsyslog

In some variants, you can validate configuration file with the CLI:

$ sudo syslogd -N1

The actual configuration file consists of two-part entries that contain both 1. a selector 2. an action (which is usually just the name of the file, but can be a pipe or remote machine etc.)

A selector consists of a facility and a priority - e.g. Kern.none, or mail.info

Examples:

# Log all critical messages to a separate log file
*.=crit            /var/log/critical.log

# Log all kernel-related messages to a separate log file
Kern.*       /var/log/firewall.log

# Do not log private cron messages or kern messages
cron.none;kern.none                /var/log/messages

# Forward all messages to a remote host
*.*            @hostname

Rotation on ubuntu?

Why log rotation? The purpose is to archive and compress old logs so that they consume less disk space, but are still available for inspection as needed.

File names might have date included or numbers and compression - e.g. syslog.1.gzip

The logrotate command usually does this. This is typically called from /etc/cron.daily/logrotate, and further defined by the configuration file /etc/logrotate.conf

Here is my logrotate config on one of my Ubuntu servers:

# rotate log files weekly
weekly

# use the syslog group by default, since this is the owning group
# of /var/log/syslog.
su root syslog

# keep 4 weeks worth of backlogs
rotate 4

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

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

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

You can specify what to do with particular log files (not just syslog files) as follows:

"/var/log/httpd/access.log" /var/log/httpd/error.log {
     rotate 5
     mail www@example.com # email them
     size 100k
     sharedscripts
     postrotate
         /usr/bin/killall -HUP httpd
     endscript
 }

Networking and logs (and potential cause of outages!)

The most important decision is protocol:

Some implementations of syslog include support for reliable delivery, including buffering messages when the server is not reachable. (e.g. rsyslog and RELP)

FYI: Usually syslog sends data over port 514 of UDP. Consider this from a firewalls and networking perspective.

logger

logger --journald <<end
                  MESSAGE_ID=67feb6ffbaf24c5cbec13c008dd72309
                  MESSAGE=The dogs bark, but the caravan goes on.
                  DOGS=bark
                  CARAVAN=goes on
                  end

What do syslog entries look like?

Here are some examples from one of my servers:

Nov 15 08:05:01 li428-20 CRON[17388]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Nov 15 08:17:01 li428-20 CRON[17421]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Nov 15 09:08:03 li428-20 systemd-timesyncd[533]: Network configuration changed, trying to establish connection.
Nov 15 09:08:04 li428-20 systemd-timesyncd[533]: Synchronized to time server 91.189.89.198:123 (ntp.ubuntu.com).
Nov 15 09:15:01 li428-20 CRON[17637]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Nov 15 09:17:01 li428-20 CRON[17648]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Nov 15 09:44:35 li428-20 systemd[1]: Starting Cleanup of Temporary Directories...
Nov 15 09:44:35 li428-20 systemd[1]: Started Cleanup of Temporary Directories.
Nov 15 10:05:01 li428-20 CRON[17880]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Nov 15 10:05:44 li428-20 snapd[19101]: storehelpers.go:436: cannot refresh snap "core": snap has no updates available
Nov 15 10:05:44 li428-20 snapd[19101]: autorefresh.go:397: auto-refresh: all snaps are up-to-date
Nov 15 10:15:01 li428-20 CRON[17931]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Nov 15 11:17:01 li428-20 CRON[18313]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Nov 15 12:20:51 li428-20 systemd[1]: Starting Message of the Day...
Nov 15 12:20:52 li428-20 50-motd-news[18652]:  * Kata Containers are now fully integrated in Charmed Kubernetes 1.16!
Nov 15 12:20:52 li428-20 50-motd-news[18652]:    Yes, charms take the Krazy out of K8s Kata Kluster Konstruction.
Nov 15 12:20:52 li428-20 50-motd-news[18652]:      https://ubuntu.com/kubernetes/docs/release-notes
Nov 15 12:20:52 li428-20 systemd[1]: Started Message of the Day.
Nov 15 15:05:35 li428-20 systemd[1]: Created slice User Slice of root.
Nov 15 15:05:35 li428-20 systemd[1]: Starting User Manager for UID 0...
Nov 15 15:05:35 li428-20 systemd[1]: Started Session 24419 of user root.
Nov 15 15:05:35 li428-20 systemd[19758]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 15 15:05:35 li428-20 systemd[19758]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 15 15:05:35 li428-20 systemd[19758]: Reached target Timers.
Nov 15 15:05:35 li428-20 systemd[19758]: Listening on GnuPG network certificate management daemon.
Nov 15 15:05:35 li428-20 systemd[19758]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 15 15:05:35 li428-20 systemd[19758]: Reached target Paths.
Nov 15 15:05:35 li428-20 systemd[19758]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 15 15:05:35 li428-20 systemd[19758]: Reached target Sockets.
Nov 15 15:05:35 li428-20 systemd[19758]: Reached target Basic System.
Nov 15 15:05:35 li428-20 systemd[1]: Started User Manager for UID 0.
Nov 15 15:05:35 li428-20 systemd[19758]: Reached target Default.
Nov 15 15:05:35 li428-20 systemd[19758]: Startup finished in 43ms.
Nov 15 15:05:47 li428-20 root: THIS IS ME TALKING FROM THE `logger` app

Above we see the following columns - timestamp - device ID (sometimes hostname) - program name - pid (in [square brackets]) - message

macos differences

Tag system

In some systems, you can give each entry in your syslog a tag, making it easier to search for entries - especially when aggregating logs from multiple systems and multiple programs on each system.

logger "My message" --tag "playground"
# If tag is not specified in the logger command, it defaults to the user id.

How to set up centralized logging on a typical server

Imagine the web server is ngingx and this talks to a Ruby server via unicorn

  1. Option 1 — configure nginx, unicorn etc. to send their logs to syslog
// ngingx.conf

http {
  // Notes:
  // 1. /dev/log : need not exist to start with — syslog just knows to connect
  // 2. serverity=X : controls severity in syslog
  access_log  syslog:server=unix:/dev/log,tag=nginx,severity=info combined;
  error_log  syslog:server=unix:/dev/log,tag=nginx,severity=error;
}

Next restart nginx

$ service nginx restart

And check it restarted correctly:

$ systemctl status nginx.service

Now connect unicorn

require 'syslog'

# Define interface.
class Unicorn::Syslog
  def initialize
    Syslog.open
  end

  def debug(msg)
    Syslog.debug(msg)
  end

  def info(msg)
    Syslog.info(msg)
  end

  def warn(msg)
    Syslog.warn(msg)
  end

  def error(msg)
    Syslog.err(msg)
  end

  def fatal(msg)
    Syslog.crit(msg)
  end
end

logger Unicorn::Syslog.new
  1. Option 2 - tell ryslog (etc.) to monitor the normal ngingx (and other) logs and forward them

References