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

Leave Comments, Critiques, and Suggestions Here

Tango's Logging API

Logging is an essential function of most software applications. Historically, logging APIs have been designed in-house by development teams, usually providing nothing more than basic output to a file. Some go a step further and provide simple compile-time configuration options. Such simple implementations do not allow the flexibility that modern software demands.

Compile-time configuration of a logging system restricts a particular build to the same output. The most common configurations options are for release mode output and debug mode output. The release build is shipped to the customer and typically only logs enough information to indicate that the program is functioning properly, or when errors occur. Debug mode output is typically more verbose and is used to diagnose and troubleshoot problems. When a customer has a problem in the field, requiring them to download and run a different build of the software is inconvenient. Furthermore, there is no way to control how much debug information is output, or which sections of the program should be ignored. More compile-time configuration options could be provided to do so, but each configuration requires yet another build of the software.

Tango's logging API is based in large part on the popular Java logging API, Log4J. The API gives developers a great amount of flexibility by providing the means to configure the logging system at run-time. They can configure how much information is logged, which sections of the application are logged, where the log output is sent, and even the format of the output. The API is designed from the ground up with performance in mind so that even when logging extensively the impact on memory and performance is as small as possible.

This chapter of the manual examines Tango's logging API in detail. There are five major components of the API: Levels, Loggers, Appenders, The Hierarchy, and Layouts. We will look at each component in turn.

Loggers

Everything in Tango's logging API revolves around Loggers. All log output goes through Loggers and all configuration is done through Loggers. But in order to fully understand how to utilize Loggers effectively, it is important to understand the other features of the API. As such, our treatment of Loggers in this section will be brief. Here, we will only examine how to create a Logger instance. In each successive section, we will discuss the Logger interface as it relates to each API feature.

Creating a Logger

Loggers are not instantiated directly. In order to get a reference to a Logger object, the user must go through another class: tango.util.log.Log. The Log class is not instantiable. It provides a collection of static methods with which the user interacts. For now, we will only consider the following method:

static Logger lookup (char[] name);

Each Logger used in an application should have a unique name. The first time a name is passed to the above method, a new Logger instance will be created and a reference to it returned. Each consecutive time the same name is passed to the method, the same reference will be returned, i.e. one name is associated with exactly one reference.

Logger logOne = Log.lookup("One");   // a new Logger instance
Logger logTwo = Log.lookup("Two");    // a new Logger instance
Logger logThree = Log.lookup("One");  // the same instance as logOne

Note that lookup is case-sensitive, so that "One", "oNe", and "ONE" all refer to unique Logger instances.

Once a reference to a Logger instance is obtained, the user can write to the log or configure it. Writing to a log requires understanding Levels, while configuration requires understanding Hierarchies.

To make use of the Log and Logger classes:

import tango.util.log.Log;

Now we will examine the Logger interface in the context of Levels, Appenders, and The Hierarchy.

Levels

Even the most primitive logging systems usually provide compile time options to control the amount of information logged to disk. The reason is that disk IO can be expensive. Writing too much information to a log can adversely affect a program's performance. Things can get even worse when logging to targets other than disk, such as a network connection. Tango's logging API allows users to control, at run time, how much information is written to a Logger via the use of Levels.

Level Names

The Level is an enum that is accessed via the Logger class. No imports other than tango.util.log.Logger are required. A specific level is accessed via the following syntax:

Logger.Level.LevelName

Tango defines six log levels. Each Level is assigned a priority. Higher priority Levels take precedence over lower priority levels. When a Level is assigned to a Logger, any output designated with a lower priority Level will be ignored.

Following are descriptions of the six Levels. The descriptions, as given, are only guidelines. Developers are free to assign any meaning they see fit to each Level. The Levels are, from lowest to highest priority:

Trace

This Level is intended to be used for debug output. Because it has the lowest priority, enabling this Level on a Logger effectively causes the Logger to log all output.

Info

This Level is intended to be used for informational purposes. For example, this level might be assigned to output which provides performance metrics or other statistical data.

Warn

This Level is intended for logging warning messages. Some failures in an application are not necessarily errors, much as compiler warnings and compiler errors are different. What constitutes and error and what constitutes a warning is entirely dependent upon the developer's view. This Level allows the developer to make the distinction in logging output.

