Logback Project

• Introduction
• News
• Download
• Documentation
• Mailing Lists
• Source Repository
• Bug Report
• License
• Log4j Properties Translator
• Logback Team

Short introduction

Copyright © 2000-2006, QOS.ch This work is licensed under a Creative Commons Attribution-NonCommercial-ShareAlike 2.5 License .

Introduction

Logback is intended as a successor to the popular log4j project. It was designed by Ceki Gülcü, the founder of the log4j project. It builds upon a decade long experience gained in designing industrial-strength logging systems. The resulting product, logback is faster with a smaller footprint than all existing logging systems, sometimes by a wide margin. Logback also offers unique and rather useful features such as Markers, parameterized logging statements, conditional stack tracing and powerful event filtering. These are only few examples of useful features logback has to offer. For its own error reporting, logback relies on Status objects, which greatly facilitate troubleshooting. You may wish to rely on Status objects in contexts other than logging. Logback-core bundles Joran, a powerful and generic configutation system, which can be put to use in your own projects for great effect.

This document presents the more basic concepts in logback, enough to get you started.

Logback architecture

Logback's basic architecture is sufficiently generic so as to apply under different circumstances. At present time, logback is divided into three modules, Core, Classic and Access.

The core module lays the groundwork for the other two modules. The classic module extends core. The classic module can be assimilated to a significantly improved version of log4j. Logback-classic natively implements the SLF4J API so that you can readily switch back and forth between logback and other logging systems such as log4j or JDK14 Logging. The third module called access integrates with Servlet containers to provide HTTP-access log functionality. The access module will be covered in a separate document.

In this document, we will write "logback" to refer to the logback classic module.

First Baby Step

Requirements

Logback-classic module requires the presence slf4j-api.jar, logback-core.jar in addition to logback-classic.jar on the classpath.

Let us now begin experimenting with logback.

package chapter1;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class HelloWorld1 {

  public static void main(String[] args) {

    Logger logger = LoggerFactory.getLogger("chapter1.HelloWorld1");
    logger.debug("Hello world.");

  }
}

The HelloWorld class is defined in the chapter1 package. It starts by importing the Logger and LoggerFactory classes defined in the SLF4J API, more specifically within the org.slf4j package.

On the first line of the main() method, the variable named logger is assigned a Logger instance retreived by invoking the static method getLogger in the LoggerFactory class. This logger is named "chapter1.HelloWorld1". The main method proceeds to call the debug method of this logger passing "Hello World" as an argument. We say that the main method contains a logging statement of level debug with the message "Hello world".

You will note that the above example does not reference any logback classes. In most cases, as far as logging is concerned, your classes will need to import only SLF4J classes. In principle, you will have to import logback classes only for configuring logback. Thus, the vast majority of your classes will only be cognizant of SLF4J API and oblivious to the existence of logback.

You can launch the first sample application, chapter1.HelloWord1 with the command:

java chapter1.HelloWorld1

Launching the HelloWorld1 application will output a single line on the console. By virtue of to logback's default configuration policy, when no default file is found to configure logback explicitely, logback will add a ConsoleAppender to the root logger.

20:49:07.962 [main] DEBUG chapter1.HelloWorld1 - Hello world.

Logback can report information about its internal state using a built-in status system. Important events occuring during logback's lifetime can be accessed through a StatusManager. For the time being, let us instruct logback to print its internal state. This is accomplished by a static method in the LoggerStatusPrinter class.

package chapter1;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.util.LoggerStatusPrinter;

public class HelloWorld2 {

  public static void main(String[] args) {
    Logger logger = LoggerFactory.getLogger("chapter1.HelloWorld2");
    logger.debug("Hello world.");
    LoggerStatusPrinter.printStatusInDefaultContext();
  }
}

Running the HelloWorld2 application will produce the following output:

20:49:07.962 [main] DEBUG chapter1.HelloWorld2 - Hello world.
|-INFO in ch.qos.logback.classic.BasicConfigurator@1c1ea29 - Setting up default configuration.

