1. Introduction

1.1. Simple Logging Facade for Java(SL4J)

The  SLF4J serves as a simple facade or abstraction for various logging frameworks, such as java.util.logging, logback and log4j. SLF4J allows the end-user to plug in the desired logging framework at deployment time. Note that SLF4J-enabling your library/application implies the addition of only a single mandatory dependency, namely slf4j-api-x.x.x.jar.

1.2. Logback

From Logback’s official documentation:

“Logback is intended as a successor to the popular log4j project, picking up where log4j leaves off.

Logback’s architecture is sufficiently generic so as to apply under different circumstances. At present time, logback is divided into three modules, logback-core, logback-classic and logback-access.

The logback-core module lays the groundwork for the other two modules. The logback-classic module can be assimilated to a significantly improved version of log4j. Moreover, logback-classic natively implements the SLF4J API so that you can readily switch back and forth between logback and other logging frameworks such as log4j or java.util.logging (JUL).

The logback-access module integrates with Servlet containers, such as Tomcat and Jetty, to provide HTTP-access log functionality. Note that you could easily build your own module on top of logback-core.”

1.3.  Spring

Spring is using by default Jakarta Commons Logging, but in the blog post Logging Dependencies in Spring from Spring.io it says “if we could turn back the clock and start Spring now as a new project it would use a different logging dependency. Probably the first choice would be the Simple Logging Facade for Java (SLF4J)“

2. Configuration

To use SLF4J with Spring you need to replace the commons-logging dependency with the SLF4J-JCL bridge. Once you have done that, then logging calls from within Spring will be translated into logging calls to the SLF4J API, so if other libraries in your application use that API, then you have a single place to configure and manage logging.

2.1. Spring

2.1.1. Exclude commons-logging

To switch off commons-logging, the commons-logging dependency mustn’t be present in the classpath at runtime. If you are using maven like me, you can simply exclude it from the spring-context artifact:

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-context</artifactId>
    <version>${spring.version}</version>
    <exclusions>
       <exclusion>
          <groupId>commons-logging</groupId>
          <artifactId>commons-logging</artifactId>
       </exclusion>
    </exclusions>            
</dependency>

Because I am using LogBack, which implements SLF4J directly, you will need to depend on two libraries (jcl-over-slf4j and logback):

<!-- LogBack dependencies --> 
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>${logback.version}</version>
</dependency>
<dependency>                                    
    <groupId>org.slf4j</groupId>                
    <artifactId>jcl-over-slf4j</artifactId>     
    <version>${jcloverslf4j.version}</version>  
</dependency>

Code tip:
All dependencies required for the projects can be found on GitHub in the  pom.xml  file.

2.2. Logback

To configure Logback all you have to do is place the file logback.xml in the classpath.

2.1. logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="consoleAppender" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>.%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg %n
            </Pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>TRACE</level>
        </filter>
    </appender>
      <appender name="dailyRollingFileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>c:/tmp/rest-demo.log</File>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- daily rollover -->
            <FileNamePattern>rest-demo.%d{yyyy-MM-dd}.log</FileNamePattern>
            <!-- keep 30 days‘ worth of history -->
            <maxHistory>30</maxHistory>            
        </rollingPolicy>
        <encoder>
            <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{35} - %msg %n</Pattern>
        </encoder>         
      </appender>
      <appender name="minuteRollingFileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- rollover every minute -->
            <FileNamePattern>c:/tmp/minutes/rest-demo-minute.%d{yyyy-MM-dd_HH-mm}.log</FileNamePattern>
            <!-- keep 30 minutes‘ worth of history -->
            <maxHistory>30</maxHistory>            
        </rollingPolicy>
        <encoder>
            <Pattern>%-4relative [%thread] %-5level %logger{35} - %msg %n</Pattern>
        </encoder>         
      </appender>      
    <logger name="org.codingpedia" additivity="false">
        <level value="http://www.mamicode.com/DEBUG" />
        <appender-ref ref="dailyRollingFileAppender"/>
        <appender-ref ref="minuteRollingFileAppender"/>
        <appender-ref ref="consoleAppender" />
    </logger>
    <root>
        <level value="http://www.mamicode.com/INFO" />
        <appender-ref ref="consoleAppender" />
    </root>
</configuration>

2.1.1. ConsoleAppender

As the name says it, this appender logs to the console. It has an encoder property - encoders are responsible for transforming an incoming event into a byte array and writing out the resulting byte array onto the appropriate OutputStream.

Note: Until logback version 0.9.19, many appenders relied on the Layout instances to control the format of log output. Since then encoders are the standard – encoders are assigned the type of ch.qos.logback.classic.encoder.PatternLayoutEncoder by default.

The PatternLayoutEncoder wraps instances of PatternLayout - this takes a logging event and returns a String, which you can customize by using PatternLayout’s conversion pattern.