Error

Some errors are recoverable and not severe enough to cause program termination. It is for logging those such errors that this Level is intended.

Fatal

This Level is intended for logging errors which cause program termination.

None

This Level is unique in that it can only be assigned to Loggers and not to output. When a Logger is configured with this Level, all output through that Logger is ignored and not written to its target. That is to say, this Level turns off logging for a Logger.

Configuring Logger Levels

A Logger's Level is configured via the following method:

Logger setLevel (Logger.Level level = Logger.Level.Trace);

There are two items of note about this method: it returns a reference to the Logger instance to allow for method chaining; calling this method with no arguments defaults to the Trace Level. Also, there is another version of this method which takes an additional boolean argument. We will consider it after the discussion on Hierarchies.

To determine which Level is currently set, the following Logger method is used:

Logger.Level getLevel();

Finally, the following convenience method can be used to determine if a specific Level is set on a Logger:

bool isEnabled(Logger.Level level);

This method will return false if the Logger's Level is currently set to one of higher priority than Level. It will return true if the Logger's Level is currently set to level or to one of lower priority.

myLogger.setLevel(Logger.Level.Error);      // only Error and Fatal output

Logger.Level level = myLogger.getLevel();   // returns Level.Error

bool ret = myLogger.isEnabled(Logger.Level.Trace);  // returns false
ret = myLogger.isEnabled(Logger.Level.Info);        // returns false
ret = myLogger.isEnabled(Logger.Level.Warn);        // returns false
ret = myLogger.isEnabled(Logger.Level.Error);       // returns true
ret = myLogger.isEnabled(Logger.Level.Fatal);       // returns true

A Caveat

The None level is a special case. Because it is a higher priority than any other Level, the following method call will always return true.

bool ret = myLogger.isEnabled(Logger.Level.None);

As such, the above call cannot be used to determine if logging has been turned off for a particular Logger instance. In order to do so, the following call should be used instead:

bool ret = myLogger.isEnabled(Logger.Level.Fatal);

If this call returns false, then logging is completely disabled for myLogger.

In the following example, assume that myLogger is a valid Logger reference:

Assigning Levels to Output

There are two ways to assign a Level to log output. The first is to do so explicitly via the following Logger method:

Logger append(Logger.Level level, char[] msg);

This method returns the Logger instance for method chaining. If level is of equal or higher priority than the Logger's current Level, the message will be logged. Otherwise, it will be ignored:

myLogger.setLevel(Logger.Level.Info).append(Logger.Level.Info, "hello");
        // "hello" will be logged

myLogger.append(Logger.Level.Trace, "trace me");    // output ignored

There are also several convenience methods that assign a Level to the output automatically. Each method's name corresponds to a particular log level:

Logger trace(char[] msg);
Logger info(char[] msg);
Logger warn(char[] msg);
Logger error(char[] msg);
Logger fatal(char[] msg);

Appenders

When software is released to the wild, it is common to send all log output to disk. In the case of on-site tech support, the technician can pull up the logs to assist in troubleshooting. In the case of remote tech support, users can send the log files to the developers as email attachments, or perhaps through a tool provided by the developers. But what if a developer wants to view the output of a log in real time?

During the development process, it is inconvenient to open the log files after each run of the program. It would be much better to send log output to the system console. It's can also be useful to be able to see real time log messages remotely, perhaps via telnet or a custom client. Such techniques may even be a requirement for some server projects. The ability to configure log output targets at run-time would make it possible to switch from disk output to console or network output on demand. Tango's Appenders are designed to allow just that.

Configuring Appenders

Each Logger instance needs to know where to send its output. But restricting a Logger to one output target would go against the goal of flexibility. As such, Tango allows each Logger to have multiple Appenders attached.

Attaching an appender to a Logger is done with the following method:

Logger add(Appender appender);

To remove all appenders from a Logger:

Logger clearAppenders();

Both methods return a reference to the Logger for method chaining. Note that there is currently no way to remove a single Appender.

When output is sent to a Logger with no Appender attached, there are no errors or thrown exceptions. The call will silently fail.

