Tag: slf4j

Logging with Spring Boot

Using and Customizing Logging with Spring Boot

Logging is an important part of any application.  For a quick and dirty example,  I might just use System.out, but for anything beyond that, it’s a good idea to use a proper logging library.  Spring Boot provides a lot for us out of the box.  That includes logging. If we go to the Spring Initializr and configure a basic Spring Boot web application, we’ll get an application set up to use SLF4J and Logback.  It’s on us to use it properly and extend or customize it as needed.

Default Configuration

Without changing any configuration, we can get an SLF4J logger and log messages.  So let’s look at a simple controller for that:

@RestController
public class LoggingController {
   private Logger logger = LoggerFactory.getLogger(LoggingController.class);

   @GetMapping("/")
   public String defaultLogging() {
      logger.trace("Trace message with SLF4j");
      logger.debug("Debug message with SLF4j");
      logger.info("Info message with SLF4j");
      logger.warn("Warn message with SLF4j");
      logger.error("Error message with SLF4j");
      
      return "Successfully logged messages";
   }
}

If we start up our application and go to http://localhost:8080/, we should see the following in our logs:

2019-08-14 21:09:05.367 INFO 8604 --- [nio-8080-exec-1] c.a.logging.LoggingController : Info message with SLF4j
2019-08-14 21:09:05.367 WARN 8604 --- [nio-8080-exec-1] c.a.logging.LoggingController : Warn message with SLF4j
2019-08-14 21:09:05.367 ERROR 8604 --- [nio-8080-exec-1] c.a.logging.LoggingController : Error message with SLF4j

So where are the TRACE and DEBUG messages? This is more of Spring Boot’s default configuration.  By default, the logging level is set to INFO.  We’ll have to customize some configuration to see those TRACE and DEBUG messages.

Configuring the Logging Level

A simple way to change our logging level is in application.properties. For any packages, that we wish to override the logging level for we create a property with the convention logging.level.package.  So to change the com.amydegregorio package to trace, let’s add a property:

logging.level.com.amydegregorio=TRACE

Now when we access our application, we get this logging output:

2019-08-14 21:14:42.033 TRACE 5528 --- [nio-8080-exec-1] c.a.logging.LoggingController            : Trace message with SLF4j
2019-08-14 21:14:42.033 DEBUG 5528 --- [nio-8080-exec-1] c.a.logging.LoggingController            : Debug message with SLF4j
2019-08-14 21:14:42.033  INFO 5528 --- [nio-8080-exec-1] c.a.logging.LoggingController            : Info message with SLF4j
2019-08-14 21:14:42.033  WARN 5528 --- [nio-8080-exec-1] c.a.logging.LoggingController            : Warn message with SLF4j
2019-08-14 21:14:42.034 ERROR 5528 --- [nio-8080-exec-1] c.a.logging.LoggingController            : Error message with SLF4j

Configuring Logback

Logback looks on the classpath for the following files in this order:

  1. logback-spring.xml
  2. logback-spring.groovy
  3. logback-test.xml
  4. logback.groovy
  5. logback.xml

Let’s use XML to configure the com.amydegregorio package to log at the TRACE level:

<configuration>
    <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>

    <logger name="com.amydegregorio" level="TRACE"/>

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

The key line for turning on the TRACE logging level in the com.amydegregorio package is <logger name=”com.amydegregorio” level=”TRACE”/>.  The other configuration sets up the ConsoleAppender and sets the root logging level to DEBUG.  After adding this configuration, we’ll also see all five lines of logging.

Logback is highly configurable, so see the documentation for how to add additional appenders and make other configuration changes.

Log4j2

If we’d rather use Log4j2, we can easily do that in our Spring Boot application.

In our build.gradle file, we need to exclude the dependency on spring-boot-starter-logging because it uses Logback by default and include a dependency for Log4J2.

configurations {
    compile.exclude module: 'spring-boot-starter-logging'
}
implementation 'org.springframework.boot:spring-boot-starter-log4j2'

To configure Log4j2, we add either log4j2-spring.xml or log4j2.xml to our classpath:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" monitorInterval="30">
    <Properties>
        <Property name="LOG_PATTERN">
            %d{yyyy-MM-dd HH:mm:ss.SSS} %5p ${hostName} --- [%15.15t] %-40.40c{1.} : %m%n%ex
        </Property>
    </Properties>
    <Appenders>
        <Console name="ConsoleAppender" target="SYSTEM_OUT" follow="true">
            <PatternLayout pattern="${LOG_PATTERN}"/>
        </Console>
    </Appenders>
    <Loggers>
        <Logger name="com.amydegregorio" level="trace" additivity="false">
            <AppenderRef ref="ConsoleAppender" />
        </Logger>

        <Root level="info">
            <AppenderRef ref="ConsoleAppender" />
        </Root>
    </Loggers>
</Configuration>

Since we’re using SLF4J, there’s no need to modify our LoggingController code.  We can just run http://localhost:8080/ and see our logging output:

2019-08-16 12:04:08.486 TRACE PGMR61 --- [nio-8080-exec-1] c.a.l.LoggingController                  : Trace message with SLF4j
2019-08-16 12:04:08.486 DEBUG PGMR61 --- [nio-8080-exec-1] c.a.l.LoggingController                  : Debug message with SLF4j
2019-08-16 12:04:08.486  INFO PGMR61 --- [nio-8080-exec-1] c.a.l.LoggingController                  : Info message with SLF4j
2019-08-16 12:04:08.486  WARN PGMR61 --- [nio-8080-exec-1] c.a.l.LoggingController                  : Warn message with SLF4j
2019-08-16 12:04:08.486 ERROR PGMR61 --- [nio-8080-exec-1] c.a.l.LoggingController                  : Error message with SLF4j

Conclusion

We’ve just taken a brief look at our logging options for Spring Boot.  Since Spring Boot uses Logback out of the box, we started by first looking at the default configuration.  Then we configured our logging level just by changing application.properties.  For more advanced configuration, we took a brief look at configuration using logback files.

With a few minor dependency and configuration changes, we can easily use Log4J2 in our application, so we then modified our application to use that instead.

We only covered using the logging through the SLF4J facade, but it’s also possible to access the loggers for Logback and Log4J2 directly.

The example code is available on GitHub.