Hibernate JPA EntityManager 创建额外的 log4j appender？答案

【问题标题】：Hibernate JPA EntityManager creates extra log4j appender?Hibernate JPA EntityManager 创建额外的 log4j appender？
【发布时间】：2012-05-06 15:45:24
【问题描述】：

我编写了一个简单的控制台应用程序，它使用 JPA 连接到 MySQL 数据库。数据的实际读/写工作正常，但日志记录似乎搞砸了。我创建的每个 EntityManager 实例似乎都将自己的 log4j appender 添加到控制台。因此，由于我的应用程序中有三个 EntityManager 实例，因此除了我想要的“真实”控制台输出行之外，我的控制台输出中还有三个额外的行。这是一个例子。第一行来自我的“真实”附加程序，其他三个似乎来自 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

这是我的 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=DEBUG

我希望能够关闭此行为并获得我想要的控制台行。我似乎无法“破解代码”如何做到这一点 - 任何帮助将不胜感激......

附加信息：这里似乎发生了两件事。第一个是 log4j appender additivity 设置，默认为 true。重新阅读稀疏的 log4j 文档（http://logging.apache.org/log4j/1.2/manual.html）我遇到了这个：

给定记录器的每个启用的记录请求都将转发到该记录器中的所有附加程序以及层次结构中更高的附加程序。

没有提到的是，无论层次结构中较高级别的记录器的设置如何，它显然都会这样做。

这意味着，或者在我的情况下似乎意味着，尽管我的根记录器设置为 WARN，但 Hibernate 类附加到它的附加程序仍然被 DEBUG 级消息使用。这与我所期望的相反。我不确定这是否代表 Hibernate 4.0.1 JPA 实现中的错误，或者只是缺少 log4j 的文档，或者 log4j 和 slf4j 之间的故障（由 Hibernate 使用）。

发生的第二件事是，每次创建 EntityManager 对象时，似乎都会向 log4j 日志树添加一个附加程序，因此如果您有多个 EntityManager，您会收到多条日志消息。我很确定这是 Hibernate 日志记录中的一个错误。

仍在寻找关于这种“可加性”如何在 log4j 实践中工作的解释或示例 - 它似乎与我对有限文档的期望相反。也就是说，appender 似乎被向下传递到日志树而不是日志事件被向上传递。

这是我目前的（修改后的）log4j 属性文件，它似乎正在工作：

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=false

这给了我以下输出，这正是我想要的：

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

最后，我强烈建议任何遇到 log4j 问题的人在运行应用程序时打开此命令行选项：

-Dlog4j.debug

【问题讨论】：

标签： hibernate logging log4j entitymanager

【解决方案1】：

作为answered elsewhere，尝试在您的 log4j 属性中更改 hibernate 的日志记录级别

例如

log4j.logger.org.hibernate=info

【讨论】：

这不是另一个问题的重复。我知道如何在 log4j 中设置日志记录级别。我在问为什么我在输出中得到重复的行。在最终发布这个问题之前，我尝试在谷歌上搜索“log4j”、“duplicate”和“EntityManager”的各种组合几个小时。
上述方法对您不起作用吗？我不认为你可以完全关闭它，因为据我所知，Hibernate 的 log4j 属性在你的类路径中
我将其缩小到 log4j.additivity 设置的问题，这似乎与文档让我相信的不同。我在上面编辑的消息中包含了完整的详细信息。
感谢您发布解决方案的更新！为清楚起见，我会考虑将其从问题正文中移出并将其添加为答案（并接受它）

【解决方案2】：

这里似乎发生了两件事。第一个是 log4j appender additivity 设置，默认为 true。重新阅读稀疏的 log4j 文档（http://logging.apache.org/log4j/1.2/manual.html）我遇到了这个：