Logging dans JBoss


JBoss AS utilise Log4J pour ses propres traces. Une vieille légende dit qu'il est impossible de gérer correctement les traces applicatives avec Log4J, et que celles-ci se retrouvent rejetée dans les traces du serveur. Le but de cet article est de clarifier cette situation et d'apporter quelques réponses.

Les exemples de configuration de cet article ont été réalisés avec JBoss AS 5.1, mais les principes s'appliquent aux versions précédentes ; à partir de JBoss AS 6, Log4J a été abandonné au profit d'une solution interne, JBoss Log Manager.


Log4J dans JBoss

Log4J est présent sous deux formes dans JBoss. Il y a des traces du démarrage qui sortent dans la console et dans le fichier boot.log, puis les traces du serveur qui sortent aussi dans la console et dans le fichier server.log.

Traces de démarrage

Les traces qui sortent au démarrage de JBoss ne sont pas les plus importantes et sont rarement reconfigurées. Toutefois, si vous voulez en modifier le sortie ou le niveau, ça se passe dans run.jar, le fichier log4j.properties.

Cette configuration est active jusqu'à ce que le service de logging de JBoss démarre.

Service de logging

Une fois le service de logging démarré, c'est la configuration de conf/jboss-log4j.xml qui utilisée. C'est dans ce fichier qu'on fait l'essentiel du travail de configuration.

Le réflexe avant une mise en production est de désactiver le ConsoleAppender et de n'associer que le FileAppender principal au root logger.

  <root>
     <priority value="${jboss.server.log.threshold}"/>
     <appender-ref ref="FILE"/>
  </root>

Le reste de la configuration est très correcte en JBoss 5 :

Tous ces points étaient critiquables dans le versions précédentes de JBoss et c'est avec plaisir que j'ai vu ces évolutions. Ça fait du travail en moins pour la mise en production. La seule critique que je pourrais formuler concerne l'excès de commentaires. Certes, c'est utile pour les exemples, mais je conseille de les supprimer avant la mise en production, afin d'avoir un fichier plus lisible.


Log4J dans les applications

La façon dont est chargé Log4J dans une application dépend des pratiques de développeurs. En particulier, il faut savoir s'ils ont chargé la configuration explicitement, en indiquant l'URL du fichier de configuration.

Configuration par défaut

Pour un déploiement en war, si aucun chargement n'est fait explicitement, le fichier log4j.jar doit être dans WEB-INF/lib et le fichier log4j.xml doit être dans WEB-INF/classes.

Pour un déploiement en ear, ces fichiers ne doivent pas être dans le war, mais uniquement dans l'ear, dans son répertoire lib pour le jar et directement à la racine pour log4j.xml. Dans ce cas, la configuration locale n'est prise en compte que si l'isolation du classloader est activée pour l'ear, ce qui n'est pas le cas par défaut. Cette situation a été à l'origine de la légende citée en introduction.

La configuration locale de Log4J ne doit absolument pas avoir de ConsoleAppender car cela enverrait des traces dans la sortie standard qui est interceptée par le service de logging de JBoss pour être ressortie dans un logger STDOUT, au niveau INFO. Le résultat serait de voir des traces étranges, avec des informations en double (date et heure) et pas forcément pertinentes (niveau).

Configuration explicite

TODO

Isolation de Classloader

Dans tous les cas, pour que la configuration locale puisse être prise en compte, il faut que les classes locale de Log4J soient chargée en priorité sur les classes installées dans JBoss. Ça ne pose pas de problème pour un war, mais dans le cas de déploiement en ear, la meilleure façon de faire est d'activer l'isolation, dans le fichier deployers/ear-deployer-jboss-beans.xml :

 <bean name="JBossAppParsingDeployer" class="org.jboss.deployment.JBossAppParsingDeployer">
   ...
   <property name="callByValue">trueproperty> 
 </bean>
 <bean name="EARClassLoaderDeployer" class="org.jboss.deployment.EarClassLoaderDeployer">
   <property name="isolated">true</property>
 </bean>

En plus de nous faciliter la tâche pour Log4J, ce changement de configuration nous rapproche du comportement standard attendu par un serveur d'applications JavaEE...


Solution mixte

Le wiki de JBoss propose une solution mixte : pas besoin de mettre Log4J dans l'application pour envoyer ses traces dans un fichier à part. L'idée, c'est de configurer Log4J au niveau global en utilisant un filtre sur l'origine des traces, non pas par rapport aux loggers, mais au fichier de déploiement. Ce filtre est fourni par JBoss, via le wiki pour les anciennes versions, directement dans JBoss à partir de la version 6, et via une mise à jour de JBoss Logging pour la version 5.1. J'ai fait l'essai dans cette version.

J'ai donc récupéré les fichiers jboss-logging-spi.jar et jboss-logging-log4j.jar, et si ils n'ont pas exactement ces noms, il faut les renommer et les mettre dans le répertoire bin de JBoss. Ceci est nécessaire pour avoir le nouveau filtre TCLMCFilter. J'ai ensuite créé mon appender dans jboss-log4j.xml qui fera sortir les traces issues de swmsg-app.ear.

 <appender name="SWFILE" class="org.jboss.logging.appender.DailyRollingFileAppender">
   <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
   <param name="File" value="${jboss.server.log.dir}/swmsg.log"/>
   <param name="Append" value="true"/>
   <param name="DatePattern" value="'.'yyyy-MM-dd"/>
   <layout class="org.apache.log4j.PatternLayout">
     <param name="ConversionPattern" value="%d %-5p [%c] (%t) %m%n"/>
   </layout>
   
   <filter class="org.jboss.logging.filter.TCLMCFilter">
     <param name="AcceptOnMatch" value="true"/>
     <param name="DeployURL" value="swmsg-app.ear"/>
   </filter>
   <filter class="org.apache.log4j.varia.DenyAllFilter"></filter>
 </appender>

Puis j'ai ajouté ce appender au root logger.

 <root>
   <priority value="${jboss.server.log.threshold}"/>
   <appender-ref ref="FILE"/>
   <appender-ref ref="SWFILE"/>
 </root>

Le résultat, c'est de voir un nouveau fichier log/swmsg.log avec les traces de mon application.

Par la suite, j'ai voulu ajouter un AsyncAppender pour essayer de réduire les temps de traitement des traces, mais ça a été un échec.

 <appender name="ASYNC" class="org.apache.log4j.AsyncAppender">
   <appender-ref ref="FILE"/>
   <appender-ref ref="SWFILE"/>
 </appender>
 
 <root>
   <priority value="${jboss.server.log.threshold}"/>
   <appender-ref ref="ASYNC"/>
 </root>

Dans cette configuration, je n'ai plus de trace dans swmsg.log :-( J'ai posté dans le forum de JBoss, si vous avez une solution vous pouvez la soumettre là-bas. J'ai aussi ouvert un bug ; à suivre...

Je n'ai utilisé que la technique la plus simple et la plus pratique à mettre en place. Ce n'est pas la seule, et le wiki de JBoss nous en propose d'autres, comme celle du Repository Selector.