Publié par

Il y a 9 ans -

Temps de lecture 6 minutes

SLF4J – Problèmes et solutions

SLF4J (Simple Logging Facade For Java) est une API d’abstraction de frameworks de log de plus en plus adoptée. Lorsque j’ai découvert cette API j’étais surtout fasciné par l’élégance des messages paramétrés utilisant des placeholders et par la simplicité de changement du framework de logging (juste en modifiant le classpath). La puissance de l’implémentation native Logback m’a fait adopter le couple SLF4J/Logback. J’ai aussitôt commencé à les utiliser sur mes nouveaux projets et à migrer ceux en cours vers SLF4J/Logback. Hélas le passage vers SLF4J et sa mise en place sur mes nouveaux projets n’a pas été exempt de surprises.

Dans cet article je vous présente deux problèmes parmi les nombreux que j’ai rencontrés: l’erreur de binding et la perte de log. Chaque problème sera accompagné d’un exemple de code. Mais avant cela je vous propose un petit rappel sur le fonctionnement de SLF4J.

Fonctionnement de SLF4J

SLF4J se compose de deux parties : une API et une implémentation (nommée binding SLF4J).

L’API SLF4J

Afin d’utiliser SLF4J dans un projet il faut que l’API slf4j-api-version.jar soit présente dans le classpath de compilation.
Les deux classes les plus importantes de l’API sont :

  • org.slf4j.Logger : Interface principale de l’API. Représente un objet log (correspond à une category dans les premières versions de Log4j).
  • org.slf4j.LoggerFactory : La classe responsable, vous l’avez deviné, de la création des loggers mais aussi de l’initialisation de SLF4J.

Une utilisation typique de l’API ressemble à ça :

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

public class BindingTest {
  private static Logger logger = LoggerFactory.getLogger(BindingTest.class);

Une implémentation

SLF4J arrive avec plusieurs implémentations :

  • slf4j-log4j12 : Une implémentation utilisant log4j.
  • slf4j-jdk14 : Une implémentation utilisant le jdk Logging.
  • slf4j-simple : Une implémentation utilisant System.err.println.
  • slf4j-nop : No Opération. Aucun log n’est affiché.
  • slf4j-jcl : Une implémentation commons-logging (si vous tenez encore à l’utiliser).
  • Logback : Une implémentation native de la librairie.

L’initialisation de la librairie se fait au premier appel de LoggerFactory.getLogger(), soit au chargement de la première classe qui déclare un Logger static soit à l’instanciation d’une classe qui déclare un Logger non static. Pendant l’initialisation SLF4J essaye de charger la classe org.slf4j.impl.StaticLoggerBinder. Ainsi chaque implémentation se doit de définir cette classe. La classe StaticLoggerBinder a la responsabilité de charger et d’initialiser la configuration de l’implémentation sous-jacente : log4j par exemple.

Problèmes rencontrés avec l’utilisation de SLF4J

Erreur de Binding

Le binding dans le jargon SLF4J représente le mécanisme de plug de la librairie d’implémentation. Ceci se passe juste en plaçant la librairie d’implémentation dans le classpath de l’application. SLF4J n’accepte qu’une seule implémentation au runtime afin d’éviter tous les problèmes liés au chargement de classes (classloading).

La vérification de la présence d’une et d’une seule implémentation se fait au moment de l’initialisation de SLF4J i.e. lors de l’appel à LoggerFactory.getLogger() comme spécifié précédemment. Si le classpath contient plusieurs occurrences de cette classe alors une erreur se produit et SLF4J interrompt le processus de chargement.

Voici un exemple de l’erreur de binding :

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:~/m2repo/org/slf4j/slf4j-log4j12/1.6.1/slf4j-log4j12-1.6.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:~/m2repo/ch/qos/logback/logback-classic/0.9.28/logback-classic-0.9.28.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.

Afin de résoudre ce problème il ne faut garder qu’une seule implémentation dans le classpath. Heureusement Le message d’erreur et assez descriptif et fournit la liste de tous les jars contenant la classe StaticLoggerBinder et qui sont présents dans le classpath.
Les utilisateurs de Maven ou de Ivy doivent vérifier les dépendances transitives qui sont souvent sources d’erreur.

Perte de logs

Ce problème est moins évident que le premier, comment les logs peuvent ils être perdus ?

Prenons l’exemple du code de la perte de log. L’application utilise SLF4J/Logback et ne fait qu’instancier un contexte Spring avec Debug comme niveau de Log. Voici le contenu du fichier logback.xml :

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{26} - %msg%n</Pattern>
    </layout>
  </appender>


  <root level="debug">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

Si vous lancez l’exemple vous remarquerez qu’il y a très peu de messages affichés, alors qu’on s’attend à une énorme quantité de log !

En effet Spring dépend de commons-logging une autre fameuse API d’abstraction de framework de log. Lors du lancement de l’exemple nous assistons à deux initialisations : celle de SLF4J/Logback et celle de commons-logging. Les messages de logs de Spring sont envoyés vers commons-logging ce qui n’est pas connu par SLF4J. Ce problème arrive aussi lorsque certaines des dépendances de l’application utilisent directement log4j ou jdk logging. Les messages de ces librairies seront « perdus ».

Mais comment doit-on faire pour ne pas perdre ces logs ? Ou encore comment peut-on consolider tous les logs au sein d’un seul framework de log ?

Afin de répondre à cette question, SLF4J propose des ponts (bridges) pour les frameworks les plus utilisés. Avec les bridges tous les appels aux librairies legacy vont être routés vers l’unique implémentation de SLF4J. On trouve principalement :

