search

grails / grails-data-mapping

GORM - Groovy Object Mapping
http://gorm.grails.org/
218 stars 198 forks source link

executeWithNewSession can result in "Active Connection is required" error on cleanup #1143

Open longwa opened 6 years ago

longwa commented 6 years ago

GORM 6.1.11.BUILD-SNAPSHOT Grails 3.3.6

We have some scenarios where using withNewSession can cause an Active Connection is required error after the block executes.

There are paths where the ConnectionSynchronization.suspend method is called and nulls out the connectionHandle on the ConnectionHolder instance that is bound.

When the GrailsHibernateTemplate.executeWithNewSession methods cleans up in the finally block, it tries to do the following:

// if there is a connection holder and it holds an open connection close it
try {
    if(connectionHolder != null && !connectionHolder.getConnection().isClosed()) {
        Connection conn = connectionHolder.getConnection();
        DataSourceUtils.releaseConnection(conn, dataSource);
     }
} catch (SQLException e) {
    // ignore, connection closed already?
    if(LOG.isDebugEnabled()) {
        LOG.debug("Could not close opened JDBC connection. Did the application close the connection manually?: " + e.getMessage());
    }
}

However, in this case there IS a connectionHolder but it doesn't have a connection set on it. Ideally, this line should be:

if(connectionHolder != null && connectionHolder.hasConnection() && !connectionHolder.getConnection().isClosed()) {

But hasConnection() is protected so that's not really an option. It looks like the code is already trying to cleanup and willing to ignore errors, so one solution would be to just catch IllegalArgumentException as well as SQLException and do the same thing.

The real solution is probably to figure out the path that causes the holder to be present but still have a null connection. It definitely revolves around the suspend logic for transactions.

I'm trying to get all the parts of a sample application together to reproduce, but I'm having trouble reproducing it in a sample application. Our particular scenario has a lot of moving parts as it's using Spring Batch, which is using some Spring AOP Transaction stuff behind the scenes along with a TaskDecorator and a few other layers.

Full Stack:

java.lang.IllegalArgumentException: Active Connection is required
    at org.springframework.util.Assert.notNull(Assert.java:134)
    at org.springframework.jdbc.datasource.ConnectionHolder.getConnection(ConnectionHolder.java:150)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.executeWithNewSession(GrailsHibernateTemplate.java:173)
    at org.grails.orm.hibernate.AbstractHibernateDatastore.withNewSession(AbstractHibernateDatastore.java:356)
    at org.grails.orm.hibernate.AbstractHibernateGormStaticApi.withNewSession(AbstractHibernateGormStaticApi.groovy:60)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewSession(GormEntity.groovy:1025)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession$21.call(Unknown Source)
    at com.triu.system.process.TaskStatus.withNewSession(TaskStatus.groovy)
    at com.triu.system.reports.EntityFetchingCompositeItemWriter.write(EntityFetchingCompositeItemWriter.groovy:37)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springsource.loaded.ri.ReflectiveInterceptor.jlrMethodInvoke(ReflectiveInterceptor.java:1427)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133)
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
    at com.sun.proxy.$Proxy148.write(Unknown Source)
    at org.springframework.batch.core.step.item.SimpleChunkProcessor.writeItems(SimpleChunkProcessor.java:175)
    at org.springframework.batch.core.step.item.SimpleChunkProcessor.doWrite(SimpleChunkProcessor.java:151)
    at org.springframework.batch.core.step.item.SimpleChunkProcessor.write(SimpleChunkProcessor.java:274)
    at org.springframework.batch.core.step.item.SimpleChunkProcessor.process(SimpleChunkProcessor.java:199)
    at org.springframework.batch.core.step.item.ChunkOrientedTasklet.execute(ChunkOrientedTasklet.java:75)
    at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:406)
    at org.springframework.batch.core.step.tasklet.TaskletStep$ChunkTransactionCallback.doInTransaction(TaskletStep.java:330)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133)
    at org.springframework.batch.core.step.tasklet.TaskletStep$2.doInChunkContext(TaskletStep.java:272)
    at org.springframework.batch.core.scope.context.StepContextRepeatCallback.doInIteration(StepContextRepeatCallback.java:81)
    at org.springframework.batch.repeat.support.RepeatTemplate.getNextResult(RepeatTemplate.java:374)
    at org.springframework.batch.repeat.support.RepeatTemplate.executeInternal(RepeatTemplate.java:215)
    at org.springframework.batch.repeat.support.RepeatTemplate.iterate(RepeatTemplate.java:144)
    at org.springframework.batch.core.step.tasklet.TaskletStep.doExecute(TaskletStep.java:257)
    at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:200)
    at org.springframework.batch.core.partition.support.TaskExecutorPartitionHandler$1.call(TaskExecutorPartitionHandler.java:139)
    at org.springframework.batch.core.partition.support.TaskExecutorPartitionHandler$1.call(TaskExecutorPartitionHandler.java:136)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1$_closure2.doCall(PersistenceThreadPoolTaskDecorator.groovy:28)
    at sun.reflect.GeneratedMethodAccessor1666.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springsource.loaded.ri.ReflectiveInterceptor.jlrMethodInvoke(ReflectiveInterceptor.java:1427)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:98)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
    at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:264)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1034)
    at groovy.lang.Closure.call(Closure.java:418)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1$_closure2.call(PersistenceThreadPoolTaskDecorator.groovy)
    at groovy.lang.Closure.call(Closure.java:434)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1$_closure2.call(PersistenceThreadPoolTaskDecorator.groovy)
    at org.grails.orm.hibernate.GrailsHibernateTemplate$1.doInHibernate(GrailsHibernateTemplate.java:153)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.doExecute(GrailsHibernateTemplate.java:299)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.execute(GrailsHibernateTemplate.java:243)
    at org.grails.orm.hibernate.GrailsHibernateTemplate.executeWithNewSession(GrailsHibernateTemplate.java:150)
    at org.grails.orm.hibernate.AbstractHibernateDatastore.withNewSession(AbstractHibernateDatastore.java:356)
    at org.grails.orm.hibernate.AbstractHibernateGormStaticApi.withNewSession(AbstractHibernateGormStaticApi.groovy:60)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper.withNewSession(GormEntity.groovy:1025)
    at org.grails.datastore.gorm.GormEntity$Trait$Helper$withNewSession$21.call(Unknown Source)
    at com.triu.system.process.Process.withNewSession(Process.groovy)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1.doCall(PersistenceThreadPoolTaskDecorator.groovy:27)
    at sun.reflect.GeneratedMethodAccessor1665.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springsource.loaded.ri.ReflectiveInterceptor.jlrMethodInvoke(ReflectiveInterceptor.java:1427)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:98)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
    at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:264)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1034)
    at groovy.lang.Closure.call(Closure.java:418)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1.call(PersistenceThreadPoolTaskDecorator.groovy)
    at groovy.lang.Closure.call(Closure.java:412)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1.call(PersistenceThreadPoolTaskDecorator.groovy)
    at groovy.lang.Closure.run(Closure.java:499)
    at com.triu.system.PersistenceContextTaskDecorator$_decorate_closure1.run(PersistenceThreadPoolTaskDecorator.groovy)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
