Utilisation de l'API SLF4J

Utilisation de l'API Log4J2 Qu'est-ce qu'un « Design Pattern » ?

Accès rapide :
Introduction
Installation de SLF4J
Installation manuelle
Installation par Maven
Produire des logs avec SLF4J
Acquisition d'un logger
Les différents niveaux de logs
Produire un log à un niveau donné
Choix de l'api sous-jacente
Configurer vos logs
Attention aux problématiques de performances

Introduction

La dernière API dont je souhaite vous parler, n'est pas une API de log à proprement parler. Il s'agit plutôt d'une surcouche d'abstraction permettant à votre application de fonctionner avec une API de log quelconque. Ainsi le changement de la solution de log concrètement utilisée, n'impactera aucune ligne de code de votre application.

Pour comprendre son intérêt, imaginons le scénario suivant : vous développez une application Web en Java pour la gestion du personnel d'une entreprise. Pour fonctionner, cette application aura donc besoin d'un serveur Web compatible Jakarta EE (anciennement Java EE). De plus, vous souhaitez vendre l'application sans imposer à vos clients le choix d'un serveur Web. Or, les serveurs Web utilisent déjà une API de log : par exemple Tomcat utilise, par défaut, JUL (java.util.logging) alors que d'autres utilisent Log4J ou autre. Du coup, comment garantir que notre application tracera correctement son activité quelle que soit l'API concrètement utilisée par le serveur Web ?

Vous l'avez compris, oui SLF4J sera dans ce cas une bonne solution : il ré-routera les demandes de journalisation (logging) sur l'API sous-jacente. Grace à SLF4J on peut donc être complément indépendant de la solution de log retenue. Le contre-coup, c'est qu'on utilise une sur-couche, ce qui ralentit un peu les performances (mais ça peut être négligeable).

Installation de SLF4J

Je vous propose deux solutions pour installer SLF4J : soit par le biais d'une installation manuelle, soit en utilisant l'outil Apache Maven.

Installation manuelle

Le logiciel SLF4J peut être téléchargé sur son site officiel : http://www.slf4j.org/download.html. A minima, il vous faut télécharger les deux jars suivants slf4j-api/1.7.30/slf4j-api-1.7.30.jar et slf4j-jdk14/1.7.30/slf4j-jdk14-1.7.30.jar (les numéros de versions pourront varier : je vous conseille toujours de prendre les versions les plus récentes). Le second fichier jar correspond au driver pour que SLF4J puisse utiliser l'API java.util.logging. Placez ces deux fichiers dans un dossier lib à la racine de votre projet Eclipse.

Une fois les deux JARs placés dans le projet, il ne reste plus qu'à les ajouter au CLASSPATH. Avec Eclipse, cela peut se faire en cliquant avec le bouton droit de la souris sur ces archives, puis en sélectionnant « Build Path / Add to Build Path » (ou via la boîte de dialogue « Configure Build Path »). Une fois cette étape réalisée, les deux archives doivent être visibles dans les librairies référencées par le projet, comme le montre la capture d'écran ci-dessous.

Il nous faut trois autres jars pour notre démo : vous les trouverez dans le ZIP de Log4J2. Vous pouvez consulter le chapitre précédent pour obtenir de plus amples informations sur le téléchargement de Log4J2. Parmi tous les fichiers jars proposés, nous avons besoin de log4j-api-2.13.3.jar, log4j-core-2.13.3.jar et log4j-slf4j-impl-2.13.3.jar. La dernière archive correspond au driver pour que SLF4J puisse utiliser l'API Log4J2. Vous pouvez les copier dans le dossier lib de votre projet.

Installation par Maven

Une autre solution pour installer une librairie sur votre machine consiste à utiliser l'outil Apache Maven. Il s'agit d'un outil de construction de programme (ou outil de build) qui gère les dépendances. Nous n'avons pas encore vraiment parlé de Maven, mais nous le ferons dans un futur chapitre.

Pour ceux qui connaissent déjà Maven, voici la définition des dépendances requises pour utiliser SLF4J par-dessus java.util.logging.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 

