Volume Number: 23 (2007)
Issue Number: 02
Column Tag: Mac in the Shell

More on Logs

Watching log files without really watching them.

by Edward Marczak

Last month's column dealt with reading and interpreting log files in a very generic sense. I typically go on at length about using logs to help troubleshoot and simply understand your system. Of course, each system you maintain will have logs to watch — multiple logs, in fact. So how could you possibly keep track of the activity in all of them at once? Well, we're talking about computers, right? This month, I'll be describing swatch, my favorite utility for letting me take my eyes off of scrolling text displays for a while, and know that I'll get alerted if there are any problems.

Of course, the other thing I tend to talk up a lot is automation. Turns out that computers can be pretty good at monitoring themselves — with the right software, of course. Enter swatch. Swatch began life as the "simple watcher" of logs. It's evolved past that quite a bit, but has retained the name. The current version is v3.2.1 and is written in perl.

Setup is incredibly straightforward for anyone comfortable on the command-line (which longtime readers now should be!), but does require some perl modules that are not included with the stock OS X install. To that end, we've created a package that installs swatch and all of its dependencies. You can download from ftp://ftp.mactech.com/src/. Double-click the .pkg file and let the installer do its thing. For those that want to handle this themselves, follow along. If you don't care about manual set up, feel free to skip ahead to "Running With the Files."

As always, bring up your favorite terminal app, and let's get started. Swatch has a repository on Sourceforge, and you can go hunt it down there. However, we already have a shell open, why not use it?!? Create a download directory and change into it. Then, download swatch using curl:

curl -O http://easynews.dl.sourceforge.net/sourceforge/¬ 
swatch/swatch-3.2.1.tar.gz

Untar it (tar xzvf swatch-3.2.1.tar.gz) and then change into the newly created swatch directory. Before we can successfully install swatch, however, we need to add some perl modules to our system. The easiest way is to utilize cpan — the Comprehensive Perl Archive Network. If you've never run cpan before, you'll need to go through a brief set up. sudo up to a root shell (sudo -s), as we're also going to install these modules now, and type cpan. You'll be asked if you're ready to perform manual setup. Take the default "[yes]" and off we go. Interestingly, you can literally take the defaults for the bulk of the questions — a testament to authors. You should, of course, read a little deeper. However, if you're not paying attention, you'll need to finally really answer a question when you're asked for mirror sites. Choose sites that are close to you, or that you know have a good chuck of bandwidth. Also, I like changing the default answer on "Policy on building prerequisites (follow, ask, or ignore)." The default is ask, however, if you want the module, you're going to want the dependency. So, after years of manually allowing the dependency each time, now, I set cpan up to "follow", which will automatically download and build the dependency. Let cpan go through its routine, and you'll finally be (unceremoniously) dumped at a "cpan>" prompt.

How do we know which modules to install? In addition to some information in the INSTALL file that comes with swatch, you'll get this if you try to make swatch with these modules:

Warning: prerequisite Date::Calc 0 not found.
Warning: prerequisite Date::Format 0 not found.
Warning: prerequisite Date::Manip 0 not found.
Warning: prerequisite File::Tail 0 not found.

So, from here, we need to install each one. Type:

install Date::Calc

at the "cpan>" prompt to install the first one. cpan will find and download the module, then compile and install it. It will find a dependency and either ask you, or if you told it to follow, just go download it itself. You will be asked if you want to add Object::Deadly to the tests. Just press return for the default of "no". Back to a cpan prompt with no errors? Great — let's repeat the process for the remaining three modules:

install Date::Format
install Date::Manip
install File::Tail

Once you're finally back at a cpan prompt after all of this, simply type "exit", "quit", or, if you're really hip, "q", to return to your shell prompt. You should still be in the swatch directory, and we can simply install swatch from here:

perl Makefile.pl
make
make install

There should be no errors reported, and you'll now have a working swatch in /usr/bin.

Now that swatch is installed, you may be anxious to get going. If you simply type swatch, you'll be disappointed. You'll get a message that you need a config file to do anything useful. Well, that's where we'll head next. Long time readers will remember my many pleas for you to learn regular expressions. Swatch configuration will vindicate me once again!

Swatch uses a simple configuration file that, at its most basic, contains patterns to look for, and actions to take if said pattern is seen. When you hear "pattern," you should immediately think of regular expressions and ruling the universe. Additionally, swatch lets you configure throttles so you don't act on log lines that are quickly, and repeatedly sent to the log file.

More specifically, a trigger definition in swatch consists of three parts:

