Logback Tutorial

Logback is intended as a successor to the log4j project and was designed by Ceki Gülcü. Logback is faster and has a smaller footprint than all existing logging systems. Logback performs about ten times faster than Log4j on specific critical execution paths.

The Logger class in logback-classic implements the SLF4J API natively, so we incur zero overhead when invoking an SLF4J logger with logback-classic as the underlying implementation. Using SLF4J API drastically reduces the work involved in switching logging frameworks.

1. Logback Dependencies

To be up and running with logback requires three modules in the application runtime:

  • logback-core: provides the main classes and interfaces needed by the other two modules.
  • logback-classic: natively implements the SLF4J API.
  • slf4j-api: logback-classic’s Logger class implements the SLF4J API. So we can readily switch back and forth between logback and other logging frameworks.
  • logback-access (Optional) : integrates with Servlet containers, such as Tomcat and Jetty, to provide remote logging functionality.
<dependency>
	<groupId>ch.qos.logback</groupId>
	<artifactId>logback-core</artifactId>
	<version>1.2.10</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.10</version>
</dependency>
<dependency>
	<groupId>org.slf4j</groupId>
	<artifactId>slf4j-api</artifactId>
	<version>1.7.32</version>
</dependency>

Note that logback-classic will automatically pull in the logback-core and slf4j-api, so adding logback-classic dependency is enough.

2. Getting Started with Logback

2.1. Creating and Using Logger

After the dependencies have been imported into the classpath, we can begin logging into the application.

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

public class Main {
	public static void main(final String[] args) 
	{
		Logger logger = LoggerFactory.getLogger(Main.class);
		// OR 
		// Logger logger = LoggerFactory.getLogger("com.howtodoinjava.demo");

		logger.info("Info Message Logged !!!");
	}
}
18:40:47.392 [main] INFO  com.howtodoinjava.demo.slf4j.Main - Info Message Logged !!!

Notice the above class Main. It imports the Logger and LoggerFactory classes defined in the SLF4J API. We get the Logger instance using the static method LoggerFactory.getLogger(). Then we use logger.info() to log messages. It supports debug(), info(), warn() and error() methods.

The getLogger() method can take two types of arguments, i.e., a class type and a String. Both methods return a logger named corresponding to the parameter.

Note we are not using any logback specific package or class. This way, we have no direct dependency on logback and can be replaced by other logging libraries with no code changes.

2.2. Parameterized Messages

In real-life applications, log messages are not always plain strings. We need to log context data into the files, such as object IDs, custom error messages and codes, etc.

These complex messages are generally created by appending the strings, which involve allocating memory, concatenation operation and finally garbage collection after the message has been printed and objects are not in use.

Sometimes, the above string concatenation operation may not be necessary. For example, if we have the Log level set to INFO then the given debug log will not be printed in the log file, but the string concatenation will happen anyway. Such string concatenation is overhead and should be avoided.

logger.info("Article fecthed for id : " + 1 + " is : " + a.toString());

Logback removes the unwanted concatenation with parameterized messages. These messages use the curly braces {} as placeholders for the objects to be printed in messages.

Once Logback determines that log message needs to be printed, it builds the log message by concatenating the original message and replacing the curly braces with the output of the object.toString() methods.

logger.info("Article fecthed for id : {} is : {}", 1, article);

We can use the parameterized messages to print any type of object or information, including the exception stack traces.

3. Logback Configuration

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

3.1. Zero Configuration Defaults

By default, when no default configuration file is found, logback will add a ConsoleAppender to the root logger and this will log all the messages in the Console.

The output is formatted using a PatternLayoutEncoder set to the pattern ‘%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} – %msg%n‘. Also, by default, the root logger is assigned the DEBUG level.

This is the equivalent configuration used by default.

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

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

3.2. Loading Configuration File

The default configuration is enough to get started and for POC purposes. But for production-grade applications, we need to configure different file loggers at suitable Log levels.

During startup, logback tries to locate logback-test.xml or logback.xml in the classpath, in the same order. If the file is found, it configures itself using the provided configuration file.

If no such file is present in classpath, it tries to locate the implementation of com.qos.logback.classic.spi.Configurator interface by looking up the file META-INF\services\ch.qos.logback.classic.spi.Configurator in the classpath for programmatic configuration.

If none of the file or Configurator implementation is found, it configures itself with default configuration, as discussed previously.

Note that may specify the location of the default configuration file with a system property or startup argument named “logback.configurationFile“. The value of this property can be a URL, a resource on the classpath or a path to a file external to the application.

3.3. Checking Initialization Errors

If we face any error during the logback initialization, we can set the debug="true" in the configuration tag. This will print status information to the console as it processes the configuration.

See the status information printed on the console for the given configuration file. We have created appender STDOUT, but in the root logger we have given the name as STDOUT_ONE. Printed logs highlight this configuration issue in the console with message Could not find an appender named [STDOUT1].

<configuration debug="true">
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    ...
  </appender>

  <root level="debug">
    <appender-ref ref="STDOUT_ONE" />
  </root>
</configuration>
18:34:34,556 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
18:34:34,556 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/C:/devsetup/gitrepo/opensource-examples/target/classes/logback.xml]
18:34:34,675 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
18:34:34,679 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
18:34:34,686 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
18:34:34,708 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG
18:34:34,708 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [STDOUT1]. Did you define it below instead of above in the configuration file?
18:34:34,708 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - See http://logback.qos.ch/codes.html#appender_order for more details.
18:34:34,708 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
18:34:34,710 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@ec756bd - Registering current configuration as safe fallback point
18:34:34,712 |-WARN in Logger[com.howtodoinjava.demo.slf4j.Main] - No appenders present in context [default] for logger [com.howtodoinjava.demo.slf4j.Main].