Stock Appenders

For most users, it is not important to understand the Appender interface. Tango ships with several stock Appender implementations that will cover most common logging needs: AppendConsole, AppendFile, AppendFiles, AppendSocket, AppendMail, and AppendNull.

It should be noted that all of the stock Appender constructors accept a Layout as an optional argument, which we will ignore in this section. See the section on Layouts for information on how to use them.

AppendConsole

This Appender, the simplest of the lot, directs log output to the operating system's stderr. It resides in the module tango.util.log.AppendConsole? and has one constructor:

this (Layout layout = null);

Usage:

// send output of myLogger to stderr
myLogger.add(new AppendConsole());

AppendFile

This Appender sends all output to a file. It is found in the module tango.util.log.AppendFile?. It has two constructors, one of which accepts a tango.io.FilePath? instance and another which accepts a path string:

this (FilePath fp, Layout layout = null);
this (char[] fp, Layout layout = null);

Usage:

// send output of myLogger to a log file named "mylog.log"
// in the current working directory
AppendFile fileAppender = new AppendFile("mylog.log")
myLogger.add(fileAppender);

...

// when finished with the file, it must be closed
fileAppender.close();

The file is opened in AppendFile's constructor and remains open until close is called. It should be noted that if the file already exists, it will not be overwritten -- all output will be appended to the file.

AppendFiles

This Appender logs to a group of files in turn. It is found in the module tango.util.log.AppendFiles?. Rather than writing to a single file, this Appender sends output to a group of files, rotating between each one when the the active file reaches a maximum size. Like the AppendFile, the AppendFiles accepts either a FilePath or a string in its constructors. The user also must specify the number of files in the group and the maximum size of each file.

this (FilePath p, int count, ulong maxSize, Layout layout = null);
this (char[] fp, int count, ulong maxSize, Layout layout = null);

In both cases, count must between 1 and 9 (inclusive). There is no limit imposed on maximum size.

Usage:

// send output of myLogger to a group of 5 files
// named mylog0.log, mylog1.log, mylog2.log, mylog3.log
// and mylog4.log in the current working directory. Each
// log will have a maximum size of 1 MB (1024 * 1024 bytes)
myLogger.add(new AppendFiles("mylog.log", 5, 1024*1024));

In this example, the AppendFiles will begin sending output to mylog0.log. When the size of that file exceeds 1 MB, output will be shifted to mylog1.log. This process will continue. When mylog4.log, the last in the group, becomes full, output will shift back to mylog0.log to repeat the process. When a file becomes the output target again, it is truncated so that any existing log output it contains is lost.

AppendSocket

This Appender allows remote logging by sending output to a socket. This class can be accessed by importing tango.util.log.AppendSocket?. It has one constructor, which accepts a tango.net.InternetAddress? as an argument.

this (InternetAddress address, Layout layout = null);

Usage:

// send output of myLogger to localhost, port 17000
AppendSocket sockAppender = new AppendSocket("127.0.0.1", 17000);
myLogger.add(sockAppender);

...

// when finished with the AppendSocket, the network connection
// must be closed
sockAppender.close();

Assuming that a server is listening on 127.0.0.1:1700, the above example will open and maintain a TCP connection with it and send myLoggers output to it. The connection is opened in SocketAppenders constructor and maintained until close is called.

AppendMail

This Appender sends each log output as email. This class is defined in tango.util.log.AppendMail?. It has one constructor, which accepts a tango.net.InternetAddress? as an argument along with the relevant email fields: from, to, and subject.

this (InternetAddress server, char[] from,
      char[] to, char[] subj, Layout layout = null);

Usage:

// email all of myLogger's output to logging@mycompany.com
myLogger.add(new AppendMail(mySMTPAddress, "MyProgram",
                     "logging@mycompany.com", "Log Entry"));

This Appender need not be explicitly closed, as no connection is maintained. Each time output is appended to the Logger, via append or one of the Level-specific methods, a new email is constructed and sent for that message. As such, this Appender should be used sparingly and in specific circumstances.

AppendNull

The tango.util.log.AppendNull? does nothing. It is useful as a template for creating custom Appenders. It could also be used for benchmarking.

The Hierarchy

