Utilisation de l'API Log4J2

Utilisation du package java.util.logging Utilisation de l'API SLF4J

Accès rapide :
Introduction
Installation de Log4J 2
Installation manuelle
Installation par Maven
Produire des logs avec Log4J 2
Acquisition d'un logger
Les différents niveaux de logs
Produire un log à un niveau donné
Configurer vos logs
Gestion des appenders
Contrôler les niveaux de log
Attention aux problématiques de performances
Utilisation de l'outil Chainsaw

Introduction

Log4J est une API de log proposée par la fondation Apache et vous pouvez trouver ce logiciel sur son site officiel : http://logging.apache.org/log4j/2.x/ Le nom Log4J signifie Logging for Java.

Attention, historiquement parlant, il y a eut deux APIs de logging appelées Log4J. La première fut développée par la fondation Apache à partir de 2001. Cette version est maintenant abandonnée au profit de Log4J 2 : il s'agit d'une réécriture complète du moteur de log. Il n'y a donc aucune compatibilité entre les deux versions et la migration d'une version à l'autre nécessitera des modifications dans le code.

Comme l'API Log4J (première du nom) est apparue bien avant l'API JUL (java.util.logging), elle a été massivement utilisée. Lors du passage à Log4J 2, les utilisateurs historiques ont basculé sur cette nouvelle implémentation au détriment de JUL.

Installation de Log4J 2

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

Installation manuelle

Le logiciel Apache Log4J 2 peut être téléchargé sur son site officiel : http://logging.apache.org/log4j/2.x/download.html. Une fois l'archive téléchargée, vous y trouverez deux archive jars (Java ARchive) principales qui sont log4j-api-2.13.3.jar et log4j-core-2.13.3.jar (les numéros de versions pourront varier : je vous conseille toujours de prendre les versions les plus récentes). 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 visible dans les librairies référencées par le projet, comme le montre la capture d'écran ci-dessous.

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 de la dépendance Log4J 2 pour votre projet Maven.

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

<dependencies>
    <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>
        <version>2.13.3</version>
    </dependency>
</dependencies>

Produire des logs avec Log4J 2

Pour produire des logs avec l'API Log4J 2, 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 LogManager.getLogger. Bien entendu, la classe LogManager doit être celle localisée dans le package org.apache.logging.log4j. D'autres packages peuvent aussi contenir une classe de même nom (et notamment le package java.util.logging) : il est donc important de faire très attention à l'import utilisé. 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.log4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LogManager.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.log4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LogManager.getLogger( TestLog4J.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 Log4J 2, 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 LogManager.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.log4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4J {

    // Récupérations multiples de notre logger.
    private static final Logger LOGGER1 = LogManager.getLogger( "Compo1" );
    private static final Logger LOGGER2 = LogManager.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

Il nous faut maintenant bien comprendre les différents niveaux de logs avec l'API Log4J2. Pour ce faire, nous allons commencer par regarder un extrait du contenu de la classe org.apache.logging.log4j.Level.

 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 
 50 
 51 

import org.apache.logging.log4j.Logger;

// Les imports

public final class Level implements Comparable<Level>, Serializable {

    // ...
    
    /**
     * No events will be logged.
     */
    public static final Level OFF;              // 0        == Integer.MIN_VALUE

    /**
     * A severe error that will prevent the application from continuing.
     */
    public static final Level FATAL;            // 100

    /**
     * An error in the application, possibly recoverable.
     */
    public static final Level ERROR;            // 200

    /**
     * An event that might possible lead to an error.
     */
    public static final Level WARN;             // 300

    /**
     * An event for informational purposes.
     */
    public static final Level INFO;             // 400

    /**
     * A general debugging event.
     */
    public static final Level DEBUG;            // 500

    /**
     * A fine-grained debug message, typically capturing the flow through the application.
     */
    public static final Level TRACE;            // 600

    /**
     * All events should be logged.
     */
    public static final Level ALL;              // 2147483647 == Integer.MAX_VALUE
    
