Download Reference Manual
The Developer's Library for D
About Wiki Forums Source Search Contact

Leave Comments, Critiques, and Suggestions Here?

Learning About Logging

Logging is an essential function of most applications. A good logging system is critical for debugging software in the wild, but can also be used for other purposes, such as reporting useful application metrics. Unfortunately, logging can become a CPU-intensive operation if much data must be written to the hard drive or printed to the system console. Thus, it is important that a logger be configurable at run time so that specific operations can be turned on only when they are needed. It is also important for some applications to be able to configure the output target -- in an application that allows remote debugging capabilities, for example, it would be extremely beneficial to send logging output to a networked client rather than to a disk file.

Programmers with a Java background may be familiar with a logging package called Log4J. Log4J is a robust, flexible, high-performance logging API that has become quite popular in the Java world. Those coming to D with Log4J experience will find themselves on familiar ground, as Tango's logging package, tango.log, is based on the popular Java library. They should keep in mind, however, that there are some notable differences.

This tutorial is an introduction to tango.util.log. The goal is to acquaint users with the basics of the API so that they may immediately put it to use in their own applications.

Hierarchies

When using tango.util.log, it is important to remember that a single logger does not equivocate to a single file or other output target. Multiple loggers can be used to write to multiple targets, identical or not. A logger, represented by an instance of tango.util.log.Logger, can be conceptualized as a dispatcher. Given a set of rules and one or more destinations, the Logger will dispatch messages accordingly.

In order to ease maintenance of rules and destinations, Loggers are placed into a hierarchical system upon creation. Adjusting the rules and destinations at one level of the hierarchy affects all sublevels. This gives the programmer extreme flexibility in logging configuration.

Loggers are created and accessed by name. Hierarchies are derived from the Logger names using dot notation. This is convenient for D programmers, as it corresponds to the packagename.modulename.classname convention used by D. When a Logger is created, it inherits the properties of the Logger directly above it in the hierarchy. Here is some code to illustrate:

module mypackage.mymodule;

import tango.util.log.Log;

auto mymoduleLogger = Log.lookup("mypackage.mymodule");

There are a few items of note in the above example. First, the tango.util.log.Log module publicly imports tango.util.log.Logger, so it need not be imported separately. Second, Logger instances are never instantiated directly. When Log.lookup is called, it attempts to find the Logger instance associated with the given name. If no Logger is found, it creates and returns a new instance. Finally, the name of the new Logger is "mypackage.mymodule". In terms of the hierarchy, if another Logger named "mypackage" has been configured, the new Logger will inherit its properties.

When new Loggers are created and no Logger has been created above them in the hierarchy, they are attached to a special Logger called "root". The root Logger is the parent of every Logger in the hierarchy. In the above example, if no Logger named "mypackage" had yet been created, then the "mypackage.mymodule" Logger would have inherited the properties of the root Logger.

The root Logger can be accessed directly in the special Log.root method:

import tango.util.log.Log;

auto root = Log.root;

The root Logger, like any other, can be written to, but it is generally used just to set the default configuration. Since Logger names are, by default, printed with log output, it is more informative to use unique Loggers rather than the root.

Levels

In order to facilitate run time configuration of different types of Log output, tango.util.log defines 6 levels of logging. Levels define the rules a Logger uses to determine which messages to print and which to ignore. Levels are ranked according to precedence, with the lowest in rank taking precedence over those above it. Following is a list of levels, from the lowest to the highest precedence (highest to lowest rank):

Trace - this is the default level intended to be used for debug output. Log4J users should be aware that this is the equivalent of that API's DEBUG level. Trace was used in tango.log because 'debug' is a keyword in D. Also, there is no ALL equivalent in tango.log, so Trace is used to enable logging for all levels. Calling setLevel with no arguments enables this level by default.

Info - this level is intended to be used for informational messages, i.e. those that aren't errors and aren't used primarily for debugging.

Warn - this level is intended for logging warning messages.

Error - this level is intended for logging non-fatal error messages.

Fatal - this level is intended for logging fatal error messages.

None - setting this level turns logging off entirely. Log4J users should be aware that this is the equivalent of that API's OFF level.

The intent behind each level, with the exclusion of None, is a guideline for tango.util.log users. What each level means in practice is entirely up to the programmer, though it is a good idea to follow the general guidelines above for consistency.

