How to Debug / Log Tomcat JDBC Connection Pool's connections?

Question

I am using Tomcat JDBC connection pool along with Spring boot, JDBC template and SQL Server. I need to know what is going inside connection pool while application is waiting for database connection. Such as....

• No of active connections
• No of idle connections
• No of blocked connections, additional info why this connection is blocked
• No of available connections
• and ...

Is there any way to get these info by debugging or using logging frameworks like log4j?

Any idea will be appreciated.

Haphazard

some of these values are registered as JMX properties. you can monitor them using wiki.apache.org/tomcat/FAQ/Monitoring Tomcat JDBC-POOL is registered as JMX bean using property jmxEnabled (default is true). you can get other values using jdbcInterceptors – Bookmaker

Thanks for the hint Nitin – Haphazard

Answer 1

After a lot of research, I am able to find 3 ways to log & monitor database connection pool.

https://tomcat.apache.org/tomcat-8.0-doc/jdbc-pool.html

1. Monitoring using Spring Boot properties.

2. Monitoring using JMX ( Java Management Extensions ) (as @nitin suggested)

3. Monitoring using Spring Aspects.

1st Way: Monitoring using Spring Boot properties.

I found below Spring boot properties which will be much useful to log & monitor database connection pool.

These properties (and some more too) were not documented. Please refer below github issue for more details. https://github.com/spring-projects/spring-boot/issues/1829

#Maximum no.of active connections
spring.datasource.max-active=10

#Log the stack trace of abandoned connection
spring.datasource.log-abandoned=true

#Remove abandoned connection,So, new connection will be created and made available to threads which are waiting for DB connection
spring.datasource.remove-abandoned=true

#If any connection is not used for 10 seconds, consider that connection as "abandoned"
spring.datasource.remove-abandoned-timeout=10 

#Number of ms to wait before throwing an exception if no connection is available.
spring.datasource.max-wait=1000

This list contains more properties which are related to datasource only.(taken from the link above)

spring.datasource.abandon-when-percentage-full
spring.datasource.access-to-underlying-connection-allowed
spring.datasource.alternate-username-allowed
spring.datasource.auto-commit
spring.datasource.catalog
spring.datasource.commit-on-return
spring.datasource.connection-customizer
spring.datasource.connection-customizer-class-name
spring.datasource.connection-init-sql
spring.datasource.connection-init-sqls
spring.datasource.connection-properties
spring.datasource.connection-test-query
spring.datasource.connection-timeout
spring.datasource.data-source
spring.datasource.data-source-class-name
spring.datasource.data-source-j-n-d-i
spring.datasource.data-source-properties
spring.datasource.db-properties
spring.datasource.default-auto-commit
spring.datasource.default-catalog
spring.datasource.default-read-only
spring.datasource.default-transaction-isolation
spring.datasource.driver-class-loader
spring.datasource.fair-queue
spring.datasource.idle-timeout
spring.datasource.ignore-exception-on-pre-load
spring.datasource.init-s-q-l
spring.datasource.initialization-fail-fast
spring.datasource.isolate-internal-queries
spring.datasource.jdbc-interceptors
spring.datasource.jdbc-url
spring.datasource.jdbc4-connection-test
spring.datasource.leak-detection-threshold
spring.datasource.log-abandoned
spring.datasource.log-validation-errors
spring.datasource.log-writer
spring.datasource.login-timeout
spring.datasource.max-age
spring.datasource.max-lifetime
spring.datasource.max-open-prepared-statements
spring.datasource.maximum-pool-size
spring.datasource.metrics-tracker-class-name
spring.datasource.minimum-idle
spring.datasource.num-tests-per-eviction-run
spring.datasource.pool-name
spring.datasource.pool-prepared-statements
spring.datasource.pool-properties
spring.datasource.propagate-interrupt-state
spring.datasource.read-only
spring.datasource.record-metrics
spring.datasource.register-mbeans
spring.datasource.remove-abandoned
spring.datasource.remove-abandoned-timeout
spring.datasource.rollback-on-return
spring.datasource.suspect-timeout
spring.datasource.test-on-connect
spring.datasource.thread-factory
spring.datasource.transaction-isolation
spring.datasource.use-disposable-connection-facade
spring.datasource.use-equals
spring.datasource.use-lock
spring.datasource.validation-interval
spring.datasource.validation-query-timeout
spring.datasource.validator
spring.datasource.validator-class-name
spring.datasource.xa
spring.datasource.xa.data-source-class-name
spring.datasource.xa.properties

2nd Way: Monitoring using JMX ( Java Management Extensions )

Tomcat JDBC pool provides a MBean namely ConnectionPoolMBean.

https://tomcat.apache.org/tomcat-7.0-doc/api/org/apache/tomcat/jdbc/pool/jmx/ConnectionPoolMBean.html

Spring Boot registers JMX MBeans automatically.So, no need to register/export this MBean into MBean server. Just open the JConsole which is coming with JDK, To open, In Windows-> Command prompt ->jconsole, thats it. Refer below screenshot for more info.

This MBean also notifies whenever a connection is abandoned, connection failed, when a query is taking long time etc. Refer screenshot below.

3rd Way: Monitoring using Spring Aspects (only for development/QA environment).

I use this aspect to log TomcatJdbc Connection Pool.

I created a Spring Aspect which will intercept every database call.This will surely affect the performance.

So, use this aspect in development/QA environment,comment out this method when it is not required (for example : during production deployment).