Logback explains that it configured itself using its default policy, which is a basic ConsoleAppender. An Appender is a class that can be seen as an output destination. Appenders exist for many different destinations including the console, files, Syslog, Socket, JMS and many more. Users can also easily create their own Appenders as appropriate for their specific situation.

The previous examples are rather simple. However, actual logging in a larger application would not be any different. The general pattern logging statements will not change. Only the configuration process will be different since you will certainly need a more specific configuration than what logback provides by default. As you will see later on in this document, configuring logback can be done in different flexible and powerfull ways. Note that, normally, you won't need to invoke LoggerStatusPrinter after your log statements.

Here is a list of the three required steps in order to enable logging in your application.

1. Configure the logback environment. You can do so in several more or less sophisticated ways. The BasicConfigurator is the simplest but also least flexible. More on this later.
2. In every class where you wish to perform logging, retrieve a Logger instance by invoking the org.slf4j.LoggerFactory class' getLogger() method, passing the current class name or the class itself as parameter.
3. Use this logger instance by invoking its printing methods, namely the debug(), info(), warn() and error(). This will produce logging output on the configured appenders.

Logger, Appenders and Layouts

Logger context

Loggers are named entities. Their names are case-sensitive and they follow the hierarchical naming rule:

For example, the logger named "com.foo" is a parent of the logger named "com.foo.Bar". Similarly, "java" is a parent of "java.util" and an ancestor of "java.util.Vector". This naming scheme should be familiar to most developers.

The root logger resides at the top of the logger hierarchy. It is exceptional in that it is part of every hierarchy at its inception. Like every logger, it can be retrieved by its name, as follows:

Logger rootLogger = LoggerFactory.getLogger(LoggerContext.ROOT_NAME);

All other loggers are also retrieved with the class static getLogger method found in the CHECK THE URLorg.slf4j.LoggerFactory class. This method takes the name of the desired logger as a parameter. Some of the basic methods in the Logger interface are listed below.

package org.slf4j; 
public interface Logger {

  // Printing methods: 
  public void debug(String message);
  public void info(String message); 
  public void warn(String message); 
  public void error(String message); 
  public void fatal(String message); 
}

Loggers may be assigned levels. The set of possible levels, that is DEBUG, INFO, WARN and ERROR are defined in the ch.qos.logback.classic.Level class. Note that in logback, the level class is final and cannot be derived as a much more flexible approach exist in the form of Marker objects.

If a given logger is not assigned a level, then it inherits one from its closest ancestor with an assigned level. More formally:

To ensure that all loggers can eventually inherit a level, the root logger always has an assigned level. By default, this level is DEBUG.

Below are four examples with various assigned level values and the resulting effective (inherited) levels according to the level inheritance rule.

In example 1 above, only the root logger is assigned a level. This level value, DEBUG, is inherited by the other loggers X, X.Y and X.Y.Z

In example 2 above, all loggers have an assigned level value. There is no need for level inheritence.

In example 3 above, the loggers root, X and X.Y.Z are assigned the levels DEBUG, INFO and ERROR respectively. Logger X.Y inherits its level value from its parent X.

In example 4 above, the loggers root and X and are assigned the levels DEBUG and INFO respectively. The loggers X.Y and X.Y.Z inherit their level value from their nearest parent X, which has an assigned level.

Printing methods

By definition, the printing method determines the level of a logging request. For example, if L is a logger instance, then the statement L.info("..") is a logging request of level INFO.

A logging request is said to be enabled if its level is higher than or equal to the level of its logger. Otherwise, the request is said to be disabled. A logger without an assigned level will inherit one from the context. This rule is summarized below.

This rule is at the heart of logback. It assumes that levels are ordered as follows: DEBUG < INFO < WARN < ERROR.

In a more graphic way, here is how the selection rule works. In the following table, the vertical header shows the the level of the logging request, designated by p, while the horizontal header shows effective level of the logger, designated by q.

Here is an example of the basic selection rule.