    // ...
    
}

Chaque niveau de log est associé à une valeur numérique lors de l'instanciation de la constante. J'ai rajouté les valeurs associées en commentaire à la suite de chaque niveau. Autoriser l'affichage des logs à un niveau donné active aussi tous les niveaux de logs ont une valeur numérique inférieure. Ainsi, si vous configurez les logs pour afficher à partir du niveau Level.INFO, vous couperez les niveaux supérieurs (Level.DEBUG et Level.TRACE, par contre vous activerez aussi tous les niveaux inférieurs (WARN, ERROR et FATAL).

Si, pour un logger donné vous le configurez au niveau Level.OFF (de valeur Integer.MIN_VALUE), aucun log sera produit, car tous les niveaux de log ont une valeur numérique supérieure. A l'opposé, si vous configurez votre logger au niveau Level.ALL (de valeur Integer.MAX_VALUE), tous les logs seront produits, car ces niveaux auront tous une valeur numérique inférieure.

Produire un log à un niveau donné

La première solution pour produire un log est d'utiliser la méthode log de votre logger. Voici un exemple d'utilisation de cette méthode.

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

package fr.koor.samples.log4j2;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4J {

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

    // Le point d'entrée du programme.
    public static void main( String [] args ) {
        
        // On produit un log de niveau informatif.
        LOGGER.log( Level.INFO, "Hello World with Log4J 2" );

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

}

Si vous lancez la classe, vous obtiendrez un résultat proche (la première information temporelle sera différente) de cet affichage.

15:28:49.663 [main] ERROR fr.koor.samples.log4j2.TestLog4J - Houston, we have a problem

Comme vous le constatez, le log informatif n'est pas affiché : c'est normal, car par défaut les logs sont activés qu'à partir du niveau Level.ERROR. Pour changer cela, il va falloir fournir un fichier de configuration pour Log4J 2.

Une autre solution consiste à utiliser des méthodes de convenance qui renvoient les appels sur Logger.log. Ces méthodes sont nommées avec le niveau de log associé (Logger.info, Logger.error...). Voici un exemple d'utilisation.

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

package fr.koor.samples.log4j2;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4J {

    // Récupération de notre logger.
    private static final Logger LOGGER =  LogManager.getLogger( TestLog4J.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 Log4J 2" );

        // 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 
 28 

package fr.koor.samples.log4j2;

import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4J {

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

    // Le point d'entrée du programme.
    public static void main( String [] args ) {
        
        // On produit un log de niveau informatif.
        LOGGER.log( Level.INFO, "Hello World with 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 ); 
        }
        
    }

}

Sous condition d'autoriser les logs de niveau informatifs (nous allons y revenir dans quelques instants), vous obtiendrez le résultat suivant quand aucune exception n'est déclenchée.

[main] INFO  | fr.koor.samples.log4j2.TestLog4J                             | Hello World with Log4J 2 (TestLog4J.java:16)
[main] INFO  | fr.koor.samples.log4j2.TestLog4J                             | value == 1 - result == 3 (TestLog4J.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.log4j2.TestLog4J                             | Hello World with Log4J 2 (TestLog4J.java:16)
[main] ERROR | fr.koor.samples.log4j2.TestLog4J                             | Houston, we have a problem. (TestLog4J.java:23)
java.lang.ArithmeticException: / by zero
    at fr.koor.samples.log4j2.TestLog4J.main(TestLog4J.java:20) [bin/:?]

Configurer vos logs

Vous pouvez configurer Log4J 2 grâce à un fichier XML : si vous souhaitez qu'il soit vu par défaut, il faut qu'il s'appelle log4j2.xml. Il doit aussi être accessible à partir du CLASSPATH : dit autrement, vous devez le placer dans le dossier src de votre projet Eclipse et non pas à la racine du projet, comme le montre la capture d'écran suivante.

Et voici un premier exemple de contenu pour ce fichier de configuration. Quelques explications suivront.

 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="info">
            <AppenderRef ref="stdout" />
        </Root>
        
    </Loggers>

</Configuration>

Gestion des appenders

Log4J 2 définit la notion d'appender pour identifier la destination de vos logs. Il existe plusieurs types d'appenders et notamment :

• L'appender de type <Console> : comme vous vous en doutez, cet appender permet d'ajouter les logs dans la console. L'exemple ci-dessus vous montre aussi qu'il est possible de formater les logs sur la console. Voici la signification des différentes séquences proposées par l'exemple (à noter que cela ressemble un peu aux possibilités offertes par la méthode System.out.printf).

  • %t : permet d'injecter le nom du thread ayant produit le log.
  • %-5p : permet d'injecter le niveau (level) du log. Dans notre cas, il occupera cinq caractères et sera aligné par la gauche.
  • %-60c : permet d'injecter le nom du logger ayant généré ce log (dans notre cas, le nom pleinement qualifié de la classe).
  • %m : permet d'injecter le message du log.
  • %F : permet d'injecter le nom du fichier Java contenant la ligne de code ayant produit le log.
  • %L : permet d'injecter le numéro de ligne de code, dans le fichier considéré, ayant produit le log.
  • %n : tout simplement pour injecter un retour à la ligne en fin de log.
  • D'autres séquences existent, je vous renvoie vers la documentation de Log4J 2 pour de plus amples informations.

• L'appender de type <JDBC> : permet d'insérer les logs dans une table en base de données relationnelle. Vous pouvez, bien entendu, contrôler l'URL du serveur de base de données, le nom de la table devant recevoir les logs ainsi que les colonnes devant recevoir les différentes parties du log.

• L'appender de type <JPA> : permet d'insérer les logs dans une table en base de données relationnelle, mais en utilisant un ORM (Object Relational Mapping) et un mapping JPA.

• L'appender de type <File> : permet d'ajouter les logs dans un fichier. Vous pouvez contrôler le nom du fichier produit ainsi que le format des logs qui y seront insérés.

• L'appender de type <NoSql> : permet d'insérer les logs dans une base de données non relationnelle (MongoDB ou autre).

• L'appender de type <RollingFile> : permet d'ajouter les logs dans des fichiers tournant. Vous pouvez configurer les seuils permettant de passer au fichier suivant.

• L'appender de type <Socket> : permet de pousser les logs sur une socket. Vous pouvez spécifier l'adresse IP du serveur devant recevoir les logs ainsi que le port réseau utilisé.

Par exemple, si vous souhaitez envoyer vos logs sur la console, mais aussi dans un fichier logs.txt, vous pouvez utiliser la configuration suivante.

 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 

<?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>
        
        <File name="file" fileName="logs.txt">
            <PatternLayout pattern="[%t] %-5p | %-60c | %m (%F:%L)%n" />
        </File>
        
    </Appenders>

    <Loggers>
        
        <Root level="info">

            <AppenderRef ref="stdout" />
            <AppenderRef ref="file" />

        </Root>
        
    </Loggers>

</Configuration>

Comme vous le constater, il est important d'enregistrer votre appender dans la section <Root> sans quoi les logs ne seraient envoyés que sur la console. L'association est faite via l'attribut ref="file" qui doit correspondre à la valeur de l'attribut name de votre appender.

Pour utiliser des fichiers tournants, je vous recommande la configuration ci-dessous.

 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 

<?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>
        
        <RollingFile name="rollingFile" fileName="logs/logs.txt"
                     filePattern="logs/logs-%d{yyyy-MM-dd}-%i.txt">
            <PatternLayout pattern="[%t] %-5p | %-60c | %m (%F:%L)%n" />
            <Policies>
                <TimeBasedTriggeringPolicy />
                <SizeBasedTriggeringPolicy size="10 MB"/>
            </Policies>
        </RollingFile>
        
    </Appenders>

    <Loggers>
        
        <Root level="info">

            <AppenderRef ref="stdout" />
            <AppenderRef ref="rollingFile" />

        </Root>
        
    </Loggers>

</Configuration>

Les logs seront envoyés dans le fichier logs/logs.txt (attribut fileName). Vous constaterez qu'il y a deux définitions dans la section <Policies> : la première indique qu'il faut changer de fichier à chaque nouveau jour et la seconde indique que chaque fichier historisé ne pourra pas dépasser 10 MB. Ainsi si l'une des deux stratégies est activée, le fichier logs/logs.txt sera historisé puis remit à zéro. Les fichiers historisés seront nommés d'après ce pattern : logs/logs-%d{yyyy-MM-dd}-%i.txt. Vous aurez compris à quoi correspond le %d{yyyy-MM-dd} : il injecte la date courante dans le nom du fichier. Par contre, à quoi correspond le %i ? C'est très simple, chaque jour, vous pourrez produire plusieurs fichiers de logs (notamment à cause de la taille maximale du fichier) : la séquence %i injecte un index unique dans le nom d'un fichier.

Si vous souhaitez utiliser d'autres appenders, je vous recommande de lire la documentation officielle : toutes les possibilités de configuration y sont détaillées.

Contrôler les niveaux de log

Et maintenant la partie la plus importante : comment sélectionner les logs qui seront produits et ceux qui ne le seront pas ? On contrôle ces aspects dans la section <Loggers>. Notez que ce tag possède un attribut level : sa valeur correspond aux niveaux de logs autorisés par défaut. Dans l'exemple, les niveaux Level.INFO, Level.WARN, Level.ERROR et Level.FATAL sont autorisés (car tous, de valeur inférieure ou égale à celle de Level.INFO).

Outre cette valeur par défaut, vous pouvez rajouter des tags <Logger> pour configurer spécifiquement certains de vos loggers. Considérons la nouvelle configuration ci-dessous.

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

<?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>
        
        <Logger name="fr.koor.samples.log4j2" level="info" />

        <Root level="error">

            <AppenderRef ref="stdout" />

        </Root>
        
    </Loggers>

</Configuration>

Du point de vue de l'appender utilisé, on envoie les logs sur la console (j'ai retiré la possibilité de stocker les logs sur un fichier). Par défaut, seules les erreurs seront tracées : cela est indiqué avec le niveau par défaut précisé sur le tag <Root level="error">. Si votre projet contient de nombreux packages, tous les loggers de ces différents packages sont donc limités à ne tracer que les erreurs (fatales ou non).

Par contre, il y a une exception : tous les loggers dont le nom commence par fr.koor.samples.log4j2 seront quant à eux configurés pour tracer à partir du niveau informatif.

Si vous souhaitez changer la configuration, arrêtez le programme, modifiez le fichier XML à votre convenance, puis relancez votre programme. La nouvelle configuration devrait être prise en considération.

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.log4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

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 = LogManager.getLogger( TestLogGuard.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 Level.ERROR (voir Level.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.

 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 85 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'outil Chainsaw

Pour finir ce chapitre, j'aimerais vous parler rapidement d'un outil graphique permettant de visualiser et filtrer les logs que vous avez produits. Cet outil se nomme « Chainsaw », il est gratuit et il est aussi proposé par la fondation Apache. Pour télécharger ce logiciel, rendez-vous avec votre navigateur favori sur cette page : https://logging.apache.org/.

Vous devriez y trouver un lien vers le site officiel de Chainsaw : activez, bien entendu, ce lien hypertexte. Cet outil permet de travailler sur des fichiers de logs produits par Log4J 2, mais aussi par les autres API de log pour C++, PHP... C'est un outil graphique codé en Java via l'API Swing. Un des avantages à utiliser un outil graphique, c'est la colorisation en fonction des niveaux de logs.

Un tutoriel sur Chainsaw est directement proposé dans l'outil. D'autres outils de visualisation de logs existent sur Internet.

Utilisation du package java.util.logging Utilisation de l'API SLF4J