Robust event logging with Syslog

Syslog is a fast, flexible, and easily extendable logging system

An important part of any project, logging can be used as a debugging tool during development, and a troubleshooting tool once a system has been deployed in a production environment. Because most developers only implement logging if time permits, it is often implemented haphazardly. However, logging provides a way to see what is happening, good or bad, inside a running system. As such, it should be addressed with care and forethought rather than as a last minute burden.

Syslog is an open source logging system that allows programmers to easily add diagnostic and status logging to their Java programs. It separates the act of logging an event from the actual handling of that event. Simple configurations may instruct Syslog to write all log messages to the console. In more elaborate configurations, Syslog can separate messages by almost any criteria, including severity, and send them to different files. These files can rotate based on time or file size and send email across a network via Remote Method Invocation (RMI) or Java Message Service (JMS). API calls allow configuration modification at runtime, and Syslog can save running configuration to an XML file for further refinement at a later time. In the case of application servers hosting multiple applications running in the same VM, message channels allow Syslog to route log messages coming from each application and handle them accordingly.

A list of log message handlers essentially constitutes Syslog. Each handler has a log policy that determines what messages it should consider. If the policy determines that the handler should deal with a given message, the logger uses a message formatter to prepare the message, and the handler then writes the message to a file or sends an email. The architecture is based on interfaces so that custom modules can replace each step.

Syslog provides the following features:

  • Simple, all-static logging API
  • Message severities
  • Pluggable log message handlers
  • Pluggable log-formatting modules for each handler
  • Pluggable log policy modules for each handler
  • Arbitrary log channels
  • A configuration that can be modified on the fly while running
  • A running configuration that can be written to a file for reload later
  • Email integration
  • Remote logging capabilities -- using RMI
  • JMS integration

Licensed under the GNU LGPL v2, Syslog is free for commercial and noncommercial use, with source code included. Though it was originally based loosely on the Unix Syslog facility, it now shares only its name. In this article, you'll learn how to easily integrate the Syslog package into your system by adding simple instrumentation to your Java code. You'll also uncover more elaborate ways to leverage Syslog in projects as an integral part of new system development. Syslog allows developers to concentrate on developing application code, not on how an operations department or hosting provider will handle logging.

Syslog for developers

Two groups of people will benefit from a logging system: developers and operations staffs. Developers need to be able to instrument their code with little effort; otherwise they'll never perform event logging. As you'll observe, you can instrument code with Syslog calls in a number of ways, ranging from the simple to the complicated.

Basic usage

Anytime developers want to issue a message to Syslog, they simply call a static method on the com.protomatter.syslog.Syslog class. There's no need to carry around a reference to an instance of Syslog to make calls. That greatly simplifies usage, as you also don't need to keep references to a logging object -- simply call static methods and that's it.

You can use 48 methods in the Syslog class to issue messages; however, it's unlikely that you will use most of them. All of those methods are pass-throughs to a single method that takes six arguments; the other 47 are simply included for convenience. Don't be intimidated by the large number: Syslog resembles a Swiss army knife in that respect -- though it features tools that you rarely use, they will release you from a jam when the time comes.

Developers usually mark up their code with log messages by peppering it with calls to System.out.println(); they invariably have to go back and comment those calls out before the system goes into production. If some calls are missed, operations will ask why the system prints "I'm in here" continuously while running.

One way to become accustomed to working with Syslog is to replace code like this:

  System.out.println("I'm in here");

with code like this:

  Syslog.debug(this, "I'm in here");

That approach requires less work than calling System.out.println() -- you actually need fewer keystrokes; and it's also more useful. Instead of receiving output like this:

  I'm in here

if Test.java made the call, Syslog will produce the code fragment below:

  10:52:53 01/08 [DBUG] Test          I'm in here

If Syslog is set to log the channel and thread name for each message, the output will look like this:

  10:56:44 01/08 [DBUG] [DEFAULT_CHANNEL] [main] Test       I'm in here

Later, when the system goes into production, messages at the "debug" severity level disappear, and nobody will wonder why the system prints "I'm in here" constantly.

Java code is often littered with exception-handling code and, unfortunately, many developers simply catch an exception and call its printStackTrace() method, which sends the stack trace to the System.err stream. Syslog features a utility method for exceptions: calling Syslog.log(this, x) where x is a java.lang.Throwable will produce output like the code below:

  10:40:32 01/08 [EROR] Test          java.lang.Exception: Crap!
  java.lang.Exception: Crap!
          at Test.bar(Test.java:37)
          at Test.foo(Test.java:28)
          at Test.main(Test.java:12)

The toString() method's output prints as the short description, a stack trace prints as the message detail, and the whole thing logs at the ERROR level. That proves a much better approach than spreading calls to x.printStackTrace() all over the code. As you'll see later, Syslog can route those kinds of messages to a separate log or even email them to a pager.

Message severity levels

Syslog messages each have an associated severity level that show the importance of each message. The levels are:

DEBUG
Generally referred to as breadcrumbs -- useful for letting the developer leave little hints here and there during the initial coding and debugging process.
INFO
Provides informational messages about what's happening, with notable events including user login and logout.
WARNING
Signifies that something bad has happened, but the system will attempt to recover from it. This message usually indicates that something is starting to go wrong.
ERROR
Indicates that something bad has happened, but the error won't cause the system to fail in general. A specific task may have failed, and some user may have received an error, but the system will keep running. Exceptions are generally logged at this level.
FATAL
Indicates that something horribly bad has happened, and most likely, the system is of little use to anyone. Someone should probably be paged, and sirens should sound.

