Tomcat JDBC Pool - Connection Leak - Catch the Culprit

Database connection leaks are something that can stay hidden unless paid specific attention and would come to the surface at the most critical stages at a peak time of the system. We would manually check if all the open connections have been closed properly. Then we have various code quality plugins that would scan and check for that. Still when the connections are passed through a complex structure of program both of these can miss a possible connection leak. Then at unit test or integration test levels, we can have checks to validate the counts in the connection pool to avoid this unfortunate situation, that would keep engineers busy at year-end, black Friday, etc. :)

In the unfortunate case of hitting with a performance degrade or a total crash of the system which can be propagated via a JDBC connection leak, when we suspect a connection leak, how easily and quickly isolate the culprit. In the Tomcat connection pool, we can do this using 3 properties.

removeAbandoned

If a DB connection has been abandoned(not been used for a while, but haven't returned to the pool), this configuration will try to remove it. How long to wait before it removes the connection is configured by the below configuration.

removeAbandonedTimeout

The time it will spare before attempting to remove the connection. By default 60s.

Note: When we are using this property with a target to isolate a culprit, it is useful to know the average time taken by the longest transaction the system would execute on the database. Setting this value considerably larger than that would avoid us from catching the innocent threads that might be actually doing useful work would get properly closed at the end.

logAbandoned 

'Should it log the stack trace when removing an abandoned connection' is governed by this. 

More details on these properties can be found at https://tomcat.apache.org/tomcat-8.0-doc/jdbc-pool.html#Common_Attributes

These configurations can also be used as a safety net in case you are doubtful if the application has any leak. Because it will automatically remove the connections that have been forgotten to be closed and the pool will handle to keep the intended min, max and idle connection count properly considering those.

This is a sample log I got captured while the pool removes an abandoned connection.

 [2020-04-24 00:26:13,229] WARN {org.apache.tomcat.jdbc.pool.ConnectionPool} - Connection has been abandoned PooledConnection[com.mysql.jdbc.JDBC4Connection@5ab91385]:java.lang.Exception  
   at org.apache.tomcat.jdbc.pool.ConnectionPool.getThreadDump(ConnectionPool.java:1096)  
   at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:799)  
   at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:648)  
   at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:200)  
   at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)  
   at org.lanka.carbon.user.core.jdbc.JDBCUserStoreManager.getDBConnection(JDBCUserStoreManager.java:1187)  
   at org.lanka.sample.CustomUserStoreManager.doAuthenticate(CustomUserStoreManager.java:51)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager.authenticateInternal(AbstractUserStoreManager.java:674)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager.access$100(AbstractUserStoreManager.java:86)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager$4.run(AbstractUserStoreManager.java:542)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager$4.run(AbstractUserStoreManager.java:539)  
   at java.security.AccessController.doPrivileged(Native Method)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager.authenticate(AbstractUserStoreManager.java:539)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager.authenticateInternal(AbstractUserStoreManager.java:702)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager.access$100(AbstractUserStoreManager.java:86)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager$4.run(AbstractUserStoreManager.java:542)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager$4.run(AbstractUserStoreManager.java:539)  
   at java.security.AccessController.doPrivileged(Native Method)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager.authenticate(AbstractUserStoreManager.java:539)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager$3.run(AbstractUserStoreManager.java:522)  
   at org.lanka.carbon.user.core.common.AbstractUserStoreManager$3.run(AbstractUserStoreManager.java:514)  
   at java.security.AccessController.doPrivileged(Native Method)  

As you can the whole stack trace relevant to the abandoned connection creation is captured here, which will lead us to the culprit faster.

Optionally, we also have the option of using JConsole to monitor the JDBC pool via JMX. For that, we need to enable the property 'jmxEnabled' which will allow connecting from Jconsole to the JDBC pool. Once done it has a whole lot of features to monitor the pool and can even set to notify when a connection is detected to be abandoned.

Hope this will help you save some time in troubleshooting.
Cheers!

Popular posts from this blog

Signing SOAP Messages - Generation of Enveloped XML Signatures

How to convert WSDL to Java

How to Write a Custom User Store Manager - WSO2 Identity Server 4.5.0