blogs.teztech.com

This is the first is a series of articles about logging. In this first article, I will describe what I believe is a simple, yet useful logging API. In later articles, I’ll give some hands on practical advise. As I continue the series, I’ll add links to the new articles here:

• Simple Tracing and Logging for Asp.Net and .Net Command Line Applications

Wow, some programmers go crazy about logging.  Do a Google search for “.net logging” and you’ll see what I mean. Some of these libraries are huge.  While some applications may really need all the complexity these libraries offer, I have seen it severely abused on more than one occasion. Crank up a copy of Blackberry Enterprise Server (BES) and let it run for a week or two. You’ll find your Windows Event Viewer overflowing with all types of mysterious, confusing and generally useless messages.  In addition to the constant Event Viewer spew, if you let BES run unattended, you’ll eventually find that your BES hard drive is literally overflowing with many different log files all with obscure names and even more obscure contents.  Exchange Server has a similar problem where some logging is done in Event Viewer, other logging is done to text files. And none of the Exchange Server logging options ever seems to enable the simple email flow messages you need for common day to day administration tasks that I take for granted on our Linux email servers.

Is all this really necessary? After 20 years of programming, I’ve found that the following simple API is more than enough for all my needs:

LogMessage(componentName, severity, format[, formatArg1, formatArg2, ...])

Depending on your programming language and coding standards,  this simple function may need to be wrapped in a class. You might also wrap the function call in a macro to allow for conditional compilation and to keep from having to pass the same componentName over and over.

With this API in mind, you also need a fairly simple configuration system to automatically prefix the messages with time, date, and thread ID and direct messages to some combination of syslog, Windows Event Log, a text file (just 1, please!), console, system debugger, email (for Alerts – see below)  and user defined functions.

The componentName argument is best handled as a single string determined by the programmer. This keeps things simple, yet gives the programmer a lot of flexibility in both the presentation of messages and the ability to filter messages.

There is no sense in going overboard with adding lots of flexibility for the severity argument. It’s best to spell things out and keep them simple. You’re never going to get a group of programmers and system administrators to agree on the difference between “error”, “critical” and “alert”. I use an enumerated type with the following values:

• Debug – Low level messages of interest only to programmers. It should be easy to enable and disable output of debug messages. The only reason a user would enable debug messages is to create a log file to be sent to a programmer. Information messages may be sent to log files and/or UI elements, but they should never be sent to system facilities (such as syslog or the Windows Event Log).
• Information – Messages that let users know the program is doing what it supposed to do. Information messages are of most value for services where there is no interactive UI to demonstrate that the program is working properly. However, interactive programs can trap Information messages to display status messages during length operations. Information messages may be sent to log files and/or UI elements, but they should never be sent to system facilities.
• Warning – Messages to let the user know the program encountered a problem, but the problem is not completely unexpected. The program should be able to work around problems that result in warnings (possibly by retrying at a later time).  Warnings should be sent to all log files and system facilities.
• Error – Messages that need the user’s attention.  Errors should be sent to all log files and system facilities.
• Alert – Messages that need the user’s immediate attention.  The user should be woken from bed. Alerts should be sent to all log files and system facilities.

I’ve found that the most difficult choice is between Error and Alert. For example, at an ISP, email server problems are almost always Alert messages, while for home users or small businesses, email problem can wait until morning. If it’s not obvious, make everything an Error and assume the administrator will have some way to filter the messages to decide for himself which Errors are really Alerts.

The data type for the format argument depends on your programming language and I8N requirements and tools. For ease of programming, I much prefer to use String.Format style format strings (printf strings in C++ and PHP code).  

I could write an entire article about choosing the best method for formatting strings for output, but quickly:

For production applications, use formatting rather than composition:

• Do use: string output = string.Format(“A = ‘{0}’”, a)
• Do not use: string output = “A = ‘” +  a + “‘”;

As much as I love C++ and Bjarne Stroustrup (and understand the arguments for the ability to format user defined types in a safe and type safe manner), favoring formatting over composition leads to programs that are easier to write, easier to read and easier to translate.

If you need to translate your program into other languages, there are two schools of thought for handling literal strings that need to be translated:  

• In the Windows/Mac style system, each string is manually assigned a unique integer identifier and all strings are stored in a database of some kind (typically application resources). When the you need a string, you program a call to the database API, passing it the unique integer ID of the string to be retrieved as a lookup key. 
• In the gettext style system (UNIX like platforms),  translated versions of the strings are still stored in an external database (though typically in simple text files). However, the original strings created by the programmer (often English) remain in the code. The original strings are used as the lookup key to retrieve the translated string.

Kind of like the difference between using raw char* vs. a string class for low level string operations, the Windows style system is the most resource efficient. The gettext system is less tedious to program with and, for better or worse, more tolerant of errors. You can find tools to retrofit your old code for either style. Also, there are various kinds of tools for both systems that allow translators to translate application strings without access to program source code.

Since my API is a lowest common denominator, mapping my simple API to syslog and the Windows Event Log is fairly straightforward.