It's important to actually use the different severity levels where they are appropriate. If you log every message in the system at the DEBUG level, the operations team will likely ignore all messages, even those that warrant immediate attention; that defeats the purpose of using severities in the first place.

API methods

Before we go further, let's look at the most commonly used logging methods that are available in the Syslog class. They fall into two groups:

  • xxx() and xxxToChannel(): where xxx is DEBUG, INFO, WARNING, ERROR, or FATAL. These are shortcut methods for each severity and have the following forms:

    xxx(Object logger, Object msg)
    xxx(Object logger, Object msg, Object detail)
    xxxToChannel(Object logger, Object chan, Object msg)
    xxxToChannel(Object logger, Object chan, Object msg, Object
    detail)
    
  • log(), which has the following forms:

    log(Object logger, Throwable t)
    log(Object logger, Throwable t, int level)
    log(Object logger, Object msg, Object detail, int level)
    log(Object logger, Object chan, Object msg, Object detail, int level)
    

Each of the above methods is also overloaded to take an InetAddress object as a parameter -- I have omitted them for clarity. It's fairly safe to assume that you will never use them, as Syslog uses them internally for remote logging. The rest of the methods' arguments are:

Object logger
The object making the log request. Generally, the logger argument is simply this, as in the example Syslog.debug(this, "I'm in here");. If there's no this reference where the logging call is made, as in a static method, simply pass in the current class object. For example, in the MyClass class, simply pass in MyClass.class instead of this. If you pass in a String, it will be used rather than that class name.
Throwable t
The log methods above that explicitly take a Throwable as an argument are convenience methods. The toString() method on Throwable is called, and the result is used as the msg argument. If the method takes a Throwable and does not take a level argument, the level defaults to ERROR. The Throwable itself is used as the detail argument.
Object msg
A short description of the message. The toString() method of whatever passes in will be called.
Object detail
If included, this argument is treated as a longer explanation of the message. If the object passed as this argument inherits from Throwable, then a stack trace is used.
int level
The severity of the message. There are constants defined in the Syslog class: Syslog.DEBUG, Syslog.INFO, Syslog.WARNING, Syslog.ERROR, and Syslog.FATAL.
Object channel
The channel name for the message, which can be one of two things: String or String[]. If the channel name is String[], the message dispatches to each channel specified in the array. The default value is Syslog.DEFAULT_CHANNEL.

Note: Exact formatting of the above arguments depends on what log-formatting module the logger handling the request uses. The above formatting explanations assume that the logger uses the default formatting module.

Message channels

Syslog supports arbitrary message channels defined on the fly -- one of its more advanced features. One VM on a server may host multiple projects, each of which wants to have its logs handled separately. If a channel is not specified, the messages go to a default channel, Syslog.DEFAULT_CHANNEL. The Syslog.ALL_CHANNEL channel broadcasts messages to every channel.

Suppose you have two projects -- "BigBank" and "SomeOtherBigBank" -- running in the same server VM. You might find it useful to log messages from the BigBank project to the BigBankChannel channel, and messages from the SomeOtherBigBank project to the SomeOtherBigBankChannel channel so that each channel can go to different sets of files, and different sets of people can be notified when bad things happen. There are two ways to accomplish that:

The first approach is to call versions of the log() methods that take a channel argument and specify the channel everywhere. That will quickly prove annoying, and developers will eventually either misspell the channel name somewhere or omit it altogether. The only way to mitigate that is to have some interface in the project that defines a constant like this:

  public interface BigBank
  {
    public static Object CHANNEL = "BigBankChannel";
  }

Then have every class specific to the BigBank project use it when calling log() methods, like so:

  Syslog.debugToChannel(this, BigBank.CHANNEL, "Hello there");

If the project grows fairly large, programmers will tire of this approach, and invariably, messages will leak out to other channels. Also, some classes may be common to both projects. As a result, the SyslogChannelAware interface exists, which is the second approach to logging messages to different channels:

  public interface SyslogChannelAware
  {
    public Object getSyslogChannel();
  }

Any object passed in as the logger argument to one of the log() methods that implements SyslogChannelAware (usually this) is asked what channels it wants to receive the message.

Why is that beneficial? Most objects in projects are built on top of more generic classes, like base classes from frameworks. If each of the base classes used in the system implements SyslogChannelAware, the developers writing subclasses never have to bother with channel names. The base class can read a channel list to use out of a configuration file or from some other source. That works particularly well for Enterprise JavaBeans and servlets since channels can be specified in deployment descriptors and init params for each. This kind of flexibility means that when a system moves into production, different subsystems can be configured to write messages to different log channels without making code changes. Programmers just continue making calls to Syslog.info() and other methods, and the messages are magically routed to the correct channel and handled accordingly.

Syslog internals

In order to get the most out of Syslog, you should understand how it operates and see what's going on under the hood. At its core, Syslog is pretty simple, and almost entirely based on interfaces, thus allowing custom implementations to override almost anything.

Architecture

1 2 3 Page
Join the discussion
Be the first to comment on this article. Our Commenting Policies
See more