From Logaback’s documentation:
“The conversion pattern of PatternLayout is closely related to the conversion pattern of the printf() function in the C programming language. A conversion pattern is composed of literal text and format control expressions calledconversion specifiers. You are free to insert any literal text within the conversion pattern. Each conversion specifier starts with a percent sign ‘%’ and is followed by optional format modifiers, a conversion word and optional parameters between braces. The conversion word controls the data field to convert, e.g. logger name, level, date or thread name. The format modifiers control field width, padding, and left or right justification.”

You can find below a short explanation of the the conversion specifiers used in the example:

• %d{HH:mm:ss.SSS} - Used to output the date of the logging event.

• %thread- outputs the name of the thread that generated the logging event

• %-5level - means the level of the logging event should be left justified to a width of five characters

• %logger{36}  - outputs the name of the logger at the origin of the logging event. It takes an integer as parameter. This specifies the length the converter’s algorithm  will shorten the logger name to.

• %msg – outputs the application-supplied message associated with the logging event.

• %n – outputs the platform dependent line separator character or characters.

• %relative – outputs the number of milliseconds elapsed since the start of the application until the creation of the logging event

The result looks something like this:

10:12:51.012 [qtp231719230-45] DEBUG o.c.d.r.util.LoggingResponseFilter

 or

102662 [qtp1790106082-48] DEBUG o.c.d.r.dao.PodcastDao.getPodcasts

2.1.2. RollingFileAppender

The RollingFileAppender extends FileAppender with the capability to rollover log files. In the example, the RollingFileAppender will log to a file named rest-demo.log file and, once a certain condition (every day and every minute) is met, change its logging target to another file.

There are two important sub-components that interact with RollingFileAppender. The first RollingFileAppender sub-component, namely RollingPolicy, is responsible for undertaking the actions required for a rollover. A second sub-component of RollingFileAppender, namely TriggeringPolicy, will determine if and exactly when rollover occurs. Thus, RollingPolicy is responsible for the what and TriggeringPolicy is responsible for the when.

To be of any use, a RollingFileAppender must have both a RollingPolicy and a TriggeringPolicy set up. However, if its  RollingPolicy also implements the TriggeringPolicy interface, then only the former needs to be specified explicitly – this is exactly the case in the example, where TimeBasedRollingPolicy is used. This assumes the responsibility for rollover as well as for the triggering of said rollover, by implementing both RollingPolicy and TriggeringPolicy interfaces.

In the example the rollover occurs daily and every minute.  For the “daily”-appender, the file property is set to rest-demo.log: During today (March 21th, 2014), logging will go to the file c:/temp/rest-demo.log. At midnight, the rest-demo.log will be renamed to c:/rest-demo.2014-03-21.log and a new c:/temp/rest-demo.log will be created and for the rest of March 22th logging output will be redirected to rest-demo.log.

Note:
The file property in RollingFileAppender (the parent of TimeBasedRollingPolicy) can be either set or omitted. By setting the file property of the containing FileAppender, you can decouple the location of the active log file and the location of the archived log files.

3. Integration in code

To use SLF4J in code is pretty easy – you just have to get a logger, and then on that logger you can log messages at the different logging levels (TRACE, DEBUG, INFO, WARN, ERROR).

For demonstration purposes I created a special logging filter LoggingResponseFilter (didn’t want the REST facade cluttered with logging code) in the REST content, that will log

• input – the HTTP method used + the relative path called of the REST resource

• output – a pretty print of the response entities in JSON format

package org.codingpedia.demo.rest.util;
import java.io.IOException;
import javax.ws.rs.container.ContainerRequestContext;
import javax.ws.rs.container.ContainerResponseContext;
import javax.ws.rs.container.ContainerResponseFilter;
import org.codehaus.jackson.map.ObjectMapper;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class LoggingResponseFilter
        implements ContainerResponseFilter {
    private static final Logger logger = LoggerFactory.getLogger(LoggingResponseFilter.class);
    public void filter(ContainerRequestContext requestContext,
            ContainerResponseContext responseContext) throws IOException {
        String method = requestContext.getMethod();
        logger.debug("Requesting " + method + " for path " + requestContext.getUriInfo().getPath());
        Object entity = responseContext.getEntity();
        if (entity != null) {
            logger.debug("Response " + new ObjectMapper().writerWithDefaultPrettyPrinter().writeValueAsString(entity));
        }
    }
}

Well, that’s it! I would like to use this opportunity once again to thank the people who have developed and documented these wonderful frameworks. To name a few Dave Syer, Ceki Gülcü, Sébastien Pennec, Carl Harris . Thank you guys and keep up the good work!

4. Resources

4.1. Source code

• GitHub – Codingpedia/demo-rest-jersey-spring (instructions on how to install and run the project)

4.1. Codingpedia

• Tutorial – REST API design and implementation in Java with Jersey and Spring

4.3. Web

• Simple Logging Facade for Java (SLF4J)

• SLF4J user manual

• Logback Project 

• Logback documentation

• Logback Appenders

• Logback Layouts

• Logging Dependencies in Spring - spring.io

• JUnit, Logback, Maven with Spring 3

• Logback or Log4j Additivity Explained

How to log in Spring with SLF4J and Logback