小结

log4j可以通过配置文件控制日志的输出，C3P0是控制数据库连接池的包，现有的项目是旧版本的log4j通过配置文件log4j.properties控制C3P0的日志输出，完全没有问题。当log4j升级到log4j2，并使用log4j2.xml配置却出现了兼容问题，查找具体原因并进行了解决。

问题

新版本的log4j2的版本如下：
log4j-api-2.17.1.jar
log4j-core-2.17.1.jar
具体log4j2.xml的logger部分配置如下：

  <Loggers>
       <Root level="error" additivity="false">
         <AppenderRef ref="Console"/>
       </Root>
     <Logger name="com.mchange" level="off" additivity="false"> 
       <AppenderRef ref="Console" level="off"/>
       <AppenderRef ref="fileAppender" level="off"/>
     </Logger>           
  </Loggers>

理论上以上设置会将C3P0的日志全部关闭，然后这个配置却没有生效，具体现象是在Console中依然输出并打印了类似以下错误日志：

        ...
java.lang.Exception: DEBUG STACK TRACE: Overdue resource check-out stack trace.
        at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:555)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutAndMarkConnectionInUse(C3P0PooledConnectionPool.java:755)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:682)
        at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:140)
        at org.hibernate.c3p0.internal.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:73)
        at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:386)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:87)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:112)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:230)
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:237)
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:214)
        at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:52)
        at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1512)
        ...

我的旧版本的log4j的版本是log4j-1.2.16.jar
log4j.properties中C3P0部分配置如下：

log4j.logger.com.mchange=OFF

以上旧版本配置是完全没有问题的，并没有任何C3P0的日志被漏出来输出到屏幕上。

查找原因

在程序启动初始，有以下输出：

 com.mchange.v2.log.MLog.<clinit> MLog clients using java 1.4+ standard logging.

以上输出证明了log4j2的设置并没有生效，默认使用了java 1.4的日志。

解决

从最开始的的分析开始，往往是看到现象：java.lang.Exception: DEBUG STACK TRACE: Overdue resource check-out stack trace，对于这个问题在网上众说纷纭，有些解决方案只解决了这个表面现象出现的异常，结果只是治标，没有治本。我们需要找到问题的根本，也就是最终定位到Log4j2与C3P0的兼容问题。这样才可以完完美，并以最小的代价来解决。

方案一

针对java.lang.Exception: DEBUG STACK TRACE: Overdue resource check-out stack trace的异常。网上已有定论：

This is the code that triggers this log statement in C3P0:

if ( logger.isLoggable( MLevel.FINEST ) ) logger.log( MLevel.FINEST,
this + ” closed by a client.”,
new Exception(“DEBUG – CLOSE BY CLIENT STACK
TRACE”) );

Note that:

This is not an exception, the new Exception is used merely to show
execution path for debug purposes. And yes, this is only a debug
message (actually, FINEST is the lowest possible level in
java.util.logging). To wrap this up: ignore and tune your logging
levels to skip these.

也就是这本来就不是一个异常，只是一个调试的提示信息，通过设置日志级别可以屏幕这个异常打印输出信息。通过hibernate的以下配置可以达到这个目的，一个是直接关闭，一个是增加超时时长。

<property name="hibernate.c3p0.debugUnreturnedConnectionStackTraces">false</property>
<property name="hibernate.c3p0.unreturnedConnectionTimeout">100</property>

这个解决方案只是不输出java.lang.Exception: DEBUG STACK TRACE: Overdue resource check-out stack trace这个异常，log4j2的设置依然无法控制C3P0的日志输出。

方案二

参考CSDN: 干掉com.mchange.v2.log.MLog 的日志
直接粗暴地修改干掉C3P0的日志输出，也就是使用java的日志级别修改C3P0的日志级别设置。

ModifyLogLevel.java

package com.mchange.v2.log;

import java.util.logging.Level;

public class ModifyLogLevel {

    public static void modifyInfoLevel(Level level) {
        com.mchange.v2.log.MLevel.INFO.level=level;
    }
}

直接在程序中调用：

ModifyLogLevel.modifyInfoLevel(java.util.logging.Level.ALL);

这个解决方案可以达到关闭所有C3P0的日志输出，但是这样就没有log4j2的任何事了，不能进行灵活配置，焊死了，如果我想要打开C3P0的日志输出呢？那岂不是很麻烦。

或者

System.setProperty ("com.mchange.v2.log.MLog", "log4j2");

再配上log4j2.xml的设置：

  <Loggers>
       <Root level="error" additivity="false">
         <AppenderRef ref="Console"/>
       </Root>
     <Logger name="com.mchange" level="off" additivity="false"> 
       <AppenderRef ref="Console" level="off"/>
       <AppenderRef ref="fileAppender" level="off"/>
     </Logger>           
  </Loggers>

修改后，期望着能一举成功，然而进行了以上设置并没有什么卵用，日志仍然使用Java自带的java 1.4+ standard logging，究其原因，原来我使用了以下版本的C3P0:
c3p0-0.9.2.1.jar
mchange-commons-java-0.2.3.4.jar

此版本并不支持此操作，下载升级到：
c3p0-0.9.5.5.jar
mchange-commons-java-0.2.19.jar

问题最终解决了。这样，通过log4j2.xml的设置，可以精确控制C3P0的日志输出级别和输出位置。

参考

CSDN: java.lang.Exception: DEBUG — CLOSE BY CLIENT STACK TRACE 的理解
 Problem with hibernate search indexing
CSDN: c3p0连接池连接泄漏检测
 CSDN: java.lang.Exception: DEBUG STACK TRACE for PoolBackedDataSource.close().
CSDN: 跟踪 C3p0 连接池连接泄漏之参数优化与日志分析
 CSDN: C3P0异常：java.lang.Exception: DEBUG — CLOSE BY CLIENT STACK TRACE 解决
 CSDN: 干掉com.mchange.v2.log.MLog 的日志
 CSDN: Hibernate c3p0 logging不通过slf4j输出的解决办法
 stackoverflow: Weird Error: CLOSE BY CLIENT STACK TRACE

Published

April 21, 2023

scruffybear in Java | April 21, 2023

Log4j2与C3P0的兼容问题及解决

小结

问题

查找原因

解决

方案一

方案二

方案三(推荐)

参考

Related

Published

April 21, 2023

Cancel Reply

Write a Comment