<dependencies>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.30</version>
    </dependency>

    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-jdk14</artifactId>
        <version>1.7.30</version>
    </dependency>
</dependencies>

Et voici la même chose pour utiliser SLF4J par-dessus Log4J2 dans Maven.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 
 19 
 20 
 21 
 22 
 23 
 24 
 25 

<dependencies>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.30</version>
    </dependency>

    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-api</artifactId>
        <version>2.13.3</version>
    </dependency>

    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-core</artifactId>
        <groupId>org.apache.logging.log4j</groupId>
    </dependency>
    
    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-slf4j-impl</artifactId>
        <groupId>org.apache.logging.log4j</groupId>
    </dependency>
</dependencies>

Produire des logs avec SLF4J

Pour produire des logs avec l'API SLF4J, vous devez réaliser, à minima, deux étapes :

• Il faut commencer par acquérir un logger.
• Puis, il faut utiliser le logger pour générer vos logs avec les niveaux désirés.

Acquisition d'un logger

Pour acquérir un logger, il faut utiliser la méthode statique org.slf4j.LoggerFactory.getLogger. Par le jeu subtil de la surcharge, votre méthode d'acquisition peut accepter en paramètre plusieurs types et notamment une chaîne de caractères. Il s'agit du nom du logger : il est très important, car il servira ultérieurement à configurer ce logger. Vous pouvez mettre le nom qui vous convient. Dans l'exemple suivant, j'imagine être dans un composant logiciel « Compo1 » et j'ai donc nommé mon logger de la même manière : cela me permettra de facilement configurer les loggers de toutes les classes de ce composant logiciel.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 

package fr.koor.samples.slf4j;

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

public class TestSLF4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LoggerFactory.getLogger( "Compo1" );

    // Le point d'entrée du programme.
    public static void main( String [] args ) {

        // TODO: utiliser votre logger
        
    }
    
}

Certains préfèrent utiliser la signature de la méthode getLogger acceptant un objet de type java.lang.Class. Voici un exemple d'instanciation en utilisant la classe courante comme nom de logger.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 

package fr.koor.samples.slf4j;

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

public class TestSLF4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LoggerFactory.getLogger( TestSLF4J.class );

    // Le point d'entrée du programme.
    public static void main( String [] args ) {

        // TODO: utiliser votre logger
        
    }
    
}

Je vous recommande d'utiliser cette seconde possibilité ! Effectivement, dans la configuration du moteur SLF4J, il va être possible de dire que tous les loggers commençant par un préfixe doivent appliquer telle ou telle règle. Si le préfixe utilisé correspond au nom d'un package, toutes les classes de ce package seront configurées. De plus, le mécanisme est récursif.

Il est à noter que vous utilisez une méthode statique de récupération du logger (la méthode LoggerFactory.getLogger()). Pourquoi n'utilise-t-on pas un constructeur ? La raison est simple, plusieurs classes peuvent partager le même logger. Dans ce cas, on doit toujours demander le même nom de logger et la première classe qui le demande va lancer son instanciation et sa configuration. Les autres appels retourneront cette instance. Voici un exemple de code mettant en évidence ce point.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 
 19 
 20 
 21 

package fr.koor.samples.slf4j;

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

public class TestSLF4J {

    // Récupérations multiples de notre logger.
    private static final Logger LOGGER1 = LoggerFactory.getLogger( "Compo1" );
    private static final Logger LOGGER2 = LoggerFactory.getLogger( "Compo1" );

    // Le point d'entrée du programme.
    public static void main( String [] args ) {

        // On fait une comparaison de pointeurs pour bien vérifier que nous 
        // avons bien deux variables qui pointent sur la même instance.
        System.out.println( LOGGER1 == LOGGER2 );       // Affiche true !
        
    }
    
}

Les différents niveaux de logs

Les niveaux de logs supportés par SLF4J sont les suivants :