3.4. Auto Reload Configuration File upon Modification

Set scan="true" to configuration tag to let logback scan for changes and automatically reconfigure itself when the configuration file changes.

In the background, a ReconfigureOnChangeTask runs in a separate thread and checks the config file on a defined interval. If the latest version of the configuration file has XML syntax errors, it will fall back to a previous configuration file free of XML syntax errors.

By default, the configuration file will be scanned for changes once every minute. To specify a different scanning period, set the scanPeriod attribute.

<configuration scan="true" scanPeriod="120 seconds" > 
  ...
</configuration>  

If no unit of time is specified, then the unit of time is assumed to be milliseconds.

3.5. Conditional Configuration

Instead of defining multiple configuration files for different needs, we can put all configurations in a single file and add conditions around the relevant sections with the help of if, then and else tags.

For example, the given configuration will configure a console appender in the local development environment with debug logging enabled. Otherwise, the root logger will log all error messages in the provided file appended.

  <if condition='property("ENV").contains("localhost")'>
    <then>
      <appender name="CON" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
          <pattern>%d %-5level %logger{35} - %msg %n</pattern>
        </encoder>
      </appender>
      <root level="DEBUG">
        <appender-ref ref="CON" />
      </root>
    </then>
  </if>

  <root level="ERROR">
     <appender-ref ref="FILE" />
  </root>

Note that conditional processing requires the Janino library.

4. Configuring Appenders

Logback delegates the task of writing a logging event to components called appenders. Appenders are responsible for outputting the logging events in a suitable format to the appropriate output device. However, they may delegate the actual formatting of the event to a Layout or to an Encoder object.

The very basic structure of the logback configuration file can be described as configuration element, containing zero or more appender elements, followed by zero or more logger elements, followed by at most one root element.

The configuration file must be a well-formed XML file, and all open tags must be closed properly.

Tag names pertaining to explicit rules are case insensitive. Few tags related to implicit rules are case-sensitive, except for the first letter. So if as a best practice, just follow the camelCase convention which is almost always the correct convention.

4.1. ConsoleAppender

The console appender appends on the console, or more precisely on System.out or System.err.

Logback, by default, configures the console appender with DEBUG level. We can configure its attributes by defining the appender in logback.xml file.

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

<root level="INFO">
	<appender-ref ref="STDOUT" />
</root>

4.2. RollingFileAppender

File appender appends log events into a file. If the file already exists, it is either appended to, or truncated depending on the value of the append property.

To log into the rolling files (based on time, log file size, or a combination of both), we use RollingFileAppender. The RollingPolicy is responsible for undertaking the actions required for a rollover, and TriggeringPolicy determines if and exactly when rollover occurs.

RollingPolicy implements the TriggeringPolicy interface so if we define only rollingPolicy then also configuration will be accepted.

<appender name="FILE"
	class="ch.qos.logback.core.rolling.RollingFileAppender">
	<file>${LOG_ROOT}/app.log</file>
	<append>true</append>
	<immediateFlush>false</immediateFlush>
	<rollingPolicy
		class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
		<!-- Archiving daily -->
		<fileNamePattern>${LOG_ROOT}/app-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
		<!-- Archiving 60 days of logs and max 10GB size limit -->
		<maxHistory>60</maxHistory>
		<totalSizeCap>10GB</totalSizeCap>
	</rollingPolicy>
	<encoder>
		<pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n
		</pattern>
	</encoder>
</appender>

<root level="INFO">
	<appender-ref ref="FILE" />
</root>

Logback’s FileAppender and all its sub-classes, including RollingFileAppender, can gracefully recover from I/O failures. Thus, if a file server fails temporarily, we no longer need to restart the application to get logging working again. As soon as the file server comes back up, the logger will be working again.

Compression, by RollingFileAppender, always occurs asynchronously so that even for large log files, the application is not blocked for the duration of the compression.

By default, each log event is immediately flushed to the underlying output stream. In case of very high logging throughput, we can set the immediateFlush property to false.

5. FAQs

5.1. How to print Jar files names in logs

Once configured, logback can include packaging data (name and version of the jar file) for each line of the stack trace lines it outputs. It can help debug identifying ClassCastException issues due to multiple versions of jars of any library in the classpath.

The packaging data is disabled by default.

<configuration packagingData="true">
  ...
</configuration>

5.2. Clean Resources on Shutdown

In standalone applications, to correctly shutting down logback and releasing associated resources, use the shutdown hook. The hook will close all appenders attached to loggers defined by the context and stop any active threads in an orderly manner. It will allow up to 30 seconds for any log file compression tasks running in the background to finish.

<configuration debug="false">
	<shutdownHook/>
	.... 
</configuration>

A shutdown hook will be installed automatically in web applications, making this directive entirely redundant.

6. Conclusion

In this Logback tutorial, we learned the default provided configuration, customize the defaults as per requirements and troubleshoot any initialization error. We learned to configure the basic console appender and rolling file appender. We will learn both, in-depth, in future posts.

We also saw the best practices that can help use Logback most effectively.

Happy Learning !!

Download Sourcecode

Was this post helpful?

Join 8000+ Awesome Developers, Like YOU!

Leave a Comment

About HowToDoInJava

This blog provides tutorials and how-to guides on Java and related technologies.

It also shares the best practices, algorithms & solutions, and frequently asked interview questions.