// get a logger instance named "com.foo", with an INFO level. 
Logger logger = LoggerFactory.getLogger("com.foo");
//set its Level to INFO
logger.setLevel(Level. INFO);
Logger barlogger = LoggerFactory.getLogger("com.foo.Bar");

// This request is enabled, because WARN >= INFO
logger.warn("Low fuel level.");

// This request is disabled, because DEBUG < INFO. 
logger.debug("Starting search for nearest gas station.");

// The logger instance barlogger, named "com.foo.Bar", 
// will inherit its level from the logger named 
// "com.foo" Thus, the following request is enabled 
// because INFO >= INFO. 
barlogger.info("Located nearest gas station.");

// This request is disabled, because DEBUG < INFO. 
barlogger.debug("Exiting gas station search");

Retrieving Loggers

Calling the LoggerFactory.getLogger method with the same name will always return a reference to the exact same logger object.

For example, in

Logger x = LoggerFactory.getLogger("wombat"); 
Logger y = LoggerFactory.getLogger("wombat");

x and y refer to exactly the same logger object.

Thus, it is possible to configure a logger and then to retrieve the same instance somewhere else in the code without passing around references. In fundamental contradiction to biological parenthood, where parents always preceed their children, logback loggers can be created and configured in any order. In particular, a "parent" logger will find and link to its descendants even if it is instantiated after them.

Configuration of the logback environment is typically done at application initialization. The preferred way is by reading a configuration file. This approach will be discussed shortly.

Logback makes it easy to name loggers by software component. This can be accomplished by instantiating a logger in each class, with the logger name equal to the fully qualified name of the class. This is a useful and straightforward method of defining loggers. As the log output bears the name of the generating logger, this naming strategy makes it easy to identify the origin of a log message. However, this is only one possible, albeit common, strategy for naming loggers. Logback does not restrict the possible set of loggers. As a developer, you are free to name loggers as you wish.

Nevertheless, naming loggers after the class where they are located seems to be the best strategy known so far.

Appenders and Layouts

The ability to selectively enable or disable logging requests based on their logger is only part of the picture. Logback allows logging requests to print to multiple destinations. In logback speak, an output destination is called an appender. Currently, appenders exist for the console, files, remote socket servers, to MySQL, PostgreSQL, Oracle and other databases, to JMS, and remote UNIX Syslog daemons.

More than one appender can be attached to a logger.

The addAppender method adds an appender to a given logger. Each enabled logging request for a given logger will be forwarded to all the appenders in that logger as well as the appenders higher in the context. In other words, appenders are inherited additively from the logger context. For example, if a console appender is added to the root logger, then all enabled logging requests will at least print on the console. If in addition a file appender is added to a logger, say L, then enabled logging requests for L and L's children will print on a file and on the console. It is possible to override this default behavior so that appender accumulation is no longer additive by setting the additivity flag to false.

The rules governing appender additivity are summarized below.

More often than not, users wish to customize not only the output destination but also the output format. This is accomplished by associating a layout with an appender. The layout is responsible for formatting the logging request according to the user's wishes, whereas an appender takes care of sending the formatted output to its destination. The PatternLayout, part of the standard logback distribution, lets the user specify the output format according to conversion patterns similar to the C language printf function.

For example, the PatternLayout with the conversion pattern "%-4relative [%thread] %-5level %logger{32} - %msg%n" will output something akin to:

176  [main] DEBUG chapter1.HelloWorld2 - Hello world.

The first field is the number of milliseconds elapsed since the start of the program. The second field is the thread making the log request. The third field is the level of the log statement. The fourth field is the name of the logger associated with the log request. The text after the '-' is the message of the statement.

Parameterized logging

Given that loggers in logback-classic implement the SLF4J's Logger interface, certain printing methods admit more than one parameter. These printing method variants are mainly intended to improve performance while minimizing the impact on the readability of the code.

For some Logger logger, writing,

logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));

