Spring Boot Logging Implementation in a multi-module project

Prashantprakash
8 min readFeb 3, 2024

--

Logging in a Spring boot project

Goal: We will implement logging framework for our multi-module project. The code to start with can be found here: https://github.com/Geek8080/notification-service/tree/1-dao-module-setup

Prerequisite: If you have a multi-module project, in which you want to add the logging feature, that’s great, otherwise, I would suggest you to go through this once, and setup your application: https://medium.com/@prashantprakash97/spring-multi-module-maven-project-51802214227e

Configure and Test Logging

If you will look into the parent pom, of our project, you will find the below dependencies:

        <!-- logging dependencies -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
<version>${spring.boot.version}</version>
</dependency>
<dependency>
<groupId>com.lmax</groupId>
<artifactId>disruptor</artifactId>
<version>${async.logger.lmax.disruptor.version}</version>
</dependency>

This is all we need in our project to get everything needed for logging.

We will create a class, with main method, and try to write a log line, to output. There are two ways to use the logger for a class.

a. Using Annotation: If you have a lombok dependency in your project(which I do in mine), Simply mark the class with @Slf4j and you have an object of name log, in your class, you can use it to log.

package io.Geek8080.notification.dao;

import lombok.extern.slf4j.Slf4j;

/**
* Created by Geek8080 on 02-02-2024.
*/
@Slf4j
public class Main {
public static void main(String[] args) {
log.info("Hello");
}
}

b. Declaring the object: You can declare a constant in your class, of type Logger, assign it a Logger of the class, as shown below. You can use this LOGGER to log.

package io.Geek8080.notification.dao;

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

/**
* Created by Geek8080 on 02-02-2024.
*/
public class Main {

private static final Logger LOGGER = LoggerFactory.getLogger(Main.class);

public static void main(String[] args) {
LOGGER.info("Hello");
}
}

Both are doing the same job, but @Slf4j gives a cleaner code, that’s what I always use and recommend.

Go on, run your code. It will print “Hello” to the output screen.

Class path contains multiple SLF4J providers

Encountering an error instead of log line “Hello”? You must be getting something as shown below:

SLF4J: Class path contains multiple SLF4J providers.
SLF4J: Found provider [org.apache.logging.slf4j.SLF4JServiceProvider@3eb07fd3]
SLF4J: Found provider [ch.qos.logback.classic.spi.LogbackServiceProvider@506c589e]
SLF4J: See https://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual provider is of type [org.apache.logging.slf4j.SLF4JServiceProvider@3eb07fd3]
Exception in thread "main" java.lang.ExceptionInInitializerError
Caused by: org.apache.logging.log4j.LoggingException: log4j-slf4j2-impl cannot be present with log4j-to-slf4j
at org.apache.logging.slf4j.Log4jLoggerFactory.validateContext(Log4jLoggerFactory.java:70)
at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:50)
at org.apache.logging.slf4j.Log4jLoggerFactory.newLogger(Log4jLoggerFactory.java:33)
at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:53)
at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:33)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:391)
at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:416)
at io.Geek8080.notification.dao.Main.<clinit>(Main.java:11)

You must be wondering why we got this. To understand that, let’s first understand Slf4j.

Slf4j (Simple Logging Facade for Java) acts as a middleman, letting you choose your preferred logging framework (like Log4j or Logback) while keeping your code flexible. Slf4j promotes flexibility and avoids redundancy, simplifying logging across diverse environments. But why Slf4j?

Imagine building a library used in various projects, each potentially using different logging tools. Slf4j prevents unnecessary duplication by leveraging the user’s existing logger. So, how does it work?

Suppose your library uses Slf4j and Log4j, but a user employs Logback. Slf4j, being clever, dynamically detects the available framework and utilizes it! However, conflicting setups (having both Log4j and Logback) create issues. Running the application in this scenario would likely result in an error:

Class path contains multiple SLF4J providers

Seems familiar? This is what we got. So we can conclude, Slf4j found more than one implementations for logging in our application. Let’s figure it out and resolve.

Maven Dependency Plugin

Our project includes numerous dependencies, making it unclear which one might be introducing duplicate dependencies or conflicting logging implementations. To figure that out, we need to list out all the libraries imported into our project.

