December 20, 2016

Remote Logging With Syslog, Part 4: Log Rotation

log-rotation.jpg

rsyslog
In the final article in this series, we provide more details on using rsyslog and discuss some important networking considerations.

As you’ll recall, we’ve been taking a deep dive into the rsyslog tool for logging -- we presented an overview in the first article, took a look at the main config file in the second article, and examined some logfile rules and sample configurations in the third. In this final article in the series, I’ll look at the /etc/rsyslog.d/www-rsyslog.chrisbinnie.tld.conf and discuss some important networking considerations.

Have a look at Listing 1, which shows the entirety of our /etc/rsyslog.d/www-rsyslog.chrisbinnie.tld.conf file.

$ModLoad imfile

$InputFileName /var/log/apache2/access_log

$InputFileTag apache.access:

$InputFileStateFile /tmp/apache_state_file

$InputFileSeverity info

$InputFileFacility local3

$InputRunFileMonitor

local3.* @@10.10.1.3:514

Listing 1: Contents of our remote application’s config using the trusty “local3” within the /etc/rsyslog.d/www-rsyslog.chrisbinnie.tld.conf file.

The key lines to focus on in this listing, starting from the top, are as follows.

We need to load up a module using $ModLoad. Step forward the outstanding “imfile” module, which has the magical ability to convert any normal text content into a rsyslog message. The manual says it will gratefully consume any printable characters that have a line feed (LF) at the end of each line to break up the otherwise monotonous content. Pretty clever, I’m sure you’ll agree.

The next important line is obvious. The line starting $InputFileName tells rsyslog which log file you’re interested in sending off to your remote logging server. The following line helps classify the log type with a “Tag” (which if you have multiple servers of the same application type sending logs to one remote server you might alter slightly per server to apache-apache-ww1: etc). Ignore the $InputFileStateFile log file for now and skim through the remaining lines.

We are collecting an “info” level of logging detail and pushing that out to the user-configurable “local3” facility and onto the IP Address “10.10.1.3”. The emoji that you can see -- the two @ signs -- stands for TCP. Only one @ sign would signify transfers via the UDP networking protocol.

Can Anybody Hear Me?

What about our remote rsyslog server’s config?

Have a quick look at the two lines below, which will sit in your remote rsyslog server’s /etc/rsyslog.conf file. For the sake of clarity, this is the recipient rsyslog server, the one that’ll receive all the logs from multiple places. Unless you’ve lost control of your senses, these two lines are easy to follow:

$ModLoad imtcp

$InputTCPServerRun 514

Incidentally, if an IP address is omitted (it can be explictly stated using something like $TCPServerAddress 10.10.10.10), then rsyslog will attempt to open up all IP addresses on the port in question.

You might be pleasantly surprised at how easy it is to finish off the remote rsyslog server config. We use something called “templates” in rsyslog. They are powerful, extensible, and worth reading about in more detail.

At the foot of our /etc/rsyslog.conf file, we simply add these lines:

$template ChrisBinnie, "/var/log/%HOSTNAME%/%PROGRAMNAME%.log"

*.*   ?ChrisBinnie

I’ve just used an arbitrary template reference in this case, my name, for ease of distinction. You will need to restart the service after making these changes.

We can see that we’re going to drop our logs into a directory off of /var/log, which has a hostname and then the application name. Appended to the end, the “.log” makes sense of the resulting filename. You can see which facilities and priorities are being added to this log file, in this case, “all” and “all” -- thanks to the asterisks.

To TCP Or Not To TCP

You might need to spend a second thinking back over some of the remote logging considerations I mentioned, such as network congestion, if you’re pushing lots of logging data across your LAN. I mention this because (as we saw above) the clever rsyslog can use both TCP and UDP for pushing your logs around. TCP is the option best suited to most scenarios, thanks to its ability to error-check against network failures. It also doesn’t require an additional plugin to be loaded up, because it’s built into rsyslog; the reverse is true for the UDP protocol.

There are two minor connection points to note here. First, avoid using hostnames via DNS. Use an IP address for greater reliability (CNAMEs are somewhere in the middle, if you change machines around every now and again). Second, as with all things that might need debugged at some point, you should try to use explicit port numbers on both server and client ends so that there’s no ambiguity introduced. Incidentally, without a port explicitly specified, both protocols default to 514.

Little Dutch Boy

Note that if you’re using properly configured systems, you might need to punch a hole in the dike. Looking at the example below, clearly you need to alter the port number after --dport to your port number of choice. You can then save the setting to make it persistent with something like /sbin/service iptables save or whatever your distribution prefers.

If you need to allow access using the default TCP option and you’re using iptables, you can use this command:

# iptables -A INPUT -p tcp -m state --state NEW -m tcp --dport 514 -j ACCEPT

And, for good, old UDP, use:

# iptables -A INPUT -p udp -m state --state NEW -m udp --dport 514 -j ACCEPT

Stale Bread

Back to the dreaded gotcha. So that we’re clear: On the client or sender machine, we make a little fix to our log rotation bug/problem. Not the remote rsyslog server.