• error : permet d'autoriser les messages de niveau « erreur / error » dans les logs. Dans ce cas, le message d'erreur et l'exception associée, s'ils sont passés au logger utilisé, pourront apparaître dans les logs.

• warn : permet d'autoriser les messages de niveau « avertissement / warning » dans les logs. Si la configuration de votre système de log autorise la production des avertissements, alors les erreurs seront aussi ajoutés aux logs.

• info : d'autoriser les messages de niveau « informatif » dans les logs. Si la configuration de votre système de log autorise la production des messages informatifs, alors les avertissements et les erreurs seront aussi générés.

• debug : permet les messages de niveau « deboggage » dans les logs. Si la configuration de votre système de log autorise la production des messages de debug, alors les messages informatifs, les avertissements et les erreurs seront aussi générés.

• trace : permet les messages de niveau « trace » dans les logs. Si la configuration de votre système de log autorise la production des traces, alors les messages de debug, les messages informatifs, les avertissements et les erreurs seront aussi générés.

Produire un log à un niveau donné

Pour produire un message à un niveau de log donné, il faut utiliser la méthode de même nom sur votre logger. Voici quelques exemples d'utilisations de ces méthodes.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 
 19 
 20 
 21 
 22 
 23 
 24 
 25 

package fr.koor.samples.slf4j;

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

public class TestSLF4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LoggerFactory.getLogger( TestSLF4J.class );

    // Le point d'entrée du programme.
    public static void main( String [] args ) {

        // On produit un log de niveau informatif.
        LOGGER.info( "Hello World with SLF4J" );

        // On produit un avertissement.
        LOGGER.warn( "Do caution, please." );

        // On produit un log de niveau erreur.
        LOGGER.error( "Houston, we have a problem" );
        
    }
    
}

Vous pouvez aussi générer des messages en y injectant les valeurs de vos variables ou encore les informations des exceptions constatées. Dans le cas où vous souhaitez injecter des valeurs, c'est la séquence {} qui permet de définir les points d'injections. Voici un exemple d'utilisation de ces possibilités.

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 
 19 
 20 
 21 
 22 
 23 
 24 
 25 
 26 
 27 

package fr.koor.samples.slf4j;

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

public class TestSLF4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LoggerFactory.getLogger( TestSLF4J.class );

    // Le point d'entrée du programme.
    public static void main( String [] args ) {

        // On produit un log de niveau informatif.
        LOGGER.info( "Hello World with SLF4J / Log4J {}", 2 );

        try {
            int value = (int)( Math.random() * 2 );
            int result = 3 / value;
            LOGGER.info( "value == {} - result == {}", value, result );
        } catch( Exception exception ) {
            LOGGER.error( "Houston, we have a problem.", exception ); 
        }
        
    }
    
}

En considérant que nous utilisons le tandem SLF4J/Log4J et sous condition d'autoriser les logs de niveau informatifs dans le fichier de configuration de Log4J 2 (nous allons revenir sur ces points dans quelques minutes), vous obtiendrez le résultat suivant si aucune exception n'est déclenchée.

[main] INFO  | fr.koor.samples.slf4j.TestSLF4J                             | Hello World with SLF4J / Log4J 2 (TestSLF4J.java:16)
[main] INFO  | fr.koor.samples.slf4j.TestSLF4J                             | value == 1 - result == 3 (TestSLF4J.java:21)

Par contre, si une exception est déclenchée, vous pourrez avoir un résultat proche de celui-ci.

[main] INFO  | fr.koor.samples.slf4j.TestSLF4J                             | Hello World with SLF4J / Log4J 2 (TestSLF4J.java:16)
[main] ERROR | fr.koor.samples.slf4j.TestSLF4J                             | Houston, we have a problem. (TestSLF4J.java:23)
java.lang.ArithmeticException: / by zero
    at fr.koor.samples.slf4j.TestSLF4J.main(TestSLF4J.java:20) [bin/:?]

Choix de l'api sous-jacente