incurs the cost of constructing the message parameter, that is converting both integer i and entry[i] to a String, and concatenating intermediate strings. This, regardless of whether the message will be logged or not.

One possible way to avoid the cost of parameter construction is by surrounding the log statement with a test. Here is an example.

if(logger.isDebugEnabled()) { 
  logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}

This way you will not incur the cost of parameter construction if debugging is disabled for logger. On the other hand, if the logger is enabled for the DEBUG level, you will incur the cost of evaluating whether the logger is enabled or not, twice: once in debugEnabled and once in debug. This is an insignificant overhead because evaluating a logger takes less than 1% of the time it takes to actually log a statement.

Better alternative

There exists a very convenient alternative based on message formats. Assuming entry is an object, you can write:

Object entry = new SomeObject(); 
logger.debug("The entry is {}.", entry);

After evaluting whether to log or not, and only if the decision is positive, will the logger implementation format the message and replace the '{}' pair with the string value of entry. In other words, this form does not incur the cost of parameter construction in case the log statement is disabled.

The following two lines will yield the exact same output. However, in case of a disabled logging statement, the second variant will outperform the first variant by a factor of at least 30.

logger.debug("The new entry is "+entry+".");
logger.debug("The new entry is {}.", entry);

A two argument variant is also availalble. For example, you can write:

logger.debug("The new entry is {}. It replaces {}.", entry, oldEntry);

If three or more arguments need to be passed, an Object[] variant is also availalble. For example, you can write:

Object[] paramArray = {newVal, below, above};
logger.debug("Value {} was inserted between {} and {}.", paramArray);

Configuration

Inserting log requests into the application code requires a fair amount of planning and effort. Observation shows that approximately four percent of code is dedicated to logging. Consequently, even moderately sized applications will contain thousands of logging statements embedded within its code. Given their number, it becomes imperative to manage these log statements without the need to modify them manually.

The logback environment is fully configurable programmatically. However, it is far more flexible to configure logback using configuration files. In logback, configuration files are written in XML format.

Existing log4j users can convert their log4j.properties files to logback.xml using our PropertiesTranslator web-application.

Configuring logback from a XML file is an easy task. One just needs to instanciate a JoranConfigurator and pass the configuration file, as the following example demonstrate.

package chapter1;

//Import SLF4J classes.
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.joran.JoranConfigurator;
import ch.qos.logback.core.util.StatusPrinter;

public class MyAppWithConfigFile {
	
  public static void main(String[] args) {
    Logger logger = LoggerFactory.getLogger(MyAppWithConfigFile.class);
    LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
		
    JoranConfigurator configurator = new JoranConfigurator();
    configurator.setContext(lc);
    configurator.doConfigure(args[0]);

    logger.info("Entering application.");
    Bar bar = new Bar();
    bar.doIt();
    logger.info("Exiting application.");
	
    StatusPrinter.print(lc.getStatusManager());
  }
}

This class defines a logger instance variable. It then instantiates a Bar object. The Bar class is listed below:

package chapter1;
  
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

class Bar {

  Logger logger = LoggerFactory.getLogger(Bar.class);	
	
  public void doIt() {
    logger.debug("doing my job");
  }
}

MyAppWithConfigFile configures logback by using the JoranConfigurator. Joran is a XML interpreter, similar to the commons-digester API, but offering several advantages over commons-digester. Here, it parses the xml file and runs actions depending on the tags it finds. To setup the JoranConfigurator properly, we passed the LoggerContext. A LoggerContext is the class that creates and manages Loggers in logback. It is also the class that implements the org.slf4j.ILoggerFactory interface.

All other classes only need to retrieve an instance of org.slf4j.Logger by calling LoggerFactory.getLogger(), and then log away. For example, the only dependence of the Bar class is on org.slf4j.Logger and org.slf4j.LoggerFactory. Except code that configures logback (if such code exists) user code does not need to depend on logback, but on SLF4J instead.

Let us configure logback with the next XML configuration file:

<?xml version="1.0" encoding="UTF-8" ?>