A trigger pattern, once matched causes the action to run.

Action(s), or, what to do when the pattern is matched.

A length of time to suppress duplicate log entries (optional).

So, let's set up a fictional entry, and then we'll force 'errors' into the log. First thing to do is to create our swatchrc file. I can expound on different methodologies regarding where this file should live, but we'll keep it easy for now and use the default: ~/.swatchrc. So, create a file in your home directory (and, if you're still following along, you're sudoed up to root, but thanks to sudo, this will create it in the home directory of account you sudoed from) called .swatchrc (note the leading dot). Give it these contents:

watchfor /anecho/
echo
throttle 0:15:00
watchfor /thebell/
bell 3

Save it, and run swatch thusly:

swatch -t /var/log/system.log

and you should be greeted with an "I'm running" message like this:

*** swatch version 3.2.1 (pid:3251) started at Mon Jan 15 14:29:33 EST 2007

We didn't tell swatch to go into the background, so, it'll monopolize our terminal while it runs. For the sake of this example, that's good. Grab a second terminal (Apple-N or File->New Shell), and let's put this example through its paces. We'll use the logger command to inject new lines into the log. In the new, non-swatch-running terminal, type:

logger anecho

...and you should see the swatch window have a reaction: it echoes the log file line to the display. Type:

logger thebell

...and you should hear your system beep three times. Now, once again, type logger anecho. You won't get a second line on the swatch console. But another "logger thebell" will make swatch beep (again and again). What's going on here?

First, the command line switch "-t" tells swatch which file to monitor, or tail. On the first line of the definition, we tell swatch the pattern (regex) to watch for in the log file. This can be any perl regex you like. The line(s) following consist of the action(s) to take when the pattern is found. There are several, and I'll hit the ones that I find most useful. Finally, you can set a throttle, so that multiple, repeated lines in the log file don't cause you to trigger an action too many times. In our first definition, we used a throttle, that said, "don't repeat these actions inside of 15 minutes." So, if there's a matching entry in your log that is repeating every minute, you'll only see an action 4 times an hour. We didn't give the second entry a throttle, so it'll repeat its action as many times as it's triggered.

So, about now, all sorts of ideas should be running through your brain regarding how this could be useful. Let's look at some of the more useful actions that swatch will perform based on a pattern being triggered. You've already seen two: echo and bell. These are of incredible use if you want to set up a dedicated swatch console on some machine. Otherwise, you'll want some other way of being notified. For the sake of completeness, let's look at those options first.

An action of echo will simply echo the matching log file line to the console. As OS X users, however, that may not be very useful if swatch is running daemonized in the background and we don't even have a console open! Similarly, bell will ring the console bell the number of times specified.

A 'simple' action is mail. This action sends the matching log file to the address you specify. Check it out:

mail addresses=marczak\@radiotope.com,subject=Some\ Bad\ Error

Notice the need to escape the usual suspects. This action, when triggered, will send a fairly uninspired mail message with the specified subject to the specified address. However, depending on the systems and workflow you have in place, this may be all you need (e.g. — Help desk systems that require input via mail to create a trouble ticket, etc.) The trigger that uses a mail action is clearly one that you also want to throttle!

pipe is another way to feed the log line to an external program. As you may expect, swatch will pipe a matched line into the command you feed it. This is similar, but not the same as using exec — my favorite.

exec will run an external program, and pass it any part of the matched log line, or the entire matched line. Now all of those ideas running around your brain can be made reality. Between pipe and exec, you can pretty much do anything. exec can also pass along variables to the program it is calling. Passing $* will pass the entire log line. $N will pass the "Nth" field of the log line. Here's a good example swatchrc using these statements:

watchfor /error/i
exec /Users/Shared/fs.sh err $* 
exec echo $* | cat >> /Users/Shared/err.txt
continue
throttle 0:60:0
watchfor /warning/i
exec /usr/local/bin/flagdb.sh $*
continue
throttle 12:0:0

Some new elements here. Notice that we're using the "i" flag on the watchfor regex. This makes the match case insensitive. This will match "ERROR", "error", "Error", or any combination of upper and lower case. When we find "error", we run two actions — nothing wrong with that. Also, note the use of "continue" — without it, a matched pattern triggers the actions in its block and then stops. "continue" tells swatch to keep looking for pattern matches in the current line. The final 'new' thing here is that the second block uses a twelve-hour throttle. Again, nothing wrong with setting a wide time to suppress duplicate actions, however, make sure what you're setting is appropriate. If you're running a script that takes corrective action based on the pattern it finds, lower might be better. You could always create two matches on the same pattern with different throttle values; one could open up wide for notifications, and the other could be lower and take action.