Unlike Levels and Appenders, hierarchies are not configurable. provide a convenient means of grouping Loggers together. This allows new Logger instances to automatically be configured upon creation. It also allows for Appenders to be configured for several Loggers at once.

The Logger Tree

Conceptually, each Logger instantiated can be viewed as a node in a tree. When a new Logger instance is created, it is inserted into the appropriate position in the tree. The Logger at the node above the new instance becomes its parent. The new instance inherits the Level and Appender configuration of its parent. This is a powerful feature that allows entire groups of Loggers to be configured at once.

The Root Logger

Internally, Tango's logging API maintains a special Logger instance, the root logger. The only way to get a reference to the root logger is by the following:

Logger root = Log.root;

Note that calling Log.lookup("root") or Log.lookup("Root") will both return references to different Loggers, not the root Logger. Also, while it is possible to do all of an application's logging through the root Logger, it is recommended that this not be done.

The purpose of the root Logger is to establish a minimum configuration. Since the root Logger is, either directly or indirectly, the parent of every Logger created, it is the best place to establish the default configuration.

By default, no configuration is set up. The following compilable example demonstrates:

import tango.util.log.Log;

void main()
{
    Log.lookup("test").info("Hello Tango!");
}

Compiling and running this example results in no output at all. While it would be possible to configure the Logger named "test", it is better to configure the root Logger. Configuring "test" would mean that any Loggers that are not children of "test" would not receive a default configuration. The following example prints "Info test - Hello Tango!" to stderr:

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

void main()
{
    Log.root.add(new AppendConsole());
    Log.lookup("test").info("Hello Tango!");
}

How Loggers Fit the Hierarchy

The Logger hierarchy is constructed from Logger names and, as such, is completely transparent to the user. But the user does have control over where a particular Logger instance fits in the hierarchy. Consider the following:

Log.lookup("one");
Log.lookup("two");
Log.lookup("three");

In this case, three Loggers are created. Each Logger will be direct children of the root Logger and inherit its configuration. The next example demonstrates how to extend the hierarchy:

Log.lookup("one");
Log.lookup("one.two");
Log.lookup("one.two.three");

This time, only the first Logger, "one", is a direct child of the root Logger. The second, second Logger, "one.two", is a child of "one", while "one.two.three" is a child of "two". So to establish a hierarchy, names must be separated by '.'.

Conveniently, since D's package and module system follows the same convention, it is easy to associate Loggers with specific modules or classes. However, since rootLogger-lookup must be done at runtime, initialization of static loggers must happen in a static constructors of the class or module.

module mypackage.mymodule;

Logger logger;
static this()
{
    logger = Log.lookup("mypackage.mymodule");
}

class MyClass
{
    Logger logger;
    static this()
    {
        logger = Log.lookup("mypackage.mymodule.MyClass");
    }
}

How Many Instances?

To be perfectly clear, the first time any dot-separated name is passed to lookup, only one Logger instance is created:

Log.lookup("mypackage.mymodule");

Here, if no instance of "mypackage" has been previously created, then it is not created now. In that case, the Logger named "mypackage" will only be a conceptual Logger in the hierarchy and not a real instance. The new instance will inherit the configuration of the root Logger in that case. However, as the following example demonstrates, this is all hidden from the user:

Log.lookup("mypackage.mymodule").info("Foo");
Log.lookup("mypackage").info("Bar");

In this case, even though the Logger "mypackage.mymodule" was created first, the Logger "mypackage" will still be inserted into the hierarchy in the appropriate place -- as a direct child of the root Logger and the parent of "mypackage.mymodule".

The user never need be concerned whether or not an instance returned by lookup is new or not, or whether a child is created before the parent. Just be aware that an instance is created only when a Logger by that name does not already exist and that only one instance will be created at a time, no matter the number of dots in the name.

The Hierarchy and Appenders

Coming soon.

The Hierarchy and Levels

Coming soon.

Layouts

The third and final configuration option for Tango's logging API controls the format of log output. In the section on Appenders, it was noted that all Appenders take an optional Layout parameter. Appenders interact with the Layout interface to construct the final output text. Most users will never need to touch the Layout class, though understanding the different stock Layouts is useful. Those implementing custom Appenders will need to be familiar with the Layout class interface. Only when implementing a custom Layout is more detail needed. First, we will examine the stock Layouts and then discuss what is required to implement a custom Layout.

