Mais pourquoi je loggue autant?

La semaine dernière, j’ai trouvé un problème intéressant. Lors de la mise à jour d’une application, celle-ci a commencé à logguer en mode DEBUG de façon aléatoire. Sur certains serveurs tout marchait correctement, mais sur d’autres, non. En apparence, tout semblait normal, le fichier log4j.properties n’avait pas changé.

En regardant les logs, un message à attiré mon attention:

Chose intéressante, sur les serveurs à problème le message était plutôt de ce type:

SLF4j va prendre la première implémentation qu’il trouve. Dans notre cas ce sera logback-classic sur certains serveurs (cela va dépendre du chargement des classes dans le classloader).

Là où le problème arrive c’est que nous ne sommes pas supposés utiliser logback mais plutôt log4j. Nous n’avons pas de fichier de configuration de logback.

En suivant la documentation, voici ce qui se passe:

Nous n’avons aucun de ces fichiers,  donc logback va écrire dans la console. Mais avec quel niveau de logs ? Et bien c’est écrit dans la doc :

C’était donc ca. Un manque de fichier de configuration et notre serveur passe en mode DEBUG.

Mais pourquoi avoir rajouter une telle librairie (logback-classic)?

Ce n’était pas volontaire, c’est une dépendance transitive qui est remontée en ajoutant une autre dépendance à un projet.

conclusion 1: toujours surveiller les dépendances remontées par les librairies

conclusion 2: toujours prêter attention aux messages dans les logs

PS: dans la version 1.6.6, slf4j va indiquer en plus dans les logs, la classe StaticLoggerBinder qu’il utilise. Cela permet de contrôler encore mieux ce qu’il se passe réellement sur le serveur.