Maven has a plugin, maven-dependency-plugin, which is a great plugin to have. Go to your parent pom, and add the following plugin:

<plugin>
<artifactId>maven-dependency-plugin</artifactId>
<version>3.6.1</version>
</plugin>

Once this is added, run the following command inside your module to list out the libraries imported.

mvn dependency:tree

You will have an output similar to this:

[INFO] Scanning for projects...
[INFO]
[INFO] --------------------------< io.Geek8080:dao >---------------------------
[INFO] Building dao 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-dependency-plugin:3.6.1:tree (default-cli) @ dao ---
[INFO] io.Geek8080:dao:jar:0.0.1-SNAPSHOT
[INFO] +- org.springframework.boot:spring-boot-starter-log4j2:jar:3.2.2:compile
[INFO] | +- org.apache.logging.log4j:log4j-slf4j2-impl:jar:2.21.1:compile
[INFO] | | +- org.apache.logging.log4j:log4j-api:jar:2.21.1:compile
[INFO] | | \- org.slf4j:slf4j-api:jar:2.0.6:compile
[INFO] | +- org.apache.logging.log4j:log4j-core:jar:2.21.1:compile
[INFO] | \- org.apache.logging.log4j:log4j-jul:jar:2.21.1:compile
[INFO] +- com.lmax:disruptor:jar:3.4.4:compile
[INFO] +- org.projectlombok:lombok:jar:1.18.28:compile
[INFO] +- org.springframework.boot:spring-boot-starter-actuator:jar:3.2.2:compile
[INFO] | +- org.springframework.boot:spring-boot-starter:jar:3.2.2:compile
[INFO] | | +- org.springframework.boot:spring-boot-starter-logging:jar:3.2.2:compile
[INFO] | | | +- ch.qos.logback:logback-classic:jar:1.4.14:compile
[INFO] | | | | \- ch.qos.logback:logback-core:jar:1.4.14:compile
[INFO] | | | +- org.apache.logging.log4j:log4j-to-slf4j:jar:2.21.1:compile
[INFO] | | | \- org.slf4j:jul-to-slf4j:jar:2.0.11:compile
[INFO] | | +- jakarta.annotation:jakarta.annotation-api:jar:2.1.1:compile
[INFO] | | +- org.springframework:spring-core:jar:6.1.3:compile
[INFO] | | | \- org.springframework:spring-jcl:jar:6.1.3:compile
[INFO] | | \- org.yaml:snakeyaml:jar:2.2:compile
[INFO] | +- org.springframework.boot:spring-boot-actuator-autoconfigure:jar:3.2.2:compile
[INFO] | | +- org.springframework.boot:spring-boot-actuator:jar:3.2.2:compile
[INFO] | | +- com.fasterxml.jackson.core:jackson-databind:jar:2.15.3:runtime
[INFO] | | | +- com.fasterxml.jackson.core:jackson-annotations:jar:2.15.3:runtime
[INFO] | | | \- com.fasterxml.jackson.core:jackson-core:jar:2.15.3:runtime
[INFO] | | \- com.fasterxml.jackson.datatype:jackson-datatype-jsr310:jar:2.15.3:runtime
[INFO] | +- io.micrometer:micrometer-observation:jar:1.12.2:compile
[INFO] | | \- io.micrometer:micrometer-commons:jar:1.12.2:compile
[INFO] | \- io.micrometer:micrometer-jakarta9:jar:1.12.2:compile
[INFO] | \- io.micrometer:micrometer-core:jar:1.12.2:compile
[INFO] | +- org.hdrhistogram:HdrHistogram:jar:2.1.12:runtime
[INFO] | \- org.latencyutils:LatencyUtils:jar:2.0.3:runtime
[INFO] +- org.springframework.boot:spring-boot-devtools:jar:3.2.2:runtime
[INFO] | +- org.springframework.boot:spring-boot:jar:3.2.2:compile
[INFO] | | \- org.springframework:spring-context:jar:6.1.3:compile
[INFO] | | +- org.springframework:spring-aop:jar:6.1.3:compile
[INFO] | | +- org.springframework:spring-beans:jar:6.1.3:compile
[INFO] | | \- org.springframework:spring-expression:jar:6.1.3:compile
[INFO] | \- org.springframework.boot:spring-boot-autoconfigure:jar:3.2.2:compile
[INFO] \- org.springframework.boot:spring-boot-configuration-processor:jar:3.2.2:compile
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1.712 s
[INFO] Finished at: 2024-02-03T12:14:57+05:30
[INFO] ------------------------------------------------------------------------

