Hack83.Monitor Your Logfiles

Hack 83. Monitor Your Logfiles

Use existing tools or simple homemade scripts to help filter noise out of your logfiles.

If you support a lot of services, a lot of hosts, or both, you're no doubt familiar with the problem of making efficient use of logfiles. Sure, you can have a log reporting tool send you log output hourly, but this information often goes to waste because of the extremely high noise-to-signal ratio. You can also try filtering down the information and using a tool such as logwatch to report on just those things most important to you on a daily basis. However, these reports won't help alert you to immediate, impending danger. For that, you need more than a reporting tool. What you really need is a log monitor; something to watch the logs continually and let you know about anything odd.

Log monitors in many environments come in human form: administrators often keep several terminal windows open with various logs being tailed into them, or they use something like root-tail to get those logs out of windows and right into their desktop backgrounds. You can even send your output to a Jabber client [Hack #84]. This is wonderful stuff, but again, it doesn't help filter out any of the unwanted noise in logfiles, and it's not very effective if all the humans are out to lunch (so to speak).

There are a number of solutions to this problem. One is simply to make sure that your services are logging at the right levels and to the right syslog facilities, and then make sure your syslog daemon is configured to break things up and log things to the right files. This can help to some degree, but what we want is to essentially have a real-time, always-running "grep" of our logs that will alert us to any matches that are found by sending us email, updating a web page, or sending a page.

9.7.1. Using log-guardian

There are a couple of tools out there that you can use for log monitoring. One is log-guardian, which is a Perl script that allows you to monitor multiple logfiles for various user-supplied patterns. You can also configure the action that log-guardian takes when a match is found. The downside to using log-guardian is that you must have some Perl knowledge to configure it, since actions supplied by the user are in the form of Perl subroutines, and other configuration parameters are supplied in the form of Perl hashes. All of these are put directly into the script itself or into a separate configuration file. You can grab log-guardian from its web site: http://www.tifaware.com/perl/log-guardian/. Once downloaded, you can put the log-guardian.pl script wherever you store local system tools, such as under /opt or in /var/local. Since it doesn't come with an init script, you'll need to add a line similar to this one to your system's rc.local file:

 /var/local/bin/log-guardian & 

The real power of log-guardian comes from Perl's File::Tail module, which is a fairly robust bit of code that acts just like tail -f. This module is required for log-guardian. To determine whether you have it installed, you can run something like locate perl | grep Tail, or run a quick Perl one-liner like this at the command line:

 $ perl -e "use File::Tail;" 

If that returns a big long error beginning with "Can't find Tail/File.pm" or something similar, you'll need to install it using CPAN, which should be dead simple using the following command:

 # perl -MCPAN -e shell 

This will give you a CPAN shell prompt, where you can run the following command to get the module installed:

 > install File::Tail 

The File::Tail module is safe for use on logfiles that get moved, rolled, or replaced on a regular basis, and it doesn't require you to restart or even think about your script when this happens. It's dead-easy to use, and its more advanced features will allow you to monitor multiple logfiles simultaneously.

Here's a simple filter I've added to the log-guardian script itself to match on sshd connections coming into the server:

 '/var/log/messages' => [ { label => 'SSH Connections', pattern => "sshd",    action => sub {    my $line = $_[1];    print $line;    } }, ], 

That's about as simple a filter you can write for log-guardian. It matches anything that gets written to /var/log/messages that has the string sshd in it and prints any lines it finds to stdout. From there, you can send it to another tool for further processing or pipe it to the mail command, in which case you could run log-guardian like this:

 # /var/local/bin/log-guardian | mail [e-mail] 

Of course, doing this will send every line in a separate email, so you might prefer to simply let it run in a terminal. You'll be able to monitor this output a little more easily than the logfiles themselves, since much of the noise has been filtered out for you.

This sshd filter is just one examplethe "pattern" can consist of any Perl code that returns some string that the program can use to match against incoming log entries, and the "action" performed in response to that match can be literally anything you're capable of inventing using Perl. That makes the possibilities just about endless!

9.7.2. Using logcheck

The logcheck utility is not a real-time monitor that will alert you at the first sign of danger. However, it is a really simple way to help weed out the noise in your logs. You can download logcheck from http://sourceforge.net/projects/sentrytools/.

Once downloaded, untar the distribution, cd to the resulting directory, and as root, run make linux. This will install the logcheck files under /usr/local. There are a few files to edit, but the things that need editing are simple one-liners; the configuration is very intuitive, and the files are very well commented.

The main file that absolutely must be checked to ensure proper configuration is /usr/local/etc/logcheck.sh. This file contains sections that are marked with tags such as CONFIGURATION and LOGFILE CONFIGURATION, so you can easily find those variables in the file that might need changing. Probably the most obvious thing to change is the SYSADMIN variable, which tells logcheck where to send output.

 SYSADMIN=[e-mail] 

You should go over the other variables as well, because path variables and paths to binaries are also set in this file.

Once this is ready to go, the next thing you'll want to do is edit root's crontab file, which you can do by becoming root and running the following command:

 # crontab -e 

You can schedule logcheck to run as often as you want. The following line will schedule logcheck to run once an hour, every day, at 50 minutes after the hour:

 50 * * * * /bin/sh /usr/local/etc/logcheck.sh 

You can pick any time period you want, but once per hour (or less in smaller sites or home networks) should suffice.

Once you've saved the crontab entry, you'll start getting email with reports from logcheck about what it's found in your logs that you might want to know about. It figures out which log entries go into the reports by using the following methodology:

• It matches a string you've noted as significant by putting it in /usr/local/etc/logcheck.hacking.

• It does not match a string you've noted as being noise by putting it in /usr/local/etc/logcheck.ignore.

These two files are simply lists of strings that logcheck will try to match up against entries in the logs it goes through to create the reports. There is actually a third file as well, /usr/local/etc/logcheck.violations.ignore, which contains strings that are matched only against entries that are already flagged as violations. There's an example of this in the INSTALL file that comes with the distribution that is more perfect than anything I can think of, so I'll reiterate it here:

 Feb 28 21:00:08 nemesis sendmail[5475]: VAA05473: to=crowland, ctladdr=root (0/0), delay=00:00:02, xdelay=00:00:01, mailer=local, stat=refused Feb 28 22:13:53 nemesis rshd: refused connect from [e-mail]:1490 The top entry is from sendmail and is a fairly common error. The stat line indicates that the remote host refused connections (stat=refused). This can happen for a variety of reasons and generally is not a problem. The bottom line however indicates that a person ([e-mail]) has tried unsuccessfully to start an rsh session on my machine. This is bad (of course you shouldn't be running rshd to begin with). The logcheck.violations file will find the word 'refused' and will flag it to be logged; however, this will report both instances as being bad and you will get false alarms from sendmail (both had the word 'refused'). 

To get around these false positive without also throwing out things you want to know about, you put a line like this in /usr/local/etc/logcheck.violations.ignore:

 mailer=local, stat=refused 

This will match only the Sendmail log entry and will be ignored. Any other entries will be caught if they contain the string "refused".

Of course, it will likely take you some time to fine-tune the reports logcheck sends, but the model of forcing you to tell the tool to explicitly ignore things ensures that it ignores only what you tell it to, instead of making assumptions about your environment.