davidbairdala commented 6 years ago

Did you end up getting traction or further info on this issue? I'm running into the exact same problem.

In my case I can get it to happen consistently when I have an optional property on my domain class that is itself another domain object. When present, that property would be lazily loaded and there are no issues, but when that property is null, the exception above occurs. I think the act of having the parent entity load the related child entity is enough to make sure the connection holder has a connection, and so the release connection code works, but if the foreign key is null, the connection holder ends up with no connection.

It seems to me that the suggestion above to simply check the if the holder has a connection before asking for it would fix this issue quite easily, but understand that it would rely on a modification to ConnectionHolder that might prove too difficult.

longwa commented 6 years ago

Fixing the issue is possible as I suggested, however, my concern is that it's just fixing the symptom and not the true issue. In fact, it might just result in pushing the issue downstream a little more.

If you have an example app that can reproduce it consistently and simply, I'd feel better about making the fix.

davidbairdala commented 6 years ago

Thanks for commenting. I've spent a couple of hours trying to create a test case that reproduces the problem without any luck. Not surprisingly, the code base in which the problem occurs is fairly complicated, and it's hard to isolate the relevant parts. The issue occurs on background threads that are consuming messages from a queue, and there is a fairly comprehensive domain model that I'm loathe to mimic in a test case. I've managed to solve my particular issue by simply ensuring that the related domain property is never null, but I will come back to trying to create a reproducible test case when I get some free time.

longwa commented 6 years ago

Same here. We are seeing the issue in some spring batch executions which involve many moving parts including multiple threads and sessions. I’ve had a hard time reproducing on a smaller scale.

davidbairdala commented 5 years ago

I now have a simple test case that reproduces the error

https://github.com/davidbairdala/active-connection-required-grails-bug.git

Because this bug is a bit old I might raise a new one

larsauswsw commented 4 years ago

+1

We have the same problem with Grails 4.0.0.

In our case the problem only exists, when we use chained afterInsert methods.

Domainclass A has afterInsert that creates eight domainclasses of B and saves them (all in a service). Domainclass B has afterInsert that creates one domainclasses of C and saves it (all in a service).

In the afterInsert of A and B we use Domainclass.withNewSession{}.

The Exception is thrown after all service methods are done in the line where in domainclass A the withNewSession code starts.

offerbaruch commented 2 years ago

Hello,

We have a large application that every once in a while hits this issue. How can we make some progress with this issue? I see there is no progress since Jan 2020. Is there anyway to get support about this issue? Ways around it?

gstroup commented 9 months ago

+1 I'm also seeing this issue with Grails 4.1.2.