  • log4j-over-slf4j : Bridge log4j.
  • jcl-over-slf4j : Bridge commons-logging
  • jul-to-slf4j : Bridge java.util.logging. Notez bien que c’est jul-to-slf4j et non pas jul-over-slf4j comme pour log4j ou jcl. C’est parce qu’il n’est pas possible de redéfinir (réécrire) les classes de java.util.logging. Pour arriver à ses fins le bridge utilise les LogRecord et Handler de Jdk logging.

Afin de corriger le problème vu plus haut il faut commencer par exclure commons-logging du classpath. Ensuite il faut rajouter la dépendance vers le bridge jcl-over-slf4j et le tour est joué.

Notez bien que le bridge et la librairie wrappée ne peuvent être présents simultanément dans le classpath.

Dans un cas réel, il est très difficile de connaitre tous les frameworks de log utilisés. Les plus fainéants peuvent inclure automatiquement tous les bridges (sauf celui de l’implémentation choisie) dans le classpath.

Télécharger les exemples de codes :

Publié par

Commentaire

6 réponses pour " SLF4J – Problèmes et solutions "

  1. Publié par , Il y a 9 ans

    C’est quand même devenu un sacré foutoir, ces mécanismes de logs (LOG4J, commons-logging, SLF4J, LogBack, soit 2 implémentations « majeures » (Log4j et son évolution Logback) et … 2 couches d’abstractions majeures !).
    Tout çà pour :
    – offrir la possibilité via les couches d’abstractions de changer d’implémentation au sein d’un projet => franchement c’est une situation ultra-rare …
    – permettre d’unifier les différentes librairies quant à leur utilisation des logs : je n’ai jamais compris pourquoi des interfaces de logs (équivalent Logger et LogFactory) n’avaient pas été directement intégrés dans le langage : il y aurait eu beaucoup moins de problème.

    Tout çà pourrait ne pas être très grave, mais les dépendances transitives de Maven, évoquées dans l’article, font qu’il est aujourd’hui hyper laborieux d’avoir un classpath cohérent et stable (la cohabitation des jars commons-logging et slf4j est problématique et ultra-fréquente). En plus il faut aussi bien voir que 95% des dépendances Maven sont mal déclarées (ne sont pas optionnelles et forcent la transitivité – mais quand elles sont optionnelles les gens râlent qu’ils doivent (re)déclarer manuellement une dépendance spécifique pour une fonction particulière …).

    Avec un peu de recul on se demande quand même comment on a pu arriver à un tel souk sur une problématique pas particulièrement compliquée à la base (encore une fois, rien de dramatique, mais un joyeux foutoir quand même).

  2. Publié par , Il y a 9 ans

    Le plugin enforcer de maven (avec la règle ‘bannedDependencies’) permet de détecter rapidement les dépendances sur commons-logging et/ou log4j et donc de faciliter la migration vers slf4j et logback.

    http://maven.apache.org/plugins/maven-enforcer-plugin/

  3. Publié par , Il y a 9 ans

    Merci pour cet article très informatif. Je voudrais noter que l’avertissement « SLF4J: Class path contains multiple SLF4J bindings. » n’est qu’un avertissement. SLF4J s’initialisera avec le premier binding trouvé dans le class path même s’ils en existent plusieurs.

  4. Publié par , Il y a 9 ans

    @Rody. Merci pour l’info, j’avais déjà vu (de loin) le plugin enforcer, mais sur sa description (« (…) such as Maven version, JDK version and OS family »), il ne m’avait pas l’air très intéressant.
    S’il y a moyen de poser des règles fines pour gérer les dépendances, je vais jetter un oeil (plus dans une optique de gestion des dépendances Maven en soi que par rapport aux mécanismes de log).

  5. Publié par , Il y a 9 ans

    @SRG
    Je suis d’accord que le choix du framework de log est devenu très difficile. Pour comprendre pourquoi nous sommes là il faut prendre en compte l’historique du langage,de la plateforme JEE et leur évolution.
    sans oublié la compréhension des développeurs de la question des logs. Il y’a quelques années c’était une question peu traitée.
    Pour ce qui est de changement d’implémentation au sein d’un projet, j’aime l’idée de pouvoir être capable de changer d’implémentation quand je veux la chose que j’utilise bop surtout dans mes testes ou j’utilise slf4j-simple.
    De ma part je trouve que les « bridges » SLF4J sont extrêmement utiles, et j’en ai besoin dans mes derniers projets.

    Pour la gestion des dépendances transitives de Maven, je partage à 100% ton avis. Comme l’a bien dit @Rody le plugin enforcer peut aider.

    @Ceki Gulcu Merci pour le correctif. ça veut dire que j’ai pas eu de chance à ce que logback ne soit pas en tête du classpath :).

Laisser un commentaire

Votre adresse de messagerie ne sera pas publiée. Les champs obligatoires sont indiqués avec *

Nous recrutons

Être un Xebian, c'est faire partie d'un groupe de passionnés ; C'est l'opportunité de travailler et de partager avec des pairs parmi les plus talentueux.