Tomcat connection pool ThrowableCallStack issue

Question

Found following logs sometimes in Tomcat8.5. When we observe error stacktrace we didn't found any connection leak in the code but the log is captured for sometimes. I am unable to recognize whether this is the indication to connection leak or any other issue.

Pooled object created 2018-11-13 11:00:01 -0800 by the following code
has not been returned to the pool:
org.apache.tomcat.dbcp.pool2.impl.ThrowableCallStack$Snapshot   at
org.apache.tomcat.dbcp.pool2.impl.ThrowableCallStack.fillInStackTrace(ThrowableCallStack.java:71)
        at org.apache.tomcat.dbcp.pool2.impl.DefaultPooledObject.allocate(DefaultPooledObject.java:192)
        at org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:455)
        at org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:361)
        at org.apache.tomcat.dbcp.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
        at org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1543)
        at com.sample.test.db.SlaveDBConnection.initiateConnection(SlaveDBConnection.java:40)
        at com.sample.test.db.SlaveDBConnection.<init>(SlaveDBConnection.java:25)
        at com.sample.test.db.DBFactory.getDBObject(DBFactory.java:80)
        at com.sample.test.app.model.dao.UserDAOImpl.getUserData(UserDAOImpl.java:1795)
        at org.apache.jsp.getData_jsp._jspService(getData_jsp.java:298)
        at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
        at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:443)
        at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:386)
        at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:330)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
        at org.apache.tomcat.websocket.server.MFilter.doFilter(MFilter.java:52)

Here what is ment by org.apache.tomcat.dbcp.pool2.impl.ThrowableCallStack$Snapshot and when do we get this issue. And how can we reproduce this issue?

Answer 1

The web application you are running has logAbandoned flag activated for the resource pool. Whenever the app acquires a new JDBC connection, the Pool will take the (overhead) time and record the call stack trace in memory. Whenever it later on recognices that a JDBC conection had not been closed properly, it will take that stack trace snapshot and dump it into the log, pointing to the exact location (Java source file and line if compiled for debug) where the connection was acquired which had not been closed safely, taking the risk of connection leaks.

The reproducability strongly depends on what and when the application is actually doing. It might be hard to reproduce if there are several side conditions for this to occoure, but you can read the actual location from where it happens in the stack trace and possibly analyze the source code, find the guilty lines of code and maybe even blame the developer ;-)

See the Tomcat documentation for further reading here.

Answer 2

If you set "logAbandoned" to "false", you will not receive these messages again. Even if you receive these messages, it does not seem to have a negative impact on your database Connection pool.