Subject: Watching your log files
From: <Microsoft Internet Explorer 5¡Æ¢® AuAa>
Date: Sun, 17 Jun 2001 11:54:42 +0900

How to automate your log filtering
Watching Your
Logs
Lance
Spitzner
Last Modified: 19 July, 2000

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.

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 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.

Trigger that shows un-authorized IP addresses attempting to use our mail
server as a mail relay.

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 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
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

/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 'throttle' (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
[email-masked] 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/

echo=normal

mail=[email-masked],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,mail=[email-masked]"
This field states
email a warning to [email-masked], 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).

Example swatchrc
config file

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=[email-masked], relay=[email-masked]
[206.54.252.1],reject=550 [email-masked]... 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: [email-masked][206.54.252.1]: expn root
[rejected]

Author’s
bio
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-masked] .

Whitepapers /
Publications