How to use Log4j and MDC in Java Spring Boot Application?

In the context of one of our projects, we were faced with many debugging cases. Simple messages in the logs are not always enough. For example, it may be necessary to have more information about the user who executed the action (his IP, his permissions, his identifier, …). In our case, our application was built from several microservices and we wanted to precisely identify the flow followed by a request that passes from one microservice to another. For this purpose, a unique identifier was generated and displayed in the logs of each web application. This helped us a lot to solve problems with third-party applications we were using.

• How to log messages?
• What context information to add to our messages?
• Can this information be added when running asynchronous threads?

This article will help you build a Spring Boot Java application to log messages with Log4j and use the MDC of this library (Mapping Diagnostic Context) to add contextualization data in addition to messages, especially for asynchronous tasks.

Create basic Spring Application with Log4j

Let’s start by generating a classic Spring Boot application with the built-in Log4j library. This library allows us to use a logger that generates log messages of different types (info, error, warning, …)

1. On Spring Initializr (https://start.spring.io/), build a basic Spring Boot project without any dependencies.
2. Edit the pom.xml file to add the dependencies needed to use the Log4j library
3. Create the src/main/resources/log4j2.xml file that defines the format for future log messages

pom.xml

src/main/resources/log4j2.xml

Display our first log message

In the current state, if we launch the application (via an IDE for example or using Maven), no log message appears. We will create a component that uses the Log4j library to log an information message.

Create a src/main/java/com/sipios/example/mdc/Execute.java file with the code below. The package name is here com.sipios.example.mdc, of course, it should be replaced by yours :)

src/main/java/com/sipios/example/mdc/Execute.java

If you run the application, a first log message respecting the defined format is now displayed. It is also possible to use the error and warning methods. Log messages corresponding to these types will be displayed.

Use MDC (Mapping Diagnostic Context) in your log

Now that we know how to use the Log4j library, we will be able to use the Mapping Diagnostic Context (MDC) which allows us to associate a data Map with our message. Some examples of data we recommend you put in the MDC:

• Data of the current session (user, query, request …)
• Metrics about the execution of the process (initial time and execution time, …)
• Pieces of information about the version of the application
• …

This Map is displayed in the logs if the %X mask is used in the Log4j message format definition. This is the case here in our src/main/resources/log4j2.xml file. In the previous execution, we see {}, which indicates an empty Map.

Using MDC is very simple and is used like a classic Map via put, get, remove, clear methods... Let's add two entries to the MDC and execute the application.

src/main/java/com/sipios/example/mdc/Execute.java

MDC is global and it’s preserved as long as it is not modified. If you want to empty it by leaving a component for example, just use the clear method. This would then give the following result.

How does it work with asynchronous components?

Let’s try MDC with asynchronous components (a component executed on a parallel thread of the main thread)! First of all, we have to configure our application to execute such beans. We create a service with two methods, one is synchronous and the other asynchronous.

1. Add @EnableAsync annotation to the Application class
2. Create a service with a normal method and an @Async one
3. Modify the component to inject and use service’s methods
4. Launch the application

src/main/java/com/sipios/example/mdc/Application.java

src/main/java/com/sipios/example/mdc/service/Example.java

src/main/java/com/sipios/example/mdc/Execute.java

Add taskExecutor in Application class

src/main/java/com/sipios/example/mdc/Application.java

Re-execute :

As we can see, MDC in async thread is empty. Indeed each asynchronous task is started in a new thread. Each thread is linked to a Map MDC initiated by the task executor. It is possible to play on this executor to obtain the same MDC as on the main thread. Let’s add a decorator in asyncExecutor in order to duplicate MDC!

src/main/java/com/sipios/example/mdc/ExampleTaskDecorator.java

Set this decorator in async config

src/main/java/com/sipios/example/mdc/Application.java

Relaunch application

There you go! We can convey in the logs all the context that we want in synchronous or asynchronous tasks.

Thanks to this, debugging an application is simplified and more understandable. As part of our project this has saved us a lot of time in the exchanges with our contributors. It’s up to you now :)

Bibliography

• http://www.baeldung.com/mdc-in-log4j-2-logback
• https://spring.io/guides/gs/async-method/
• https://moelholm.com/2017/07/24/spring-4-3-using-a-taskdecorator-to-copy-mdc-data-to-async-threads/