At the risk of repeating myself, there may be better ways of fixing the log rotation problem (with a version upgrade, for example); however, read on to see what fixed it for me. Remember that the issue is that after “logrotate” had run, the remote logging stopped. The solution was a simple script set to run via a cron job after “logrotate” had run in the middle of the night.

There is some method to the madness of my script. By running it, we effectively insist that after a log rotation has taken place the faithful rsyslog pays attention to its “state” file. Let’s peek into an example now:

<Obj:1:strm:1:

+iCurrFNum:2:1:1:

+pszFName:1:25:/var/log/apache2/access_log:

+iMaxFiles:2:1:0:

+bDeleteOnClose:2:1:0:

+sType:2:1:2:

+tOperationsMode:2:1:1:

+tOpenMode:2:3:384:

+iCurrOffs:2:7:1142811:

>End

.

Listing 2: Our rsyslog “state” file example.

We shouldn’t profess to understanding what’s going on in Listing 2, I would hazard a guess that rsyslog is counting lines it’s processed -- among other things, to keep it operating correctly. Let’s promptly move on to Listing 3. This is the cron job and script solution that fixed the issue for me.


#!/bin/bash


#

# Deletes stale rsyslog “state” files, appends a timestamp to the new filename in /tmp & restarts rsyslog.

#

# After rsyslog restart the remote logging node should catch up any missed logs fairly quickly.

#


# Declare var

timestamp=$(date +%s)


# Delete all “state” files in /tmp

/bin/rm -f /tmp/apache_state_file*


# Edit rsyslog file which sends data remotely in order to show newly named “state” file

/bin/sed -i.bak 's/apache_state_file-[0-9]*/apache_state_file-'"$timestamp"'/g' /etc/rsyslog.d/www-syslog.chrisbinnie.tld.conf


# Apply changes to “state” file in use

/sbin/service rsyslog restart

Listing 3: Our quick-fix script to get log rotations to speak to rsyslog satisfactorily after “logrotate” has finished doing its business.

If you read the comments at the top of the script then all going well the scripts raison d’etre should make sense. This script is run sometime around 5am after the excellent “logrotate” has finished its sometimes lengthy business. There’s no point in running the script during or before “logrotate” has finished its run (during testing my remote logging still failed).

The small script works like this (you probably need to run it twice initially to clean up /tmp filenames, which should be harmless if you do it manually). It deletes the old “state” file upon which rsyslog relies, works out the current time, and appends that time to the end of the “state” filename.

As a result, the /tmp directory ends up having one or two files that look like this apache_state_file-1321009871. It then backs up the existing remote logging config file and changes the “state” file that it references. Finally, a super-quick service restart means that the remote logging data starts up again and the other end (the remote rsyslog server) catches up with any missed logs in a whizz-pop-bang if there’s lots of data.

My experience is that if you tail the recipient log after running this script (or just performing a restart), you’ll see the catchup taking place super-speedily. In case you’re wondering, I found that sometimes a service restart didn’t pick up the pieces properly but altering the “state” file it referenced was successful without fail. Your mileage might vary of course.

As mentioned, I’m a little suspicious of an old version issue that I needed to fix with this script. In the current version, you can see there is some additional information about the current version’s “state” file. I hope my solution gives you some pointers and helps you out if you encounter a similar scenario, however.

I Can’t Hear You

If your already exceptionally noisy log file /var/log/messages begins to fill up with your application’s logs, too, then here’s another little life-saver. The workaround is simple, you just need a service restart, after applying this ;local3.none addition to the relevant destination log file line in /etc/rsyslog.conf:

*.*;auth,authpriv.none;local3.none  -/var/log/messages

No doubt you get the idea, this disables “local3” logging locally.

End Of Watch

I should have probably put more emphasis on the how configurable and extensible rsyslog is at the start. It would be remiss not to point you at the extensive, well-maintained, documentation, which is all linked to from the application’s main website. There are modules and templates galore to explore in high levels of detail. And, as well as user examples on the main site, there’s an excellent wiki with some trickier configuration examples. If you’re eager for even more, you can check out this list of modules.

Now that I’ve presented the solution to a working remote rsyslog server, even with the challenges that log rotation throws into the mix, I hope you’ll think more about your logging infrastructure. I had originally used a Syslog server, back in the day, to pick up salient events from Cisco routers. So universal are the logging formats supported by rsyslog that you can also connect them to all sorts of devices, such as load balancers and other proprietary devices. You are far from being limited to picking up logs from other Unix-type devices and instead are blessed with the ability to collect logging event information from all over the place.

I hope you enjoy putting your new logging knowledge to creative and productive use.

Read the other articles in this series:

Remote Logging With Syslog, Part 1: The Basics

Remote Logging With Syslog, Part 2: Main Config File

Remote Logging With Syslog, Part 3: Logfile Rules

Chris Binnie is a Technical Consultant with 20 years of Linux experience and a writer for Linux Magazine and Admin Magazine. His new book Linux Server Security: Hack and Defend teaches you how to launch sophisticated attacks, make your servers invisible and crack complex passwords.

Advance your career in system administration! Check out the Essentials of System Administration course from The Linux Foundation.

Click Here!