If you will look carefully, we have added log4j dependency as: org.springframework.boot:spring-boot-starter-log4j2 and we have a logging library in dependency org.springframework.boot:spring-boot-starter-actuator which is: org.springframework.boot:spring-boot-starter-logging.

To make our code work, we need to remove this second logging implementation. To do that, simply go to pom, where you have your dependency(in my case, it is in parent pom) and change your dependency tag to have an exclusion tag as follows:

        <dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-actuator</artifactId>
<version>${spring.boot.version}</version>
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>

Run the above command again and your output will have something like this:

[INFO] Scanning for projects...
[INFO]
[INFO] --------------------------< io.Geek8080:dao >---------------------------
[INFO] Building dao 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- maven-dependency-plugin:3.6.1:tree (default-cli) @ dao ---
[INFO] io.Geek8080:dao:jar:0.0.1-SNAPSHOT
[INFO] +- org.springframework.boot:spring-boot-starter-log4j2:jar:3.2.2:compile
[INFO] | +- org.apache.logging.log4j:log4j-slf4j2-impl:jar:2.21.1:compile
[INFO] | | +- org.apache.logging.log4j:log4j-api:jar:2.21.1:compile
[INFO] | | \- org.slf4j:slf4j-api:jar:2.0.6:compile
[INFO] | +- org.apache.logging.log4j:log4j-core:jar:2.21.1:compile
[INFO] | \- org.apache.logging.log4j:log4j-jul:jar:2.21.1:compile
[INFO] +- com.lmax:disruptor:jar:3.4.4:compile
[INFO] +- org.projectlombok:lombok:jar:1.18.28:compile
[INFO] +- org.springframework.boot:spring-boot-starter-actuator:jar:3.2.2:compile
[INFO] | +- org.springframework.boot:spring-boot-starter:jar:3.2.2:compile
[INFO] | | +- jakarta.annotation:jakarta.annotation-api:jar:2.1.1:compile
[INFO] | | +- org.springframework:spring-core:jar:6.1.3:compile
[INFO] | | | \- org.springframework:spring-jcl:jar:6.1.3:compile
[INFO] | | \- org.yaml:snakeyaml:jar:2.2:compile
[INFO] | +- org.springframework.boot:spring-boot-actuator-autoconfigure:jar:3.2.2:compile
[INFO] | | +- org.springframework.boot:spring-boot-actuator:jar:3.2.2:compile
[INFO] | | +- com.fasterxml.jackson.core:jackson-databind:jar:2.15.3:runtime
[INFO] | | | +- com.fasterxml.jackson.core:jackson-annotations:jar:2.15.3:runtime
[INFO] | | | \- com.fasterxml.jackson.core:jackson-core:jar:2.15.3:runtime
[INFO] | | \- com.fasterxml.jackson.datatype:jackson-datatype-jsr310:jar:2.15.3:runtime
[INFO] | +- io.micrometer:micrometer-observation:jar:1.12.2:compile
[INFO] | | \- io.micrometer:micrometer-commons:jar:1.12.2:compile
[INFO] | \- io.micrometer:micrometer-jakarta9:jar:1.12.2:compile
[INFO] | \- io.micrometer:micrometer-core:jar:1.12.2:compile
[INFO] | +- org.hdrhistogram:HdrHistogram:jar:2.1.12:runtime
[INFO] | \- org.latencyutils:LatencyUtils:jar:2.0.3:runtime
[INFO] +- org.springframework.boot:spring-boot-devtools:jar:3.2.2:runtime
[INFO] | +- org.springframework.boot:spring-boot:jar:3.2.2:compile
[INFO] | | \- org.springframework:spring-context:jar:6.1.3:compile
[INFO] | | +- org.springframework:spring-aop:jar:6.1.3:compile
[INFO] | | +- org.springframework:spring-beans:jar:6.1.3:compile
[INFO] | | \- org.springframework:spring-expression:jar:6.1.3:compile
[INFO] | \- org.springframework.boot:spring-boot-autoconfigure:jar:3.2.2:compile
[INFO] \- org.springframework.boot:spring-boot-configuration-processor:jar:3.2.2:compile
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 1.218 s
[INFO] Finished at: 2024-02-03T12:25:29+05:30
[INFO] ------------------------------------------------------------------------