Stock Layouts

Tango ships with 5 stock Layout implementations: SpartanLayout, SimpleLayout, SimpleTimerLayout, DateLayout, and !Log4Layout.

SpartanLayout

This is a very basic Layout which prints the name of the Logger followed by the output text. It is found in the tango.util.log.Layout module.

Example Output:

myLogger - Hello Tango!

SimpleLayout

This Layout prefixes the output with the Level name and Logger name. It is found in the tango.util.log.Layout module. It is also the default Layout created by the base Appender class when no Layout is given to an Appender constructor.

Example Output:

Info myLogger - Hello Tango!

SimpleTimerLayout

This Layout prefixes the output with the number of milliseconds since the application started, the Level name, and the Logger name. It is declared in tango.util.log.Layout.

Example Output:

1 Info myLogger - Hello Tango!

DateLayout

This Layout prefixes output with ISO-8601 date information, followed by the Level name and the Logger name. It is found in tango.util.log.DateLayout?.

Example Output:

2007-01-01 01:00:28,001 Info myLogger - Hello Tango!

Log4Layout

This layout prints XML output which conforms to the Log4J specifications. It is found in tango.util.log.Log4Layout.

Example Output:

<log4j:event logger="root" timestamp="1168574079907"
             level="Info" thread="{unknown}">
    <log4j:message><![CDATA[Log4]]></log4j:message>
    <log4j:properties>
        <log4j:data name="application" value="tango"/>
        <log4j:data name="hostname" value="network"/>
    </log4j:properties>
</log4j:event>

The Layout Interface

The abstract Layout class defines four methods. When implementing custom Appenders and Layouts (explained in the next section) it is important to understand the purpose of these methods:

abstract char[]  header (Event event);
char[] footer (Event event);
char[] content (Event event);
final char[] ultoa (char[] s, ulong l);

The header, footer, and content methods should be overridden by custom Layout subclasses to provide the proper formatting. Because the header method is abstract, it must be overridden by subclasses. The default footer implementation returns an empty string, while the default content implementation returns the raw output string originally passed to a Logger.

Appenders call the header, footer and content methods in order to append the formatted output to the final output buffer.

The ultoa method is a convenience method which converts a millisecond time value to a string.

Custom Appenders and Layouts

When the stock Appenders and Layouts don't meet a project's logging requirements, developers can implement their own. This section explains what is needed to do so.

Custom Appenders

All Appenders must derive from the abstract tango.util.log.Appender. It declares three abstract methods which must be overridden:

abstract Mask getMask ();
abstract char[] getName ();
abstract void append (Event event);

The Appender class also maintains a reference to its Layout. This reference can be set and fetched by subclasses via the following two methods:

void setLayout(Layout layout);
Layout getLayout();

Masks

Because Logger output propagates up the Hierarchy to parent Loggers, it is possible that the output could pass to multiple appenders with the same target. Masks are used internally to ensure that any given output is sent to a particular Appender exactly once. This means that each Mask must uniquely identify an Appender. To create a Mask, an Appender must call its register method with a unique string.

protected Mask register (char[] tag);

What constitutes a unique string depends on the nature of the Appender. For example, since there is only one stderr on a user's system, the AppendConsole uses its class name as the argument to register. This ensures that even if multiple instances of AppendConsole exist, output will only be printed to stderr once even when it is sent to each instance. SocketAppenders create masks from the internet address given in the constructor, MailAppenders from a concatenation of the to and subject fields. Whatever the string used to create the mask, it should uniquely identify the output target such that no output is sent to the same target twice.

Names

The getName method is expected to return the name of the Appender's class, hence all implementations should generally be of this form:

char[] getName ()
{
    return this.classinfo.name;
}

It's possible, of course, to return a hardcoded string, such as "MyClass?". But using the above approach ensures that the result of calling getName will always be correct, even when a class is refactored and the name changed.

Appending

