J'ai écrit une simple application console qui utilise JPA pour se connecter à une base de données MySQL. La lecture et l'écriture des données fonctionnent, mais la journalisation semble ne pas fonctionner. Chaque instance d'EntityManager que je crée semble ajouter son propre appender log4j à la console. Ainsi, puisque j'ai trois instances EntityManager dans mon application, j'obtiens trois lignes supplémentaires dans ma sortie de console en plus de la "vraie" ligne de sortie de console que je veux. Voici un exemple. La première ligne provient de mon "vrai" appender, les trois autres semblent provenir de l'appender de l'EntityManager :
08:31:58,970 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:169 - geoEntityDao.getByCompositeKey took 81 milliseconds
0 [main] DEBUG foobar - geoEntityDao.getByCompositeKey took 81 milliseconds
0 [main] DEBUG foobar - geoEntityDao.getByCompositeKey took 81 milliseconds
0 [main] DEBUG foobar - geoEntityDao.getByCompositeKey took 81 milliseconds Voici ma configuration de log4j :
log4j.rootCategory=WARN, mylog
log4j.appender.mylog=org.apache.log4j.ConsoleAppender
log4j.appender.mylog.layout=org.apache.log4j.PatternLayout
log4j.appender.mylog.layout.ConversionPattern=%d{ABSOLUTE} %C %5p %t %c{2}:%L - %m%n
log4j.category.foobar=DEBUGJ'aimerais pouvoir désactiver ce comportement et n'obtenir que les lignes de la console que je souhaite. Je ne semble pas être en mesure de "déchiffrer le code" sur la façon de le faire - toute aide serait appréciée...
Informations complémentaires : Il semble qu'il y ait deux choses qui se passent ici. La première est le paramètre d'additivité de l'appender de log4j, qui est vrai par défaut. En relisant la documentation éparse de log4j (http://logging.apache.org/log4j/1.2/manual.html), je suis tombé sur ceci :
Chaque demande de journalisation activée pour un logger donné sera transmise à tous les appenders de ce logger ainsi qu'aux appenders situés plus haut dans la hiérarchie.
Ce qui n'est PAS mentionné, c'est qu'il le fait apparemment indépendamment des paramètres des enregistreurs situés plus haut dans la hiérarchie.
Ce que cela signifie, ou semble signifier dans mon cas, c'est que bien que mon logger Root soit réglé sur WARN, les appenders qui lui sont attachés par les classes Hibernate sont toujours utilisés par les messages de niveau DEBUG. C'est le contraire de ce que je m'attendais à voir se produire. Je ne sais pas si cela représente un bug dans l'implémentation JPA d'Hibernate 4.0.1 ou simplement un manque de documentation de la part de log4j, ou un problème entre log4j et slf4j (utilisé par Hibernate).
La deuxième chose qui se passe est que chaque fois que vous créez un objet EntityManager, il semble ajouter un appender à votre arbre de logging log4j, donc si vous avez plusieurs EntityManagers, vous obtenez plusieurs messages de logging. Je suis presque sûr qu'il s'agit d'un bogue dans la journalisation d'Hibernate.
Je suis toujours à la recherche d'une explication ou d'un exemple de la façon dont cette "additivité" fonctionne en pratique avec log4j - elle semble fonctionner à l'inverse de ce à quoi je m'attendais d'après la documentation limitée. C'est-à-dire que les appenders semblent être transmis vers le bas de l'arbre de journalisation au lieu que les événements de journalisation soient transmis vers le haut.
Voici ce que j'ai jusqu'à présent pour mon fichier de propriétés log4j (révisé), et cela semble fonctionner :
log4j.rootCategory=WARN, mylog
# logger "root" logs at WARN level to appender "mylog"
log4j.appender.mylog=org.apache.log4j.ConsoleAppender
log4j.appender.mylog.layout=org.apache.log4j.PatternLayout
# Logger "foobar" logs at DEBUG level to appender "bootylog"
log4j.category.foobar=DEBUG, bootylog
log4j.appender.bootylog=org.apache.log4j.ConsoleAppender
log4j.appender.bootylog.layout=org.apache.log4j.PatternLayout
log4j.appender.bootylog.layout.ConversionPattern=%d{ABSOLUTE} %C %5p %t %c{2}:%L - %m%n
# additivity is off
log4j.additivity.foobar=false
log4j.additivity.org.hibernate=falseCela me donne le résultat suivant, qui est exactement ce que je veux :
11:15:43,622 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:152 - geoDataItemDao.create took 5 milliseconds
11:15:43,624 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:166 - geoEntityDao.getByCompositeKey took 2 milliseconds
11:15:43,626 com.electricgearbox.app.ProcessDataItemApp DEBUG main foobar:159 - dataEntityDao.getDataEntityByFieldCode took 1 milliseconds Enfin, je recommande vivement à tous ceux qui ont des problèmes avec log4j d'activer cette option de ligne de commande lorsqu'ils lancent leur application :
-Dlog4j.debug
