How to fix connection pool leak in Grails?

Question

This is with Grails 2.4.4. I'm encountering a connection pool leak that seems to have to do with Grails transaction management. Anybody have an idea of where the the problem lies?

Suspect leak detection message from Tomcat JDBC Pool:

015-06-11 13:44:03,483 [PoolCleaner[2120388162:1434055276957]] [||] WARN  pool.ConnectionPool  - Connection has been marked suspect, possibly abandoned PooledConnection[org.postgresql.jdbc4.Jdbc4Connection@4fcf9353][89657 ms.]:java.lang.Exception
at org.apache.tomcat.jdbc.pool.ConnectionPool.getThreadDump(ConnectionPool.java:1063)
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:780)
at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:619)
at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:188)
at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:128)
at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.getTargetConnection(LazyConnectionDataSourceProxy.java:403)
at org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy$LazyConnectionInvocationHandler.invoke(LazyConnectionDataSourceProxy.java:376)
at com.sun.proxy.$Proxy77.prepareStatement(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.jdbc.datasource.TransactionAwareDataSourceProxy$TransactionAwareInvocationHandler.invoke(TransactionAwareDataSourceProxy.java:240)
at com.sun.proxy.$Proxy77.prepareStatement(Unknown Source)
at groovy.sql.Sql$CreatePreparedStatementCommand.execute(Sql.java:4512)
at groovy.sql.Sql$CreatePreparedStatementCommand.execute(Sql.java:4491)
at groovy.sql.Sql.getAbstractStatement(Sql.java:4342)
at groovy.sql.Sql.getPreparedStatement(Sql.java:4357)
at groovy.sql.Sql.getPreparedStatement(Sql.java:4434)
at groovy.sql.Sql.access$900(Sql.java:228)
at groovy.sql.Sql$PreparedQueryCommand.runQuery(Sql.java:4622)
at groovy.sql.Sql$AbstractQueryCommand.execute(Sql.java:4553)
at groovy.sql.Sql.rows(Sql.java:1954)
at groovy.sql.Sql.firstRow(Sql.java:2192)
at groovy.sql.Sql$firstRow.call(Unknown Source)
at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:45)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:108)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:120)
...

In resources.groovy:

import groovy.sql.Sql
beans = {
    sql(Sql, ref("dataSource"));
}

In DataSource.groovy:

dataSource {
url = "jdbc:postgresql:testdb"
username = "USERNAME"
password = "PASSWORD"
driverClassName = "org.postgresql.Driver"
dialect = "org.hibernate.dialect.PostgreSQL9Dialect"
pooled = true
jmxEnabled = true
readOnly = false
autoCommit = false
properties {
    initialSize = 1
    maxActive = 15
    minIdle = 1
    maxIdle = 2
    maxWait = 20000 // 20 seconds
    maxAge = 20 * 60000 // 20 minutes
    timeBetweenEvictionRunsMillis = 15000
    minEvictableIdleTimeMillis = 10000
    validationQueryTimeout = 10 // 10 seconds
    validationInterval = 15000 // 15 seconds
    testOnBorrow = true
    testWhileIdle = true
    testOnReturn = false
    logValidationErrors = true
    removeAbandonedTimeout = 60 * 1440 // 24 hours, use suspectTimeout instead
    removeAbandoned = true // needed for suspectTimeout
    suspectTimeout = 60
    logAbandoned = true // needed for suspectTimeout logging
    validationQuery = "SELECT 1"
}
}

TestController.groovy:

class TestController {
  def testService

  def test() {
    Integer id = testService.test()
    render "Testing: $id\n"
  }
}  

TestService.groovy:

import grails.transaction.Transactional

@Transactional
class TestService {
    def sql

    @Transactional
    Integer test() {
        def row = sql.firstRow("select id from TestTable where name = 'Test'")
        return row.id
    }
}

The leak detection message doesn't show if the query is moved from the transactional service to the controller, and I assume this is because the controller isn't transactional.

It also doesn't report a leak message if I change in resources.groovy to using the Unproxied version of the dataSource:

import groovy.sql.Sql
beans = {
    sql(Sql, ref("dataSourceUnproxied"));
}

Digging down into the actual groovy.sql.Sql code, it looks to me that the problem is related to the fact that firstRow() opens and closes its own connection from the pool using a try {} finally{} block. But the connection that it gets is proxied via a Spring TransactionAwareConnectionFactoryProxy.

In the proxy source code, I see:

else if (method.getName().equals("close")) {
    // Handle close method: only close if not within a transaction.                             
    ConnectionFactoryUtils.doReleaseConnection(this.target, this.connectionFactory);
    return null;
}

Ok, so the underlying connection doesn't get released back to the pool if within a transaction? This isn't making much sense to me because it will always be within a transaction in a @Transactional service method, so the connection will never get closed unless there's code somewhere else in Grails or Spring that will close() a connection after a commit()?

Answer 1

Figured it out.

I had a JmsTransactionManager configured in resources.groovy.

It turns out I needed to also explicitly add the JDBC transaction manager. I had to add the following to resources.groovy:

transactionManager(org.springframework.jdbc.datasource.DataSourceTransactionManager, ref("dataSource"))

This gives me a ChainedTransactionManager with Grails that contains the JmsTransactionManager and the DataSourceTransactionManager.

I'm not using Hibernate. If using Hibernate/GORM, instead of DataSourceTransactionManager, you'll want org.codehaus.groovy.grails.orm.hibernate.GrailsHibernateTransactionManager.