Using Logback With Spring

In my previous project, I learned that using logback for logging is essential for our Spring applications. At that time, I had never heard it before. Now you are maybe in the same shoes, so I decided to write a small fact-finding article about how to use logback with Spring.

This article is also part of my recent case study session that I drew from my latest project. Check my first one here: Spring Boot with external tomcat.

What Is Logback?

The short answer is that it is a logging framework.

The longer one is that the logback is a significantly improved version of the Log4j project, picking up where the latter leaves off. It was founded by the same developer. So, if you are familiar with the above one, you can quickly feel at home using logback.

Logback is divided into three modules:

•  logback-core 
  
•  logback-access 
  
•  logback-classic 
  

In this article, I write about the latest one.

Logback-classic implements the SLF4J API, so you can easily switch back and forth between the different popular implementations, such as Log4j or java.util.Logging.

Reasons to Prefer Logback

• Faster implementation and more tested than Log4j
• Extensive documentation
• Configuration through XML or Groovy
• Automatic reloading of configuration files
• Graceful recovery from I/O failures
• Automatic removal of old log archives
• Automatic compression of archived log files
• Prudent mode
• Lilith
• Conditional processing of configuration files
• Filtering capabilities
• SiftingAppender
• Stack traces with packaging data

See more at https://logback.qos.ch/index.html.

Therefore, I highly recommend you switch to logback in both of your upcoming and running projects. Switching between the SLF4J implementations shouldn’t cost more than replacing your logging jar in your project.

Using Logback With Spring

• Add the logback-classic library to your project in Maven:

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
</dependency>

This will pull the slf4j-api.jar and logback-core.jar as a dependency additionally of the logback-classic.jaron the classpath.

• Use it:

package zoltanraffai.logback;

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

public class Test {

  public static void main(String[] args) {

    Logger logger = LoggerFactory.getLogger("zoltanraffai.logback.Test");
    logger.debug("Hello world.");

  }
}

Launching the application results in the following code on the console:

10:30:05.112 [main] DEBUG zoltanraffai.logback.Test - Hello world.

It is that simple.

Note that, in this example, we do not reference any of the logback libraries. You only need to import SLF4J classes.

Configuring Logback

By default, logback uses a basic ConsoleAppender to write logs to the output. That's why we have seen our logs immediately on our console.

In most cases, we would like to change our application’s default logging behavior. For example, we would like to store additional information in a different format and/or we would like to redirect its output to a different location like a file.

For this, we have different configuration possibilities. We can configure logback either programmatically or with a configuration script expressed in the XML or Groovy format.

Let us see the configuration process:

1. If not found, it tries to find logback.groovy in the classpath
2. Logback seeks thelogback-test.xml in the classpath.
3. If no such file is found, it looks further for the file called logback.xml in the classpath.
4. In the case that none of the above was found, logback tries to resolve the implementation of the  com.qos.logback.classic.spi.Configurator interface.
5. If none of the above succeeds, Logback starts to use theBasicConfigurator, which sets up the framework to log redirect the logging output to the console.

Let us see how you can check this behavior through our example. Extend our code with the following:

// print internal state
    LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
    StatusPrinter.print(lc);

From this time, if we run our code, we can see the following output:

12:49:22.203 [main] DEBUG zoltanraffai.logback.Test - Hello world.
12:49:22,076 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
12:49:22,078 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
12:49:22,093 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.xml]
12:49:22,093 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Setting up default configuration.

Configuring Logback With Spring in a Real-World Scenario

The following expectations are given from the operation team:

• Uses logback.xml for configuration
• This configuration file must be modifiable from a parameterized external location.
• After we modify the configuration file, the changes have to live after 60 seconds.
• Cannot write logs to standard output; instead, they have to go into files to a specified location.
• We need to store some additional data in the logs.

Let us see how we solved it.

• Create a logback.xml file and place it on your classpath (resources folder) with the following content:

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

<configuration scan="true" scanPeriod="60000 milliseconds"> //scan for configuration modifications every 60 secs.
            <include file="${global.appconf.dir}/contextpath/logback-included.xml"/> //Include a configuration file from an external folder. We get to root path from enviroment an variable which is set in the tomcat's setenv.sh file.
</configuration>

• Create the logback-included.xml in the appropriate directory with the following.

Example of the logback-included.xml:

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

<included>
<contextName>testApplication</contextName>
  <appender name="DEVELOPMENT" class="ch.qos.logback.core.rolling.RollingFileAppender"> //This will be an appender, which logs into file
    <file>${server.log.dir}/apps/${CONTEXT_NAME}-development.log</file> //The file name
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>${server.log.dir}/apps/${CONTEXT_NAME}-development.log-%d{yyyy-MM-dd}.%i</fileNamePattern>
      <maxHistory>3</maxHistory>
      <maxFileSize>50MB</maxFileSize>
      <totalSizeCap>200MB</totalSizeCap>
    </rollingPolicy> //configuration for the rolling files, itt will create a new file when the current size hits the 50MB. It will preserve only 3 files historically.
    <encoder>
      <pattern>%d{"yyyy-MM-dd'T'HH:mm:ss.SSSXXX"} [${HOSTNAME}][${server.name}][DEBUG][%contextName][%X{UserName:--}][%class][%method][thread=%thread][requestId:%X{RequestId:--}][severity:%level]%msg%n</pattern> //Information about the datas what the log should store.
    </encoder>
  </appender>

 <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> //A basic ConsoleAppender
            <encoder>
                <pattern>%-5relative %-5level %logger{35} - %msg%n</pattern>
            </encoder>
        </appender>

  <root level="INFO"> //log level setting
    <appender-ref ref="DEVELOPMENT"/> //Appender for that level
  </root>

</included>

Here, our first four bullet point is done. Next, we should put some additional to the framework, which it can extract into the appropriate place defined in the  <pattern> node.

• Transfer additional data to the framework in Spring.

For this, we should create a custom implementation from the javax.servlet.Filter interface. We must define it as a Spring bean to load.

import java.io.IOException;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;

import org.slf4j.MDC;
import org.springframework.stereotype.Component;

@Component
public class Slf4jMDCFilter implements Filter {

    @Override
    public void doFilter(ServletRequest req, ServletResponse res, FilterChain chain) throws IOException, ServletException {

if (req instanceof HttpServletRequest) {

HttpServletRequest request = (HttpServletRequest) req;
String requestId = request.getHeader("Request-Id");

// add cid to the MDC
MDC.put("RequestId", requestId); //Here is the trick, by putting the requestId into the the SLF4J MDC with name of "RequestId" this is the name what we defined in our "logback.xml" file under the <pattern> node.
}

        try {
// call filter(s) upstream for the real processing of the request
            chain.doFilter(req, res);
        } finally {
// it's important to always clean the cid from the MDC, 
// this Thread goes to the pool but it's loglines would still contain the cid.
            MDC.remove("RequestId");
        }

    }

    @Override
    public void destroy() {
        // nothing
    }
    @Override
    public void init(FilterConfig fc) throws ServletException {
        // nothing
    }
}

That's all we’re done. After you start your application and you did the configuration well it should produce the logs on the appropriate way.

Summary

In this article, we learned about what is logback. What are the advantages to use it over the other logging frameworks? How it works, how you can configure it. I took an example from a real-world working expectation and showed you how you can solve it step by step.

Hope it helps you in the near/far future. Sharing is caring!