To set the level of a Logger, the Logger.level method is used. To determine the level of a Logger, either Logger.level or Logger.enabled can be used. Passing any level value to a Logger means that logging will be enabled for all messages matching that level's rank and lower. So enabling the Trace level means that all levels are enabled, while enabling the Error level means only the Error and Fatal levels are enabled.

The level of a message can be specified in two ways, either via the Logger.append method, or by using one of the shorthand methods named for each level. The following code illustrates how to manipulate logging levels.

module mypackage.mymodule;

import tango.util.log.Log;

void testLogger()
{
        auto logger = Log.lookup("mylogger");

	// Enable Info, Warn, Error, and Fatal levels
	logger.level = logger.Info; 
	
	logger.append(logger.Info, "This is an info message.");
	logger.info("This is an info message, too.");
	
	logger.trace("This is a trace message and won't be printed.");
	logger.append(logger.Trace, "This is a trace message, too, and also won't be printed.");
	
	logger.level = logger.Error; // enable logging only for Error and Fatal levels
	
	logger.trace("This message won't be printed.");
	logger.info("Neither will this one.");
	logger.warn("Nor this one.");
	logger.error("But this will.");
	logger.fatal("And this will, too.");
	
	// This turns logging off completely for logger
	logger.level = logger.None;	
}

Appenders

Every Logger needs to know where to send its output. In tango.util.log, Appenders handle the task of sending the output to its final destination. No Appenders are configured by default. If the above example were to be used as-is in an actual program, it wouldn't print any output since no Appender is configured. tango.util.log includes a handful of useful Appenders that are ready for use.

AppendConsole - prints output to the system console.

AppendFile - prints output to a file.

AppendFiles - prints output to one of a group of files, moving on to the next file in the group when the current one reaches a maximum size.

AppendSocket - prints output to a network socket.

AppendMail - sends output to an email server.

AppendNull - sends output nowhere. Useful as a placeholder or for benchmarking.

AppendConsole is the only Appender we will consider, as the others rely on packages other than tango.util.log and are beyond the scope of this basic tutorial.

To assign an Appender to a Logger, the Logger.add method should be used. As the name suggests, this method does not replace any existing Appenders already assigned to the Logger, meaning multiple Appenders can be assigned to one Logger. By default, the Logger will output to all Appenders assigned to it. It will also pass output to the Logger above it in hierarchy. This latter behavior can be changed by a call to Logger.additive. Calling Logger.additive will give the current state, returning false if the Logger is configured to not pass output up the hierarchy.

The following example demonstrates how to configure an Appender and print text using a Logger. It is a working program that can be compiled and executed.

module logtest;

import tango.util.log.Log;
import tango.util.log.AppendConsole;

void main()
{
	auto logger = Log.lookup("mylogger");
	logger.add(new AppendConsole);
	logger.info("Hello Tango.Log!");	
}

Additional Notes

Level Testing

Sometimes it is necessary to concatenate several strings into one or perform some other expensive operation to derive log output. When that particular string is being constructed for a log level that is not enabled, it could potentially impact performance. Debug messages are particularly prone to this. In such situations,it is a good idea to test if the level is enabled before constructing the string.

if(logger.trace)
{
	char[] output = doExpensiveOutputConstruction();
	logger.trace(output);	
}

The Config

tango.util.log includes a special nodule that will automatically configure the root Logger to append to the system console. Doing so means that every Logger object created will have the ability to log to the system console by default. Just import it to make it operate.

import tango.util.log.Log;
import tango.util.log.Config;

void main()
{
	// test it
	Log.root.info("Hello Root Logger!");   
}

Layouts

Anyone running the logtest example from the Appenders section of this tutorial and comparing its output to that of the Config examples just above will notice that the output is different -- the latter examples have output a number just before the Logger name. That is because the Config uses an advanced feature of the tango.util.log called Layouts. In tango.util.log, the final format of the output text is configured independently of the Appenders. Config uses a special Layout called LayoutTimer, which can be found in tango.util.log.Log. Additionally, tango.util.log.LayoutDate and tango.util.log.LayoutChainsaw define two layouts that are more complex.

Layouts are a powerful feature and are mentioned here for completeness, though the details are beyond the scope of this basic tutorial.