Participer au site avec un Tip
Rechercher
 

Améliorations / Corrections

Vous avez des améliorations (ou des corrections) à proposer pour ce document : je vous remerçie par avance de m'en faire part, cela m'aide à améliorer le site.

Emplacement :

Description des améliorations :

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.

Liens entre les APIs java.util.logging, Log4J 2 et SLF4J

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).

il existe d'autres API de log comparables à SLF4J et notamment JCL (Java Commons Logging).

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.

Ajout des jar de SLF4J au CLASSPATH de la JVM

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.

ne rendez pas encore des trois derniers jars accessibles dans le CLASSPATH. Nous verrons cette étape un peu plus loin dans ce chapitre.

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>
Définition des dépendances Maven pour SLF4J, par-dessus java.util.logging.

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>
Définition des dépendances Maven pour SLF4J, pardessus Log4J2.
dans un premier temps, activez la première configuration Maven.

Produire des logs avec SLF4J

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

Dans une certaine mesure, on peut dire que SLF4J et Log4J 2 se ressemblent beaucoup. Si l'on connaît déjà l'une des deux APIs, apprendre à manipuler l'autre est assez simple.

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.

un composant logiciel est une unité fonctionnelle qui peut regrouper une ou plusieurs classes Java. En Java, un composant logiciel est souvent associé à un package de votre application.
 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
        
    }
    
}
Fichier TestSLF4J.java : exemple d'instanciation d'un logger SLF4J

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
        
    }
    
}
Fichier TestSLF4J.java : exemple d'instanciation d'un logger SLF4J grâce à la classe courante

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.

Vous l'aurez remarqué, le logger est, à chaque fois, défini en tant que constante privée (private static final). Afin d'améliorer les performances de votre programme, il est important de respecter cette manière de faire. En tant que membre statique, l'instanciation du logger est sa configuration n'interviendront qu'une unique fois. De plus, le fait qu'il soit marqué comme étant statique garantira que la JVM pourra placer cette instance dans un metaspace (ou le perm dans les vieilles JVMs). L'activité du garbage collector en sera donc réduite. Je vous renvoie vers les chapitres dédiés au garbage collector pour de plus amples informations.

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 !
        
    }
    
}
Pour un nom de logger, vous n'aurez qu'une unique instance.

Les différents niveaux de logs

Les niveaux de logs sont les suivants :

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" );
        
    }
    
}
Les méthodes de production de log

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 ); 
        }
        
    }
    
}
Injecter des informations complémentaires dans vos logs.

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.

personnellement, j'ai tendance à privilégier le tandem SLF4J / Log4J 2.

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

mal utilisés, vos logs peuvent consommer beaucoup de ressources pour pas forcément grand-chose. Le mieux, pour comprendre cette problématique de performance, c'est un petit exemple concret : nous allons donc considérer l'exemple suivant.
 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" );
    }

}
Un petit exemple de code pour comprendre une problématique de performance.

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>
Fichier log4j2.xml utilisé pour la configuration de notre moteur de logs.

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 );
    }
}
Utilisation d'un « log guard »

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 !

si le message à tracer ne contient aucune concaténation, le « log guard » n'est plus nécessaire. Si vous laissez le « log guard » pour protéger un log sur une chaîne de caractères constante et que le niveau de log est autorisé, la vérification aura lieu deux fois : c'est pas top non plus.

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 );
    }
}
Utilisation d'un log formaté
personnellement, c'est la technique que je préconise vivement. Certes le programme prend un petit peu plus de temps, mais cette technique évite la présence des « log guards », souvent un peu lourd à écrire systématiquement. En conséquence, la lisibilité du code en sera meilleure.

En synthèse :

Style de code Temps de réponse pour 10 millions de logs désactivés
LOGGER.info( i + ": A message " + this ); Environ 6000 ms
if ( LOGGER.isInfoEnabled() )
    LOGGER.info( i + ": A message " + this );
40 ms
LOGGER.info( "{}: A message {}", i, this ); 86 ms

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 » ?