Comme nous l'avons déjà précisé, vous pouvez utiliser SJF4J par-dessus JUL (java.util.logging) soit par-dessus Log4J2. Pour rappel, le choix de l'API de log concrètement utilisée dépend des fichiers JAR visibles dans votre classpath. Si vous avez suivi les consignes au début de ce chapitre, normalement Log4J 2 et le jar log4j-slf4j-impl-2.13.3.jar ne devrait pas être déployé dans votre projet. Lancez-le et normalement, vous devriez constater que le format des messages produits et bien celui de JUL.

Maintenant, commencer par retirer le jar slf4j-jdk14-1.7.30.jar du CLASSPATH. Puis, ajouter les fichiers JAR relatifs à Log4J 2 ainsi que le fichier log4j-slf4j-impl-2.13.3.jar. Pour ce faire, soit vous ajouter les fichiers JAR dans le CLASSPATH (le build path, sous Eclipse), soit vous modifiez votre ficher pom.XML de Maven pour y ajouter les dépendances (voir configuration proposée plus haut dans cette page). Relancez le programme et vous devriez constater que le format des messages produits et bien celui de Log4J2.

Ainsi si votre programme doit être déployé dans des infrastructures exploitant JUL (Serveur Web Java EE ou autre), il fonctionnera très bien. Et s'il doit aussi être déployé dans une infrastructure privilégiant Log4J 2, il fonctionnera tout aussi bien.

Configurer vos logs

Il est important de comprendre que l'API SLF4J ne propose pas de formalisme particulier pour la configuration de vos logs. Et c'est normal : SLF4J n'est qu'une surcouche logicielle et elle nécessite une véritable API de log pour fonctionner. Si nécessaire, je vous recommande de bien revoir le diagramme proposé en début du chapitre.

Si vous utilisez l'API java.util.logging (JUL), il vous faudra utiliser un fichier de configuration au format JUL (au format .properties). Activez ce lien pour de plus amples détails sur la syntaxe de ce fichier.

Si vous utilisez Log4J 2, il vous faudra utiliser un fichier de configuration au format Log4J 2 (un format XML). Activez ce lien pour de plus amples détails sur la syntaxe de ce fichier.

Les niveaux de log de SLF4J seront mis en correspondance avec le niveau de log le plus proche de l'API sous-jacente utilisée.

Attention aux problématiques de performances

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 
 19 
 20 
 21 
 22 
 23 
 24 
 25 
 26 
 27 
 28 
 29 
 30 
 31 
 32 
 33 
 34 
 35 
 36 
 37 
 38 
 39 
 40 
 41 
 42 
 43 
 44 
 45 
 46 
 47 
 48 
 49 

package fr.koor.samples.slf4j;

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

public class TestLogGuard {

    // Un compteur pour démultiplier la problématique 
    private static final int LOOP_COUNT = 10_000_000;

    // Récupération de notre logger.
    private static final Logger LOGGER =  LoggerFactory.getLogger( TestSLF4J.class );

    // Deux attributs utiles pour notre simulation de toString.
    private String aName = "AName";
    private double aValue = Math.random() * 100;
    
    // On simule un traitement itératif qui produit régulièrement des logs.
    public void doSomething() {
        for (int i = 0; i < LOOP_COUNT; i++) {
            aValue += 0.01;
            LOGGER.info( i + ": A message " + this );
        }
    }

    /*
     * Une méthode pour transformer une instance en chaîne de caractères.
     * L'idée est de simuler l'affichage d'objets complexes dans les logs,
     * ce qui est très utile quand on trace l'activité d'un programme.
     */
    @Override
    public String toString() {
        return "TestLogGuard[aName=" + aName + ", aValue=" + aValue + "]";
    }
    

    // Le lancement de la démonstration.
    public static void main(String[] args) {
        TestLogGuard test = new TestLogGuard();
        
        // On prend des mesures de temps pour chronométrer le temps pris par doSomething.
        long begin = System.currentTimeMillis();
        test.doSomething();
        long end = System.currentTimeMillis();
        
        System.out.println( "Duration : " + (end - begin)  + "ms" );
    }

}

