Comment utiliser Log4j et MDC dans une application Java Spring Boot ?

Dans le cadre d’un de nos projets, nous avons été confrontés à de nombreux cas de débogage. De simples messages dans les logs ne sont pas toujours suffisants. Par exemple, il peut être nécessaire d’avoir plus d’informations sur l’utilisateur qui a exécuté l’action (son IP, ses permissions, son identifiant, …). Dans notre cas, notre application était construite à partir de plusieurs microservices et nous voulions identifier précisément le flux suivi par une requête qui passe d’un microservice à un autre. Pour cela, un identifiant unique a été généré et affiché dans les logs de chaque application web. Cela nous a beaucoup aidé à résoudre des problèmes avec des applications tierces que nous utilisions.

• Comment journaliser les messages ?
• Quelles informations contextuelles ajouter à nos messages ?
• Cette information peut-elle être ajoutée lors de l’exécution de threads asynchrones ?

Cet article vous aidera à construire une application Java Spring Boot pour journaliser des messages avec Log4j et utiliser le MDC de cette bibliothèque (Mapping Diagnostic Context) pour ajouter des données de contextualisation en plus des messages, notamment pour les tâches asynchrones.

Débutons par la génération d’une application Spring Boot classique avec la bibliothèque Log4j intégrée. Cette bibliothèque nous permet d’utiliser un logger qui génère des messages de log de différents types (info, erreur, avertissement, …)

1. Sur Spring Initializr (https://start.spring.io/), construisez un projet Spring Boot de base sans aucune dépendance.
2. Modifiez le fichier pom.xml pour ajouter les dépendances nécessaires à l’utilisation de la bibliothèque Log4j
3. Créer le fichier src/main/resources/log4j2.xml qui définit le format des futurs messages de log

pom.xml

src/main/resources/log4j2.xml

Afficher notre premier message de log

Dans l’état actuel, si nous lançons l’application (via un IDE par exemple ou en utilisant Maven), aucun message de log n’apparaît. Nous allons créer un composant qui utilise la bibliothèque Log4j pour journaliser un message d’information.

Créer un fichier src/main/java/com/sipios/exemple/mdc/Execute.java avec le code ci-dessous. Le nom du package est ici com.sipios.example.mdc, bien sûr, il doit être remplacé par le vôtre 🙂

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

Si vous exécutez l’application, un premier message de log respectant le format défini est maintenant affiché. Il est également possible d’utiliser les méthodes error et warning. Les messages de log correspondant à ces types seront affichés.

Utiliser le MDC (Mapping Diagnostic Context) dans votre log

Maintenant que nous savons comment utiliser la bibliothèque Log4j, nous allons pouvoir utiliser le Mapping Diagnostic Context (MDC) qui nous permet d’associer une donnée Map à notre message. Quelques exemples de données que nous vous recommandons de mettre dans le MDC :

• Données de la session actuelle (utilisateur, requête, demande…)
• Métriques sur l’exécution du processus (temps initial et temps d’exécution, ….)
• Des éléments d’information sur la version de l’application
• …

Cette carte est affichée dans les logs si le masque %X est utilisé dans la définition du format de message Log4j. C’est le cas ici dans notre fichier src/main/resources/log4j2.xml. Dans l’exécution précédente, nous voyons {}, ce qui indique une Map vide.

L’utilisation de MDC est très simple et s’utilise comme une Map classique via les méthodes put, get, remove, clear…. Ajoutons deux entrées au MDC et exécutons l’application.

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

Le MDC est global et il est conservé tant qu’il n’est pas modifié. Si vous voulez le vider en laissant un composant par exemple, il suffit d’utiliser la méthode clear. On obtiendrait alors le résultat suivant.

Comment ça marche avec des composants asynchrones?

Essayons MDC avec des composants asynchrones (un composant exécuté sur un thread parallèle du thread principal) ! Tout d’abord, nous devons configurer notre application pour exécuter de tels beans. Nous créons un service avec deux méthodes, l’une est synchrone et l’autre asynchrone.

1. Ajouter l’annotation @EnableAsync à la classe Application
2. Créer un service avec une méthode normale et une méthode @Async
3. Modifier le composant pour injecter et utiliser les méthodes du service
4. Lancer l’application

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

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

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

Ajouter taskExecutor dans la classe Application

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

Rexécuter :

Comme nous pouvons le voir, le MDC dans le thread asynchrone est vide. En effet chaque tâche asynchrone est lancée dans un nouveau thread. Chaque thread est lié à un MDC Map initié par l’exécuteur de la tâche. Il est possible de jouer sur cet exécuteur pour obtenir le même MDC que sur le thread principal. Ajoutons un décorateur dans asyncExecutor afin de dupliquer le 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

Voilà ! Nous pouvons transmettre dans les logs tout le contexte que nous voulons dans les tâches synchrones ou asynchrones.

Grâce à cela, le débogage d’une application est simplifié et plus compréhensible. Dans le cadre de notre projet cela nous a fait gagner beaucoup de temps dans les échanges avec nos contributeurs. A vous de jouer maintenant 🙂