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. 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
alerting you with the information you need.
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.
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 on our Solaris system (/var/log/maillog for Linux).
goalith #cat /etc/syslog.conf
| grep mail
mail.debug ifdef(`LOGHOST', /var/log/syslog, @loghost)
The final 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.
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 expn 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 root. 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, "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. Swatch comes with a useful install script that will copy all the libraries, man pages, and perl files to their respective directories. You might need to compile and install several perl modules, the installation script will let you know. Once done installing, all that is left is creating a configuration file and then launching the program. You can download swatch here.
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 fields, the first two fields are required, the last two fields are optional. The first field is
where pattern is a regular expression that swatch is looking for. This is our trigger. The second field is
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 'throttle' (which is optional) is a time interval defined as
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,
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 email@example.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:
watchfor /Relaying denied|expn/
firstname.lastname@example.org,subject=--- Sendmail Alert! ---
throttle 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,email@example.com"
This field states email a warning to firstname.lastname@example.org, 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/swatchrc -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).
Example swatchrc config file
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.
Trigger for anyone attempting un-authorized mail relay from your sendmail server.
Oct 3 14:48:51 homer sendmail: OAA06704: ruleset=check_rcpt,email@example.com, firstname.lastname@example.org [18.104.22.168],reject=550 email@example.com... Relaying denied
Trigger for anyone attempting to utilize the expn command on your sendmail server.
Oct 2 20:28:37 homer sendmail: NOQUEUE: firstname.lastname@example.org[22.214.171.124]: expn root [rejected]
Lance Spitzner enjoys learning by blowing up his Unix systems at home. Before this, he was an Officer in the Rapid Deployment Force, where he blew up things of a different nature. You can reach him at email@example.com .
|Whitepapers / Publications|