Looks great, let’s run our main class now.

You didn’t get anything in output? No error either? Let’s fix it.

log4j2.xml and Async Logging

Log4j requires a configuration file, log4j2.xml to know, where to write the log, how to write it. Create a log4j2.xml in resources folder, with the following content:

<?xml version="1.0" encoding="UTF-8" ?>
<Configuration>
<Properties>
<Property name="logpath-location">app/logs</Property>
<Property name="logfile-name">journal_service.log</Property>
<Property name="archive">${logpath-location}/archive/notificationService</Property>
<Property name="interval">10</Property>
</Properties>

<Appenders>
<Console name="Console">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p %C.%M():%L %X - %m%n"/>
</Console>

<RollingFile name="RollingFileAppender" fileName="${logpath-location}/${logfile-name}"
filePattern="${archive}/${logfile-name}.%d{yyyy-MM-dd-HH}.gz">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p %c.%M ():%L %X - %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
</Policies>
</RollingFile>
</Appenders>

<Loggers>
<Logger name="com.indiantraditionalsnacks.notificationservice" level="DEBUG" additivity="false" includeLocation="true">
<AppenderRef ref="Console" level="INFO"/>
<AppenderRef ref="RollingFileAppender" level="DEBUG"/>
</Logger>

<Root level="INFO" includeLocation="true">
<AppenderRef ref="Console" level="INFO"/>
<AppenderRef ref="RollingFileAppender" level="DEBUG"/>
</Root>
</Loggers>

</Configuration>

Run your main class again, and you will see something like below:

2024-02-03 12:39:30,794 [main] INFO  io.Geek8080.notification.dao.Main.main():17 {} - Hello

That looks pretty neat, right? With all the info of code, which resulted in this log line. This is what we configured with our xml file.

Every time we log something to the output, it consumes computational power of the system. If you add too many logging, it will slow down your application.

This is where async logging comes into play. Asynchronous logging offers significant performance boosts by writing logs in the background, keeping your main thread free and responsive. This translates to faster application response times, especially for high-traffic scenarios. Plus, it allows your system to handle more concurrent requests and scales better under heavy load.

However, it’s not a one-size-fits-all solution. Implementing async logging adds complexity and might increase memory usage. Additionally, depending on the implementation, log order might not be guaranteed, which is not much of an issue, since we are printing the line number and classes, from where the log was generated.

To make logging asynchronous, simply add file named “log4j2.component.properties” to resources with the following content:

log4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

If you want to learn about configuring async logging in more detail, I am adding link to another blog in the end, follow that once.

On few systems, you might not see logs after adding the async logger property. This happens because, in case of async logger, the logs are stored in the buffer, and only after certain threshold buffer size, or time interval, it is written to output(console or file). Since our application is doing nothing, but printing the log, and exit, none of the case becomes true, so that log will be written. And you get an empty output screen. To resolve this, you can simply add a delay(Thread.sleep()) of few millisecond, right before the exit of application. There is one more extensive solution to this, where we define a shutdown hook, and clean all the logging resources before application exit.

Here’s the code to flush all the logs in buffer:

package io.Geek8080.notification.dao;

import lombok.extern.slf4j.Slf4j;
import org.apache.logging.log4j.LogManager;

/**
* Created by Geek8080 on 02-02-2024.
*/
@Slf4j
public class Main {

public static void main(String[] args) throws InterruptedException {
log.info("Hello");
Runtime.getRuntime().addShutdownHook(new Thread(LogManager::shutdown));
}

}

Code: https://github.com/Geek8080/notification-service/tree/2-dao-module-logging-setup

--

--