Think about exec for a minute and the options available to you. Shell scripts, AppleScript code, perl or php that interacts with a database...anything, really. If you really want to impress your date, tie swatch in with Growl using growlnotify, and set Growl to forward (sticky) notifications to machines on the LAN...that's a hot combination!

It's what you don't know

A quick note on an interesting swatch directive: ignore. Often, you know what errors in your logs look like. Sure, you want to be notified about them. But, what about log entries you've never seen before? Swatch requires that you already be somewhat familiar with the contents of the log you're monitoring. Since swatch is supposed to get us away from staring at a log all day, what can be done? Figure out what you know, and ignore it.

The ignore statement is the exact opposite of watchfor. If there's a log file that you're pretty comfortable with, and just want to look for anomalies, use swatch to ignore all of the items that you already know, and alert you when something new to you crops up. There are no actions for ignore, however, swatch stops processing the log line when it sees a matching ignore, so, put these at the beginning of your swatchrc file.

The best thing about swatch may be its ability to monitor your entire organization. How? Remember, we're just feeding and watching syslog. A few months ago, MacTech published an article showing how you can have all of your machines log to a central Tiger server (which is now on-line at http://www.mactech.com/articles/mactech/Vol.21/21.09/ TipsNTidbits/). If this were any other Unix variant, I'd also have to tell you to create a new log that captures all entries. However, readers from last month will remember — we're special. We use OS X. We have the Apple System Log.

Use the "Centralized Device Logging" article (linked above) to allow syslogd to accept remote log entries. From there, you can set any syslog enabled device to send their log entries to it. This includes Mac clients, other servers (including Windows servers, using third-party software), hardware appliances such as firewalls, and more. Now, you can be alerted to warnings and errors (or whatever you please, really) from any device on your network, and potentially act on it. That's power!

Naturally, we don't want to have start a program like swatch manually, or have to tie up a console or ssh session to have it run. Again, OS X users are special, and we can create a launchd item to have swatch run at every boot. This is where, though, we get back to style. For a daemon that will run at boot and be able to manage the machine, rather than a single user, the configuration file belongs in a more universal location, like "/etc".

Using your text editor of choice, or Lingon, create the following file:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple Computer//DTD PLIST 1.0//EN"
¬ "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
   <key>Disabled</key>
   <false/>
   <key>Label</key>
   <string>com.radiotope.swatch</string>
   <key>OnDemand</key>
   <false/>
   <key>ProgramArguments</key>
   <array>
      <string>/usr/bin/swatch</string>
      <string>-c</string>
      <string>/etc/swatchrc</string>
      <string>-t</string>
      <string>/var/log/asl.log</string>
   </array>
   <key>RunAtLoad</key>
   <true/>
</dict>
</plist>

Save it as /Library/LaunchDaemons/net.sourceforge.swatch.plist. Note that, as mentioned, this launchd plist will run swatch and have it look for a config file in /etc named "swatchrc", and it will monitor the Apple System Log at /var/log/asl.log.

Watching logs is an incredibly important activity for the health and security of your network and networked machines. However, as humans, there's only so long we can keep our eyes on scrolling text. Plus, since logs typically contain both warnings, errors and notices ("good" information), it can quickly lead to information overload. Using a tool like swatch allows us to be alerted to the things that we deem important.

As noted last month, just about every subsystem logs. However, not every system logs using the system log, and may just drop a file somewhere else in the system (like Samba and Apache). Feel free to run a second instance of swatch with a custom swatchrc to monitor a second log file. Also, check the swatch man page one you have it installed. You can run swatch in batch mode — not even tailing a file in 'real-time,' change the line separator, create a stand-alone script, have swatch restart automatically (to pickup rolled log files), use an alternate tail application (which can resolve the former issue) and even create custom actions.

I was really thrilled to meet many readers at MacWorld this year. It really was a great week — I learned a lot, and really had my confidence in the Mac platform boosted even higher. Nowadays, there's just no reason not to buy a Mac (on the client side...servers are subject to more variables). Now, we have other Mac-related events to attend during the year (WWDC, Mac Networkers Retreat, SoCal Mac Fair and more).

Media of the month: Battlestar Galactica Season 1 DVD set. SciFi enough to satisfy the geek in you, and well written enough to keep you significant other watching, too. If you haven't been watching, check out the mini-series and season 1.

So, stop watching your logs...but make sure you're monitoring them! See you next month!