Watching your logs

by Lance Spitzner

Logs are a critical asset to successfully running our systems. They tell uswhat is and what isn't happening. However, logs can be extremely copious,quickly overwhelming us with information. Pretty soon they become useless filesthat just fill up disk space. This article will cover how to solve this problemby automating the filtering of your logs, thereby freeing up your time whilepresenting the information you need.

Filtering

Logs are incredible assets that, unfortunately, are often ignored. You have toolittle time to review too much information. Wouldn't it be nice to automate theprocess--to create a process that reviews the logs for you, and then notifiesyou with only the information you need? Well, we're going to do just that.We'll show you how to filter your logs for the information you need, andimplement a notification system.

The first part of the article will cover developing a plan on what you want tofilter and what you want to be notified of. The second half will be onimplementing the filter. For this article, we'll be using SWATCH as a filter,written by Todd Atkins. We'll also be using sendmail logs as an example of thefiltering process. However, you can apply these guidelines to any type oflogging.

Where to begin

The best place to start is with a plan. There are three steps to planning forautomated logging. The first step is to define what you want to know. Whatinformation do you need from your system logs? The second step is to determinewhich logs contain that information. The third step is to identify the trigger,or determine what defines the critical information.

For example, let's say you're concerned about the security of your sendmail.Specifically, you want to know if someone attempts to use your mail server as aspam relay. You also want to know if anyone is attempting to gain unauthorizedinformation with SMTP commands, such as expn. We've completed the first step,which is identifying what we want to know.

The next step is identifying the source, or which log contains thisinformation. The best place to find that is /etc/syslog.conf. Thisconfiguration file will show you what information is logged where. For mail, wesee that all mail information is logged to /var/log/syslog. 

mail.debug   ifdef('LOGHOST', /var/log/=>syslog, @loghost)
The last step is defining the trigger. What specific entries in the logs definethe information we're looking for? In the case of sendmail, we're looking fortwo triggers:

1. A trigger showing unauthorized IP addresses attempting to use our mailserver as a mail relay.

2. A trigger showing that someone is attempting to use the expand command,which we've turned off.

The best way to define the trigger is to re-create the incident whilemonitoring the log with /usr/bin/tail -f. If you can't do this on a productionsystem, find a lab system you can replicate the trigger on.

First, let's re-create the incident for the first trigger--unauthorized use ofour system as a mail relay. From an unauthorized IP address, attempt to useyour mail server as a relay. With /usr/bin/tail -f you see the log entry in/var/log/syslog, shown in Listing A.

Listing A: Trigger for anyone attempting unauthorized mail relay from your sendmailserver 

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
Here we see the error message of someone at moo.com attempting to relayemail, usually a sign of spam. This is the trigger for unauthorized mail relay.Notice that the error also includes the IP address, verifying the domain.

Now, let's re-create the second trigger--unauthorized use of the expandcommand. Telnet to the SMTP port and execute expn. Meanwhile monitor the/var/log/syslog with tail -f, as shown in Listing B.

Listing B: Trigger for anyone attempting to utilize the expn command on your sendmailserver 

Oct 2 20:28:37 homer sendmail[5453]:    NOQUEUE: foo@moo.com [206.54.252.1]: expn bsmith [rejected]
There we see the error message of someone at moo.com attempting toexpand the user name bsmith. This is the trigger if anyone attempts toexploit the expn command. Notice that the error also includes the IP address,verifying the domain.

We've now completed the three steps in planning for automated log filtering. Wefirst identified the information important to us, unauthorized attempts to useour mail server as a mail relay and use of the expn command.

We then identified the logs that contain this information. Last, we identifiedthe triggers for this information by re-creating the incidents. We're now readyto build our automated filter.

SWATCH

SWATCH, "The Simple WATCHer and filter," is a Perl program developed by ToddAtkins that monitors your logs in real time. SWATCH monitors your logs forspecific triggers, and when those triggers are matched, SWATCH notifies you ina pre-determined manner. In our case, we're going to implement SWATCH to alertus whenever someone is messing with our sendmail.

