The Design of a Logging Utility

Whether or not you agree with my position that Debuggers are a Crutch, there is no doubt that logging is an extremely common and useful behavior for many classes of software — server-side processes, long-running GUI apps, utilities, etc. This page will outline and discuss a design for a logging utility that I’ve found to be extremely effective and successful.

Drivers

There are two main drivers for a logging utility: first, it must make it easy to create the content in the log; second, it must make it easy to use the content of the log.

To encourage content creation, the client API absolutely must be as friction-less and unobtrusive as possible. Creating log entries has to be drop-dead easy and painless. Clients should find the creation of log information to be as routine as adding parenthesis and braces — you don’t even really think about it, you just do it. Any sense that client programmers have that the logging API is intrusive or awkward or difficult will only reduce the amount of information the log contains, and thus its effectiveness.

Making log information “easy to use” is a more complicated issue because so much of it depends on the context of both what type of application is creating the content and under what conditions the content is needed. I’ll discuss a couple especially common scenarios below.

Creating the Log Information

Just to frame the rest of the discussion, here are some examples of using the client API for the logging utility:

Log.Info("Here is a logging comment");

Log.Warn("Ignoring exception: {0}", ex.Log());

These examples illustrate the three cardinal virtues of the logging utility. First, clients have instant access to the functions; no objects required. Second, both the typing required and the visual clutter of the logging code are minimized by keeping names short. And finally, it is extremely simple to directly format output.

Instant Access: If the client first has to create a logging object before they can log anything they are forced to answer a bunch of ancillary questions such as what form of the constructor should I use? how do I scope the object (and what are the performance implications of different choices here)? and how do I coordinate output from related scopes? None of this really has to do with the logging, but only with the implementation mechanism.

Provide static functions for logging; individual functions for different purposes. You can allow users to create a logging object in order to have finer-grained control if they need it, but don’t force them to create one. Hint: have your static functions just turn around and invoke the same functions on a hidden global singleton object — but don’t require the user to specify the singleton as in:

// this is bad
Log.Singleton.Info("clutter clutter");

Short: If the names involved (both the name of the class/object and the function) are longer than a handful of characters, focus is drawn away from the content being logged. What is even worse, the logging statements themselves draw the focus away from the surrounding code which is the real point of interest. Logging statements should be unobtrusive and concise.

Likewise, keep the calling sequences short. Don’t use an enum value to indicate a severity level:

logger.Log(Log.Severity.Warning, "blah blah blah");

but instead embed the severity level in the names as shown in the first example.

Directly Format Output: Few things are as irritating as being forced to use a string.Format call when it is inherent in the context. (This applies equally to constructors for Exception classes, but I digress…) Logging functions should always allow for directly embedding the formatting statements:

// this is good
public static void Warn(string format, params object[] args);

// this is evil
public static void Warn(string message);

Don’t force the user to jump through hoops to create content! Hoop-less logging…

To make it very easy to output more complex data — for example, stack traces associated with exception objects — use extension methods to make creating the logging string trivial. Note the use of a “Log()” extension method on an exception object in the first example above: you could make this even simpler by examining the args array in your logging function and automatically calling Log() on any exceptions you find…

Don’t enforce a particular structure on the logging messages — keep it as wide-open as possible to (again) encourage content creation.

Using the Log Information

So you have client code dumping copious amounts of log information into the utility. What does the utility do with it? There are lots of options:

  • Write it to a file
  • Forward it to the Windows Event Log
  • Forward it to the Windows trace library
  • Pop up a message box
  • Ignore it
  • Put it into a database

Depending on the context, any one of these options might be valid. In fact, more than one of them might be applied at the same time or at different times.

Only the top-most application has enough information to really make the determination on how best to treat logging information, where it makes the most sense for the user. The client simply doesn’t have enough information to determine how to route logging data — another reason that it is unwise to force the client to create a logging object — especially if the code is in a library that may be reused in multiple application contexts! The determination of the proper strategy needs to be left to the discretion of the top-level application.

For a back-end service, writing to a file probably makes the most sense. (Although you need to make sure you don’t fill up the disk with logging data.) But depending on the severity, you may also want to forward some logging messages to the Windows Event Log.

For a desktop application with a UI, a file may make sense. But the dynamic, interactive nature of a UI app lends itself to showing the log information as it is created, perhaps in an auxiliary window.

Web applications might simply put the most recent error log entry in a cookie and ignore all the rest.

Only the top-level application has the full view of the run-time context and can determine the most effective method for dispensing with log data. Of course, the logging utility should provide helper tools to handle some of the most common strategies: e.g. it should provide a default mechanism for writing to files while cropping old data to avoid eating the disk.

There are a variety of mechanisms that can be used to allow the hosting application to establish the policy: creating a “strategy” sub-class, a simple callback function, events, lambda functions… Choose your favorite. One of my favorites is this:

// in the host's initialization code...
Log.Handler = MyLogHandler;

// the definition...
private void MyLogHandler(Severity severity, string message)
{
    try {
        // make sure your logging doesn't bring down the system...
    }
    catch { }
}

Note that the host callback, unlike the client API, should just take the fully-formatted message. This allows the Log utility to care care of things like time stamps, convenience functions such as the Exception auto-formatting discussed above, etc.

Variations on the Theme

Standard data: Add a time-stamp, or information about the server or user name to each log statement in the centralized Log functions.

Allow objects: Allow the client to create Log objects and use them to handle the rare, special-cases where different, additional log handling is required. For instance, we might want a separate log of events that have to do with resource contention or other specific problems during the course of tracking down a heisenbug.

Tagging categories: Provide overloaded versions of the client logging functions that prepend additional arguments for things like category or sub-system tags. Or use formatting conventions to extract them out of the message text itself…

Log mining: Create a tool that can collate and filter log data from multiple sources (files, databases, etc.). This is especially useful in server-farms, and is often complemented by enforcing a higher degree of uniformity in the logging messages.

File tail: If any of your clients is writing log data to a file, provide (or download) a utility to monitor the tail contents of the file so that users can monitor log data in a shell window.

DIY vs 3rd-party

Why should you bother? Why not just use one of the many packages already available in both the open-source and proprietary worlds? Why, why, why?

My general thoughts on the topic are documented here. The particular reasons why I think you need to build your own logging utility are:

  1. It is vital to your success. Good diagnostics and retrospective logs pay for themselves almost instantly and become a core tool in any platform.
  2. The third-party alternatives I’ve examined all fail to make it as easy as possible to create content. Sometimes this is unavoidable since they are trying to satisfy a very large audience. You can be more selective.
  3. The third-party alternatives I’ve examined have lots of YAGNI and thus a higher learning curve. A high learning curve is the very first barrier to easy content creation.
  4. It’s easy and cheap. Build something minimal that covers your needs and is simple to use and you won’t need to invest a huge amount of time or effort.

For similar reasons, I’ve just provided a design sketch and left the implementation details as an exercise for the reader…

Advertisements

One Response to The Design of a Logging Utility

  1. Pingback: Article: The Design of a Logging Utility | Jeff K

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s