abdel
abdel

Reputation: 735

spring or hibernate connection leak

I am using spring with hibernate on a webapp (hibernate-core-4.3.8.Final and spring 3.2.11.RELEASE). I am using hikaricp (v 2.2.5) as the connection pool impl which detects a connection leak and prints the stacktrace below. I am using spring's declarative transaction demarcation so I assume the management and clean up of resources is done by spring/hibernate. Therefore, I think either spring or hibernate is the cause of the detected connection leak.

basically, there is timer which when fired, calls a spring bean marked with @Transactional annotation.

 @Transactional public class InvoiceCycleExporter {
public runExportInvoiceCycleJob(){
  //this method when called is **sometimes** leaking a connection ....
} }

can you please help me to trace the source of connection leak.

my appcontext.xml config for datasource, connection pool, entitymanager are below

 <bean id="hikariConfig" class="com.zaxxer.hikari.HikariConfig">
    <property name="jdbcUrl" value="${jdbc.url}"/>
    <property name="username" value="${jdbc.user}"/>
    <property name="password" value="${jdbc.password}"/>
    <property name="maximumPoolSize" value="${jdbc.maximumPoolSize}"/>
    <property name="driverClassName" value="org.postgresql.Driver"/>
    <property name="leakDetectionThreshold" value="${jdbc.leakDetectionThreshold}"/>
</bean>

<bean id="dataSource" class="com.zaxxer.hikari.HikariDataSource" destroy-method="shutdown">
    <constructor-arg ref="hikariConfig"/>
</bean>

<bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">        
    <property name="dataSource" ref="dataSource"/>
    <property name="persistenceUnitName" value="velosPU"/>
    <property name="persistenceXmlLocation" value="classpath:META-INF/persistence.xml"/>       //more stuff ....   
 </bean>

stacktrace below:

2015-01-13 14:25:00.123 [Hikari Housekeeping Timer (pool HikariPool-0)] WARN  com.zaxxer.hikari.util.LeakTask - Connection leak detection triggered, stack trace follows
java.lang.Exception: null
        at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:139) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1435) ~[hibernate-core-4.3.8.Final.jar:4.3.8.Final]
        at org.hibernate.jpa.internal.TransactionImpl.begin(TransactionImpl.java:61) ~[hibernate-entitymanager-4.3.8.Final.jar:4.3.8.Final]
        at org.springframework.orm.jpa.DefaultJpaDialect.beginTransaction(DefaultJpaDialect.java:70) ~[spring-orm-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:61) ~[spring-orm-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:378) ~[spring-orm-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:372) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:417) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:255) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94) ~[spring-tx-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:633) ~[spring-aop-3.2.11.RELEASE.jar:3.2.11.RELEASE]
        at com.ukfuels.velos.services.bl.internalinterface.impl.bl.invoicing.**InvoiceCycleExporter (this is the spring bean marked with the transactional annotation)**$$EnhancerBySpringCGLIB$$519c078f.runExportInvoiceCycleJob(<generated>) ~[spring-core-3.2.11.RELEASE.jar:na]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
        at org.apache.camel.component.bean.BeanProcessor.process(BeanProcessor.java:67) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.impl.ProcessorEndpoint.onExchange(ProcessorEndpoint.java:103) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.impl.ProcessorEndpoint$1.process(ProcessorEndpoint.java:71) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorConverterHelper$ProcessorToAsyncProcessorBridge.process(AsyncProcessorConverterHelper.java:61) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.SendProcessor$2.doInAsyncProducer(SendProcessor.java:122) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.impl.ProducerCache.doInAsyncProducer(ProducerCache.java:298) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:117) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:72) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.interceptor.BacklogTracerInterceptor.process(BacklogTracerInterceptor.java:84) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:91) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:391) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:273) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.RouteContextProcessor.processNext(RouteContextProcessor.java:46) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.interceptor.DefaultChannel.process(DefaultChannel.java:335) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.RouteContextProcessor.processNext(RouteContextProcessor.java:46) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.UnitOfWorkProcessor.processAsync(UnitOfWorkProcessor.java:150) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.UnitOfWorkProcessor.process(UnitOfWorkProcessor.java:117) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.RouteInflightRepositoryProcessor.processNext(RouteInflightRepositoryProcessor.java:48) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:72) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.loadbalancer.QueueLoadBalancer.process(QueueLoadBalancer.java:44) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:99) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.processor.loadbalancer.QueueLoadBalancer.process(QueueLoadBalancer.java:71) ~[camel-core-2.11.4.jar:2.11.4]
        at org.apache.camel.component.quartz.QuartzEndpoint.onJobExecute(QuartzEndpoint.java:113) ~[camel-quartz-2.11.4.jar:2.11.4]
        at org.apache.camel.component.quartz.CamelJob.execute(CamelJob.java:61) ~[camel-quartz-2.11.4.jar:2.11.4]
        at org.quartz.core.JobRunShell.run(JobRunShell.java:223) ~[quartz-1.8.6.jar:na]
        at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549) ~[quartz-1.8.6.jar:na] **(a timer is triggered)**

Upvotes: 16

Views: 27916

Answers (2)

abdel
abdel

Reputation: 735

here is some information that i think could be useful for debugging connection leaks in general

  • Rule out false alarms. For example, if you have a transaction that could potentially run for 5 minutes (e.g., while producing a large report) and you had set your 'leakDetectionThreshold' parameter (or whatever the equivalent for your chosen pool implementation) to 4 minutes, then any transaction taking longer than 4 minutes will be reported as a leak even though it may not be a genuine leak (transaction could complete gracefully and adequately release all connections after 5 minutes).
  • If you are using a connection pool but find yourself running out of connections occasionally then think of how you configure your pool. In my case, I had configured the pool with 'maximumPoolSize'=100. Hikari will auto-default 'minimumIdle' config (minimum number of idle connections that HikariCP tries to maintain in the pool) to the same as that of 'maximumPoolSize' so on start-up the pool will be initialized with all max 100 connections. But this will mean that when the 'maxLifetime' (the maximum lifetime of a connection in the pool) fires, then all connections will have to be renewed at the same time. This results in a steep temporary reduction of available connections. In my logs I was occasionally seeing following lines.

    HikariPool-0 (total=100, inUse=0, avail=100, waiting=0)
    HikariPool-0 (total=4, inUse=0, avail=4, waiting=0)
    HikariPool-0 (total=100, inUse=0, avail=100, waiting=0)

    the second line where available connections dropped to only 4, is when the 'maxLifetime' was reached and the connections needed renewal. So when configuring your pool, do it in a way so that the connections expire at different times. In my case, I simply changed 'minimumIdle' to 40, which means as load increases on server, new connections will be incrementally acquired (watch if your pool impl offers the equivalent of minToAcquire property) and hence those connections will have different expiry dates.

  • Your connection 'maxLifetime' need to be less than what your database assigns/expects for connections so that you don't end up with connections in the pool that are invalid. UPDATE: some databases may force drop the connection after a period of time. For example, postgres has a 'connectionTimeout' and 'socketTimeout' options. So in your application's connection pool, you don't want to keep connections for longer than this db-enforced-connection-timeout because otherwise you will be keeping an invalid/already-dropped connection.

Upvotes: 21

Cristian Sevescu
Cristian Sevescu

Reputation: 1489

The issue is discussed here at large:

https://github.com/brettwooldridge/HikariCP/issues/34

To narrow the problem:

  1. Try Spring 4 with Hibernate 4
  2. Try another data-source to see if problem persists.

Upvotes: 3

Related Questions