Logs are a critical asset to successfully running your systems. They tell us what is and what is not happening. However, logs can be extremely copious, quickly overwhelming us with information. Pretty soon they become useless files that just fill up disk space. This article will cover how to solve this by automating the filtering of your logs, freeing up your time while presenting you the information you need.
 

Filtering
Logs are an incredible asset, unfortunately they are often ignored. You have too little time to review too much information. Wouldn’t it be nice to automate the process, a process that reviews the logs for you, then notifies you with only the information you need. Well, we are going to do just that. I am going to cover how to filter your logs for the information you need, then implement a notification system.

The first part of this article will cover developing a plan on what you want to filter, and what you want to be notified of. The second half will be on implementing the filter. For this article, I will be using swatch as a filter, written by Todd Atkins. We will also be using sendmail logs as an example of the filtering process. However, you can apply these guidelines to any type of logging.

Where to begin
The best place to start is with a plan. There are three steps to planning for automated logging. The first step is define what you want to know. Determine what information  you need out of your system logs. The second step is to identify which logs contain that information. The third step is identifying the trigger, what defines the critical information?

For example, lets say you are concerned about the security of your sendmail, specifically you want to know if someone attempts to use your mail server as a spam relay. You also want to know if anyone is attempting to gain unauthorized information with SMTP commands, such as expn. We have completed the first step by determining what we want to know.

The second step is identifying the source, or what log contains this information. The best place to find that is /etc/syslog.conf, this configuration file will show you what information is logged where. For mail, we see that all mail information is logged to /var/log/syslog.