<configuration>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </layout>
  </appender>

  <root>
    <level value="debug" />
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

We first created an Appender, named STDOUT that is of ConsoleAppender type. Its layout is managed by a PatternLayout, that uses the value of the pattern parameter to generate the logging statement. We then configured the root logger, set its level to DEBUG, and linked the newly configured ConsoleAppender to the root logger.

Note that we've set the root logger level explicitly. Since root logger have a DEBUG level by default we could have omitted this.

To run this example, use this command:

java chapter1.MyAppWithConfigFile src/main/java/chapter1/sample-config-1.xml

Here is what you should see in the console:

18:15:26.718 [main] INFO  chapter1.MyAppWithConfigFile - Entering application.
18:15:26.718 [main] DEBUG chapter1.Bar - doing my job
18:15:26.718 [main] INFO  chapter1.MyAppWithConfigFile - Exiting application.

Logging to the console is a rather simple example. Let's now configure logback so that it logs to the console, but also to a custom file.

<?xml version="1.0" encoding="UTF-8" ?>

<configuration>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%-4relative [%thread] %-5level %class - %msg%n</pattern>
    </layout>
  </appender>

  <appender name="FILE"
    class="ch.qos.logback.core.FileAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%-4relative [%thread] %-5level %class - %msg%n</pattern>
    </layout>
    <File>sample-log.txt</File>
  </appender>

  <root>
    <level value="debug" />
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE" />
  </root>
</configuration>

Now, all the logging statements are directed to the console and to a file named sample-log.txt. As you can see, the configuration needed to add an Appender is rather small. The options are declared as xml element, in either Appender configuration. They are read and their value are assigned to the corresponding attribute in the specified java class.

Suppose that we do not want to see the DEBUG level statements in the chapter1 package anymore. This is done by adding the following bold xml snippet to the configuration file, right before the <root> element.

<?xml version="1.0" encoding="UTF-8" ?>

<configuration>

  <appender name="STDOUT"
    class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%-4relative [%thread] %-5level %class - %msg%n</pattern>
    </layout>
  </appender>

  <appender name="FILE"
    class="ch.qos.logback.core.FileAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <pattern>%-4relative [%thread] %-5level %class - %msg%n</pattern>
    </layout>
    <File>sample-log.txt</File>
  </appender>

  <logger name="chapter1">
    <level value="info" />
  </logger>

  <root>
    <level value="debug" />
    <appender-ref ref="STDOUT" />
    <appender-ref ref="FILE" />
  </root>
</configuration>

Once done, the output is modified to show only statements of level INFO and higher:

0    [main] INFO  chapter1.MyAppWithConfigFile - Entering application.
0    [main] INFO  chapter1.MyAppWithConfigFile - Exiting application.

Note that to obtain these different logging behaviors we did not need to recompile code. We could just as easily have logged to a UNIX Syslog daemon, redirected all chapter1 output to a log visualizer, or forwarded logging events to a remote logback server, which would log according to local server policy, for example by forwarding the log event to a second logback server.

Until now, we always had to specifically load the configuration file and pass it to a logback component. However, this step is not necessary in most cases. When logback is not configured by instanciating JoranConfigurator objects, it follows a simple policy to configure itself.

Logback first tries to find a file called logback.xml within the classpath.

If no such file is found, it checks for another file called logback-test.xml.

In case none of these files are found, logback configures itself automatically using the BasicConfigurator class.

The first two checks allow for two environments to cooperate nicely. When the application using logback is in development and test process, a special file can be used to setup a logging environment that is developer-friendly. Once in production environment, the presence of a logback.xml file overrides any logback-test.xml configuration.

The last step is meant to provide very basic logging functionnality in case no configuration file is provided. In that case, the logging requests are output to the console.

Letting logback load its configuration file is the most often used way of configuring. It allows the user to only import SLF4J classes in her code.

The last step of logback's configuration policy permits the use of a minimal logging configuration right out of the box. Remember the very first example of this short introduction. The output was generated due to this feature.