Externally, output is appended to a Logger in the form of strings. Internally, the output is converted to a tango.util.log.Event instance. Events contain a lot of useful information about an output string which is intended to be used by the Layout assigned to an Appender. As such, the Appender can ignore the data an event object contains and pass it on to the formatting methods of the Layout object.

When the append method is called, the Appender should pass the Event parameter to each of the following Layout methods in turn: header, content, and footer. The string returned from each method should be appended to a final output string and, finally, the buffer sent to the output target.

A Custom Appender Example

The following example shows an Appender that sends output to stdout. This could, perhaps, be implemented to extend AppendConsole, but it is implemented as a separate class for demonstration purposes.

// public import of tango.util.Event and tango.util.Layout
import tango.util.log.Appender;

import tango.io.Console; // for Tango's stdout interface - Cout

class StdoutAppender : Appender
{
    private Mask mask; // stores the value returned by the register method

    this(Layout layout = null)
    {
    // get a unique mask for this Appender. Because there is only one stdout,
    // it makes sense in this case to pass the class name to the register
    // method. This will ensure that even if multiple instances of this
    // class are found in the Hierarchy, any given output will only be
    // sent to stderr once
    mask = register(getName());

    // the default Appender constructor sets the Layout instance
    // to a new SimpleLayout, so the Layout passed to this constructor
    // should be given to setLayout to change the default.
    setLayout(layout);
    }

    Mask getMask()
    {
    return mask;
    }

    char[] getName()
    {
    return this.classinfo.name;
    }

    void append(Event event)
    {
    // fetch a reference to the layout
    Layout layout = getLayout();

    // append the formatted output to the current stdout line
    Cout.append(layout.header);
    Cout.append(layout.content);
    Cout.append(layout.footer);

    // calling Cout.newline will flush the output
    Cout.newline;
    }
}

Inspection of Tango's source will reveal that this class is identical to the AppendConsole, with the exception that Cout is used rather than Cerr. Anyone wanting to implement a custom Appender would be well served to examine the source of the stock appenders to see how they are implemented.

Custom Layouts

Implementing a custom Layout is no more difficult than implementing a custom Appender. Before discussing the required steps, a brief examination of the tango.util.log.Event object would be useful.

Events

When a string is passed to a Logger through one of its append methods, it goes on a journey through Appenders, Layouts and the Hierarchy. Before that journey begins, the string is assigned to an Event object pulled out of a free list. The following methods are available to obtain information from an Event:

char[] getName

Returns the name of the Logger to which the output was originally given.

Logger.Level getLevel()

Returns the Level assigned to the output.

char[] getLevelName()

Convenience method that returns a string representaion of the output Level.

ulong getTime()

Returns the time, in milliseconds, that the output was produced relative to the start of program execution.

ulong getEpochTime()

Returns the time, in milliseconds, that the output was produced relative to January 1, 1970.

char[] toUtf8():

Returns the original output string.

Event objects also maintain a special scratch buffer that Layouts can use to construct formatted strings. This is a convenient means of allowing string manipulation without allocating more memory. Text can be appended to the scratch buffer via the append method and the content of the scratch buffer can be obtained via the getContent method:

Event append(char[] x);
char[] getContent()

Another convenience method returns the number of milliseconds since the application was started. This is a static method:

static ulong getRuntime ()

Implementing a Custom Layout

Since the Layout's header method is abstract, all custom Layouts must implement it. If the format of the original output string is to be altered, the content method must be implemented. If text is to be appended to the end of the original output string, the footer method should be implemented.

The following example, CapLayout, prepends output with the Level name, converts the original output to upper case, and appends the output with the Logger name. It makes use of the Event object's scratch buffer to construct the formatted strings.

import tango.util.log.Layout;
import tango.text.Ascii;

class CapLayout
{
    char[] header(Event event)
    {
        event.append(event.getLevelName()).append(" - ");
        return event.getContent();
    }

    char[] content(Event event)
    {
        return toUpper(event.toUtf8());
    }

    char[] footer(Event event)
    {
        event.append(" - ").append(event.getName());
        return event.content();
    }
}

Dependency Graph

Click here for a dependency graph of the logging package. It shows import relationships between modules, and has hotspots to the relevant module documentation. See Dependency Graphs for more information.