homer#cat /etc/syslog.conf | grep mail
 mail.debug ifdef(`LOGHOST', /var/log/syslog, @loghost)

The last step is defining the trigger. What specific entries in the logs define the information we are looking for. For sendmail, we are looking for two triggers.

1. Trigger that shows un-authorized IP addresses attempting to use our mail server as a mail relay.
2. Trigger that shows someone is attempting to use the expand command, which we have turned off.

The best way to define the trigger is to recreate the incident while monitoring the log with /usr/bin/tail –f. If you can’t do this on a production system, find a lab system you can replicate the trigger on. First, lets recreate the incident for the first trigger, unauthorized use of our system as a mail relay . From an un-authorized IP address, attempt to use your mailserver as a relay. With /usr/bin/tail –f you see the log entry in /var/log/syslog (Refer to Figure A).

There we see the error message of someone at moo.com attempting to relay email, potentially a sign of spam. This is the trigger for unauthorized mail relay. Notice how the error also includes the IP address, verifying the domain.

Now, lets recreate the second trigger, unauthorized use of the expand command. Telnet to the SMTP port and execute expn. Meanwhile monitor the /var/log/syslog with tail –f (Refer to Figure B).

There we see the error message of someone at moo.com attempting to expand the username bsmith. This is the trigger if anyone attempts to exploit the "expn" command. Notice how the error also includes the IP address, verifying the domain.

We have now completed the three steps in planning for automated log filtering. We first identified the information important to us, unauthorized attempts to use our mail server as a mail relay and use of the expn command.  We then identified the logs that contain this information, /var/log/syslog. Last, we identified the triggers for this information by recreating the incidents. We are now ready to build our automated filter.
 

SWATCH
SWATCH, "The Simple WATCHer and filter", is a perl program developed by Todd Atkins that monitors your logs in real time. Swatch monitors your logs for specific triggers, when those triggers are matched swatch notifies you in a pre-determined manner. In our case, we are going to implement swatch to alert us whenever someone is messing with our sendmail.

The program is extremely simple to install. Since this is a perl program, there is no compiling involved. Swatch comes with a useful install script that will copy all the libraries, man pages, and perl files to their respective directories. Once done installing, all that is left is creating a configuration file and then launching the program. You can download swatch at ftp://ftp.stanford.edu/general/security-tools/swatch.

The configuration file, called swatchrc, is the heart of the swatch program. This text file tells swatch what logs to monitor, what triggers to look for, and what to do if triggered. Swatch works by looking for regular expressions that match the triggers defined in swatchrc. When it finds a match, it executes the notification procedure defined in swatchrc. Swatch monitors the files in real time, using /usr/bin/tail –f.

We will now create a swatchrc file for our sendmail logging we discussed above. The goal is to have sendmail email us whenever someone is messing with our email system. We defined this earlier as anyone attempting unauthorized mail relay or the expn command. The syntax of a swatchrc file is as follows. It consists of four tab-deliminited fields, the first two fields are required, the last two fields are optional. The first field is

/pattern/pattern/

where pattern is a regular expression that swatch is looking for. This is our trigger. The second field is

Action,action…

where action is what to do if the pattern is matched. Swatch has various options for actions, including email, paging, or executing any file you select.  The third field (which is optional) is a time interval defined as

HH:MM:SS

HH is for hours, MM for minutes, and SS for seconds. This time interval is the amount of time swatch will ignore identical matched patterns that repeat themselves. For example, if you define this period as 5 minutes, swatch will only report one identical matched pattern over that time period, even though it might have matched 20 identical entries.

The fourth field (required if you are using the third field) is a timestamp, defined as
start:length. This defines the location and length of the timestamp in the notification message.

 For our sendmail example, we want to create a swatchrc file that looks for patterns matching our two triggers (See Figure A and Figure B). When it matches either of these patterns, we want it to notify via email abuse@ourcompany.com and to include the matched pattern in the email. However, we have to be careful not to be flooded with warnings. For example, if someone attempts to relay off us with 1000 emails a minute, we would be overwhelmed with notifications. So, we will set a time interval of 5 minutes. Regardless of how many identical patterns are matched in a five minute period, we will receive only one warning. Our swatchrc file would look as follows:

/Relaying denied|expn/ echo=normal,mail=abuse@ourcompany.net 5:00 0:16

 The first field has "/Relaying denied|expn/". If swatch matches either pattern in the regular expression, it will send an alert. The first pattern "Relaying denied" is found in trigger #1 (Figure A), this log is the result of someone attempting an unauthorized mail relay. The pattern "expn" is found in trigger #2 (Figure B), it is the result of someone attempting to use the expn command. You will find both expressions in the triggers we covered in the first part of the article.

The second filed has "echo=normal,mail=abuse@company.net"
This field states email a warning to abuse@ourcompany.net, and echo the matched log entry.

The third and fourth field (which are optional), have "5:00 0:16". This states do not repeat any warning for identical patterns matched within 5 minutes. The last field states the location and length of the timestamp.

We now have a properly configured swatchrc file. The last step is starting swatch itself. Swatch can be launched with a variety of options. However, we will launch with the following syntax.

/usr/local/bin/swatch -c /var/log/syslogrc -t /var/log/syslog &

The –c option points to the configuration file, and the –t option monitors the log file in realtime. The "&" runs the swatch in the background. Once launched, swatch forks a child, so swatch will be running as two processes. Be sure to kill both processes in any stop/start scripts you create. That’s it. Your sendmail logs will be automatically filtered. Whenever someone messes with your sendmail system, you will be instantly notified via email, with the matched trigger in the log included (See Figures A and Figure B).

Conclusion
Logs are powerful tools, yet they can easily overwhelm us with data. When this happens, we start ignoring this valuable source because we don’t have time to scan through megs of data. Automating the filtering of such logs solves the problem. These automated filters do the work for us, alerting us in real time with the information we need. Hopefully this article has given you ideas on how to automate the filtering of your log files.

Figure A
Trigger for anyone attempting un-authorized mail relay from your sendmail server.
Oct 3 14:48:51 homer sendmail[6704]: OAA06704: ruleset=check_rcpt,arg1=bsmith@domain.com, relay=foo@moo.com [206.54.252.1],reject=550 bsmith@domain.com... Relaying denied
 

Figure B
Trigger for anyone attempting to utilize the expn command on your sendmail server.
Oct 2 20:28:37 homer sendmail[5453]: NOQUEUE: foo@moo.com[206.54.252.1]: expn bsmith [rejected]