@Before("execution(* com.test.app.db.dao.*.*(..))")
    public void logBeforeConnection(JoinPoint jp) throws Throwable {
        String methodName = "";
        methodName += jp.getTarget().getClass().getName();
        methodName += ":";
        methodName += jp.getSignature().getName();
        logger.info("before method call : " + methodName +  " : number of connections in use by the application (active) : "+ tomcatJdbcPoolDataSource.getNumActive());
        logger.info("before method call : " + methodName +  " : the number of established but idle connections : "+ tomcatJdbcPoolDataSource.getNumIdle());
        logger.info("before method call : " + methodName +  " : number of threads waiting for a connection : "+ tomcatJdbcPoolDataSource.getWaitCount());
    }


@After("execution(* com.test.app.db.dao.*.*(..)) ")
public void logAfterConnection(JoinPoint jp) throws Throwable {
    String methodName = "";
    methodName += jp.getTarget().getClass().getName();
    methodName += ":";
    methodName += jp.getSignature().getName();
    logger.info("after method call : " + methodName +  " : number of connections in use by the application (active) : "+ tomcatJdbcPoolDataSource.getNumActive());
    logger.info("after method call : " + methodName +  " : the number of established but idle connections : "+ tomcatJdbcPoolDataSource.getNumIdle());
    logger.info("after method call : " + methodName +  " : number of threads waiting for a connection : "+ tomcatJdbcPoolDataSource.getWaitCount());
    //tomcatJdbcPoolDataSource.checkAbandoned();
}

Now, you can easily identify the particular database call which creates connection leak in your application.

Haphazard

I can't find information on the spring.datasource.log-writer property in particular. I would appreciate if anyone could find what the syntax for that is supposed to be. I'm assuming that is us telling the datasource what class it will be using to write logs. – Calyx

Note that, in order to expose the MBean, you need to add spring.datasource.jmx-enabled=true to your application.properties file. – Gile

I am using the first method to find out the current pool size but am not able to find it in the log file. I enabled spring.datasource.log-abandoned=true spring.datasource.log-validation-errors=true spring.datasource.log-writer=true spring.datasource.jmx-enabled=true but I can only see connection pool configuration detail i.e maxIdle,maxActive etc. but not "numActive" or active connection details. How/where do I find active connection details in the log file? – Hollingshead

Answer 2

Thanks @Sundararaj Govindasamy for great answer. Based on it, I created a component in my Spring Boot Application to debug my Database Pool information.

import org.apache.tomcat.jdbc.pool.DataSource;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class DataSourceAspectLogger {

    protected final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Autowired
    private DataSource ds;

    @Before("execution(* br.com.foo.core.repository.*.*(..))")
    public void logBeforeConnection(JoinPoint jp) throws Throwable {
        logDataSourceInfos("Before", jp);
    }

    @After("execution(* br.com.foo.core.repository.*.*(..)) ")
    public void logAfterConnection(JoinPoint jp) throws Throwable {
        logDataSourceInfos("After", jp);
    }

    public void logDataSourceInfos(final String time, final JoinPoint jp) {
        final String method = String.format("%s:%s", jp.getTarget().getClass().getName(), jp.getSignature().getName());
        logger.info(String.format("%s %s: number of connections in use by the application (active): %d.", time, method, ds.getNumActive()));
        logger.info(String.format("%s %s: the number of established but idle connections: %d.", time, method, ds.getNumIdle()));
        logger.info(String.format("%s %s: number of threads waiting for a connection: %d.", time, method, ds.getWaitCount()));
    }
}

Hawser

Answer 3

This is a pure JSP page MBean debugger, easy to use in every Tomcat release without external dependencies. Call dumpMBean.jsp?name=ConnectionPool to list dbpool or leave name empty to dump all MBeans.

<%@ page contentType="text/plain; charset=UTF-8" pageEncoding="ISO-8859-1"
  session="false"
  import="java.io.*, java.util.*, java.net.*,
  javax.management.*, java.lang.management.ManagementFactory
  "
%><%!

private void dumpMBean(MBeanServer server, ObjectName objName, MBeanInfo mbi, Writer writer) throws Exception {
    writer.write(String.format("MBeanClassName=%s%n", mbi.getClassName()));
    Map<String,String> props=new HashMap<String,String>();
    int idx=0;
    for(MBeanAttributeInfo mf : mbi.getAttributes()) {
        idx++;
        try {
            Object attr = server.getAttribute(objName, mf.getName());
            if (attr!=null)
                props.put(mf.getName(), attr.toString());
        } catch(Exception ex) {
            // sun.management.RuntimeImpl: java.lang.UnsupportedOperationException(Boot class path mechanism is not supported)
            props.put("error_"+idx, ex.getClass().getName()+" "+ex.getMessage());
        }
    }
    // sort by hashmap keys
    for(String sKey : new TreeSet<String>(props.keySet()))
        writer.write(String.format("%s=%s%n", sKey, props.get(sKey)));
}

%><%
// Dump MBean management properties, all beans or named beans
// dumpMBean.jsp?name=ConnectionPool,ContainerMBean
// dumpMBean.jsp?name=

if (request.getCharacterEncoding()==null)
    request.setCharacterEncoding("UTF-8");

String val = request.getParameter("name");
String[] names = val!=null ? val.trim().split(",") : new String[0];
if (names.length==1 && names[0].isEmpty()) names=new String[0];

MBeanServer server = ManagementFactory.getPlatformMBeanServer();
for(ObjectName objName : server.queryNames(null,null)) {
    MBeanInfo mbi = server.getMBeanInfo(objName);
    boolean match = names.length<1;
    String name = mbi.getClassName();
    for(int idx=0; idx<names.length; idx++) {
        if (name.endsWith(names[idx])) {
            match=true;
            break;
        }
    }
    if (match) {
        dumpMBean(server, objName, mbi, out);
        out.println("");
    }
}
out.flush();

%>

Concessionaire