如何记录Tomcat 7 JDBC连接池，连接创建

Question

尽管我们使用的是 Tomcat 7 JDBC 连接池，但我正在尝试调试似乎过多的数据库连接被打开和关闭。如何在数据源上调用 getConnection() 导致打开新连接而不是从池中借用现有连接时进行日志记录？

Answer 1

我知道有两种查看 Tomcat DB 连接池信息的方法。

1.使用JMX监控

默认情况下，Tomcat 连接池会将自身注册为 MBean (JMX Bean)。可以使用 tomcat-jdbc-pool 上的 jmxEnabled 属性打开/关闭此功能。请参阅Tomcat JDBC 连接池。

您可以使用各种外部 JMX 工具来监视数据库连接池和其他 JMX 资源。我建议从 Java 附带的 JConsole 开始。启动 JConsole，连接到 Tomcat (Catalina) JVM，选择 MBeans 标头，打开 Catalina/DataSource/... 参见下图。

阅读有关监控 Tomcat 的更多信息。

2.编写一个记录数据库连接池信息的JdbcInterceptor类

Tomcat 连接池允许您注册 JDBC 连接的拦截器。下面，我将展示如何编写一个记录连接使用情况的JdbcInterceptor类。该示例适用于 Tomcat 8，但也可能适用于 Tomcat 7。

将tomcat-jdbc.jar添加为项目的提供依赖项。

    <dependency>
        <groupId>org.apache.tomcat</groupId>
        <artifactId>tomcat-jdbc</artifactId>
        <version>8.0.8</version>
        <scope>provided</scope>
    </dependency>

创建 JdbcInterceptor 类

这个类使用公共日志记录，您可能想使用其他东西。

package com.acme.rest.config;

import java.lang.reflect.Method;

import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.apache.tomcat.jdbc.pool.ConnectionPool;
import org.apache.tomcat.jdbc.pool.JdbcInterceptor;
import org.apache.tomcat.jdbc.pool.PooledConnection;

public class MyConnectionPoolLogger extends JdbcInterceptor {

    private static final Log log = LogFactory.getLog(MyConnectionPoolLogger.class);

    @Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        if (log.isDebugEnabled()) {
            String name = method.getName();
            if (CLOSE_VAL.equals(name)) {
                log.debug(String.format("Returning Connection to Pool [%s]", proxy));
            }
        }
        return super.invoke(proxy, method, args);
    }

    @Override
    public void reset(ConnectionPool connPool, PooledConnection conn) {
        if (connPool != null && conn != null) {
            if (log.isDebugEnabled()) {
                log.debug(String.format("Getting Connection [%s], Pool active=[%s], idle=[%s]", conn.toString(),
                        connPool.getActive(), connPool.getIdle()));
            }
        }
    }

    @Override
    public void disconnected(ConnectionPool connPool, PooledConnection conn, boolean finalizing) {
        if (connPool != null && conn != null) {
            if (log.isDebugEnabled()) {
                log.debug(String.format("Closing Connection [%s], Pool active=[%s], idle=[%s]", conn.toString(),
                        connPool.getActive(), connPool.getIdle()));
            }
        }
    }
}

在Context.xml中注册这个拦截器类

<Context>
  <Resource 
    name="jdbc/acmedb"
    auth="Container"
    type="javax.sql.DataSource"
    factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"

    jdbcInterceptors="org.apache.tomcat.jdbc.pool.interceptor.ConnectionState;
      org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer; 
      com.acme.rest.config.MyConnectionPoolLogger"

  />
</Context>

JdbcInterceptor 类可以注册为Resource（如上所示）或POJO。

日志样本

以下是 Tomcat 访问连接池时的一些示例日志

2017-11-04 00:15:19,389 DEBUG Getting Connection [PooledConnection[com.mysql.jdbc.JDBC4Connection@6dea96f]], Pool active=[1], idle=[0]
2017-11-04 00:15:19,393 DEBUG Returning Connection to Pool [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@6dea96f]]]
2017-11-04 00:16:19,249 DEBUG Closing Connection [PooledConnection[com.mysql.jdbc.JDBC4Connection@6dea96f]], Pool active=[0], idle=[1]

Answer 2

我今天也遇到了类似的情况。我通过slf4j登录，我的问题是由hibernate引起的。

我所做的就是在日志配置中设置调用 JDBC 连接 getter 的空间。幸运的是，对于休眠来说，那里有调试级别的日志。

<logger name="org.hibernate.engine.jdbc">
    <level value="debug"/>
</logger>

我的猜测是，对于您的情况，您可以尝试对调用 JDBC 池 getter 的名称空间执行等效操作。它可能是这样的：

<logger name="org.apache.tomcat.jdbc.pool">
    <level value="debug"/>
</logger>

我希望这有帮助。使用 hibernate 我得到这样的结果：

DEBUG 02.07.2015 16:36:50,571 http-bio-8080-exec-33 (org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection():212) [] - Obtaining JDBC connection
DEBUG 02.07.2015 16:36:50,601 http-bio-8080-exec-6 (org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection():218) [] - Obtained JDBC connection
DEBUG 02.07.2015 16:36:50,627 http-bio-8080-exec-10 (org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection():218) [] - Obtained JDBC connection
DEBUG 02.07.2015 16:36:50,643 http-bio-8080-exec-32 (org.hibernate.engine.jdbc.spi.SqlExceptionHelper.logExceptions():139) [] - Could not open connection [n/a]
org.apache.tomcat.dbcp.dbcp.SQLNestedException: Cannot get a connection, pool error Timeout waiting for idle object
    at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:114)
    at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:1044)

...