Si vous activez les logs pour notre classe, un grand nombre de traces seront affichées sur la console. C'est normal et étant donné le nombre de tours de boucle, je vous conseille de terminer le processus sans en attendre la fin.

Souvent, une fois la mise en production effectué, les logs de l'application sont restreints au niveau error (voir warn) : l'idée étant de ne pas tout enregistrer, mais quand même de tracer les problèmes s'ils surviennent. Le plus simple pour obtenir ce résultat, c'est de modifier ainsi le fichier de configuration de Log4J2 (si vous utilisez Log4J2 comme API de log sous-jacente).

 1 
 2 
 3 
 4 
 5 
 6 
 7 
 8 
 9 
 10 
 11 
 12 
 13 
 14 
 15 
 16 
 17 
 18 
 19 
 20 

<?xml version="1.0" encoding="UTF-8" ?>
<Configuration xmlns="http://logging.apache.org/log4j/2.0/config" status="WARN">

    <Appenders>
    
        <Console name="stdout" target="SYSTEM_OUT">
            <PatternLayout pattern="[%t] %-5p | %-60c | %m (%F:%L)%n" />
        </Console>
        
    </Appenders>

    <Loggers>
        
        <Root level="error">
            <AppenderRef ref="stdout" />
        </Root>
        
    </Loggers>

</Configuration>

Vous pouvez maintenant relancer le programme et, normalement, aucun log ne sera produit. Seul l'appel à System.out.println() devrait vous donner le temps nécessaire pour ne pas produire 10 millions de logs. Sur ma machine cela prend environ 6 secondes, mais le temps peut varier en fonction de la puissance de calcul de votre PC.

Je ne sais pas trop ce que vous en pensez, mais croyez-moi sur parole : c'est beaucoup trop ! Dans ce programme, on passe 6 secondes à produire des chaînes de caractères pour rien. Cela se passe au niveau de la ligne 22 : avant de rentrer dans l'appel à LOGGER.info, on évalue l'expression i + ": A message " + this. Or, si le log ne doit pas être produit, on a quand même fait les concaténations (plus celles cachées dans le toString).

Pour vous en convaincre, veuillez modifier le code de la méthode doSomething ainsi :

 1 
 2 
 3 
 4 
 5 
 6 
 7 

public void doSomething() {
    for (int i = 0; i < LOOP_COUNT; i++) {
        aValue += 0.01;
        if ( LOGGER.isInfoEnabled() )
            LOGGER.info( i + ": A message " + this );
    }
}

La différence, dans ce nouveau code, c'est l'utilisation de la condition if ( LOGGER.isInfoEnabled() ) : on parle de « log guard » (un gardien de log). Cette condition permet de vérifier si le log doit être produit ou non. Certes, la méthode info fait normalement ce test, mais dans notre cas cela nous évitera de réaliser les concaténations avant l'appel à la méthode.

Relancez le programme avec le « log guard » et constatez la différence. Sur ma machine, cela ne prend plus que 40 millisecondes. CQFD : nous avions donc bien passé environ 6 secondes à produire de chaînes de caractères totalement inutiles !

Une autre manière de régler le problème de performance, consiste à utiliser les logs formatés : cette technique ressemble un peu à l'utilisation de la méthode System.out.printf(), en définissant des points d'injections dans une chaîne de caractères servant de format. Afin de tester cette possibilité, je vous propose de réécrire le contenu de la méthode doSomething tel que proposé dans l'exemple ci-dessous. Relancez le programme. Sur ma machine, je ne mets que 86 millisecondes pour terminer les 10 millions de tours de boucles.

 1 
 2 
 3 
 4 
 5 
 6 

public void doSomething() {
    for (int i = 0; i < LOOP_COUNT; i++) {
        aValue += 0.01;
        LOGGER.info( "{}: A message {}", i, this );
    }
}

En synthèse :

Au terme de cette démonstration, j'espère vous avoir convaincu de ne pas avoir de concaténations dans vos logs.

Utilisation de l'API Log4J2 Qu'est-ce qu'un « Design Pattern » ?