The program is extremely simple to install. Since this is a Perl program, nocompiling is involved. SWATCH comes with a useful install script that will copyall the libraries, man pages, and Perl files to their respective directories.Once installation is complete, all that's left to do is create a configurationfile and then launch 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 which logs to monitor, which triggers to look for,and what to do if triggered. SWATCH works by looking for regular expressionsthat match the triggers defined in swatchrc. When it finds a match, it executesthe notification procedure defined in swatchrc. SWATCH monitors the files inreal time, using /usr/bin/tail -.

We'll now create a swatchrc file for the sendmail logging we discussed above.The goal is to have sendmail email us whenever someone is messing with ouremail system. We defined this earlier as anyone attempting unauthorized mailrelay or the expn command.

The syntax of a swatchrc file is as follows. It consists of four tab-delimitedfields. The first two fields are required, but the last two fields areoptional. The first field is 

/pattern/pattern/
where pattern is a regular expression that SWATCH is looking for. Thisis our trigger. The second field is 
Action,action-
where action is what to do if the pattern is matched. SWATCH has variousoptions 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. Thistime interval is the amount of time SWATCH will ignore identical matchedpatterns that repeat themselves. For example, if you define this period as fiveminutes, SWATCH will only report one identical matched pattern over that timeperiod, even though it might have matched twenty identical entries.The fourth field (required if you're using the third field) is a timestamp,defined as 
start:length.
This defines the location and length of the timestamp in the notificationmessage.

For our sendmail example, we want to create a swatchrc file that looks forpatterns matching our two triggers shown in Listings A and B.When SWATCH matches either of these patterns, we want it to notify via email atabuse@ourcompany.com and to include the matched pattern in the emailmessage. However, we have to be careful not to be flooded with warnings. Forexample, if someone attempts to relay off us with 1,000 emails a minute, we'dbe overwhelmed with notifications. So, we'll set a time interval of fiveminutes. Regardless of how many identical patterns are matched in a five-minuteperiod, we'll receive only one warning. Our swatchrc file would look as follows: 

/Relaying denied|expn/ echo=normal,=>mail=abuse@company.net 5:00   0:16
The first field has /Relaying denied|expn/. If SWATCH matches either pattern inthe regular expression, it will send an alert. The first pattern, Relayingdenied, is found in trigger #1, or Listing A. This log is the result ofsomeone attempting an unauthorized mail relay. The pattern expn is found intrigger #2, or Listing B, and is the result of someone attempting to usethe expn command. You'll find both expressions in the triggers we covered inthe first part of the article.

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

The third and fourth fields (which are optional) have 5:00 0:16. This tellsthe program not to repeat any warning for identical patterns matched withinfive minutes. The last field states the location and length of the timestamp.

We now have a properly configured swatchrc file. The last step is startingSWATCH itself. SWATCH can be launched with a variety of options. However, we'lllaunch with the following syntax. 

/usr/local/bin/SWATCH -c /var/log/syslogrc -t    /var/adm/syslog &
The -c option points to the configuration file, and the -t option monitors thelog file in real time. The & runs the SWATCH in the background. Oncelaunched, SWATCH forks a child, so SWATCH will be running as two processes. Besure to kill both processes in any stop/start scripts you create. That's it.Your sendmail logs will be automatically filtered. Whenever someone messes withyour sendmail system, you'll be instantly notified via email, with the matchedtrigger in the log included, as we've shown in Listings A andB.

Conclusion

Logs are powerful tools, yet they can easily overwhelm us with data. When thishappens, we start ignoring this valuable resource because we don't have time toscan through megabytes of data. Automating the filtering of such logs solvesthe problem. These automated filters do the work for us, alerting us in realtime with the information we need. We hope this article has given you some goodideas on how to automate the filtering of your log files.
 

<< Back to Tech Corner