HibernateException after upgrade to 5.1: connnection proxy not usable after transaction

[rivarola]

Hello,
We have upgraded from Alfresco Community 4.2-b to 5.1-e and now some errors happen randomly :
[font=Courier]
2016-04-20 10:22:32,866 ERROR [org.springframework.extensions.webscripts.AbstractRuntime] [http-apr-8080-exec-8] Exception from executeScript - redirecting to status template error: 03200001 Wrapped Exception (with status template): nested exception is org.apache.ibatis.executor.ExecutorException: Error preparing statement.  Cause: org.hibernate.HibernateException: connnection proxy not usable after transaction completion
org.springframework.extensions.webscripts.WebScriptException: 03200001 Wrapped Exception (with status template): nested exception is org.apache.ibatis.executor.ExecutorException: Error preparing statement.  Cause: org.hibernate.HibernateException: connnection proxy not usable after transaction completion
   at org.springframework.extensions.webscripts.AbstractWebScript.createStatusException(AbstractWebScript.java:1138)
   at org.springframework.extensions.webscripts.DeclarativeWebScript.execute(DeclarativeWebScript.java:171)
   at org.alfresco.repo.web.scripts.RepositoryContainer$3.execute(RepositoryContainer.java:512)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:461)
   at org.alfresco.repo.web.scripts.RepositoryContainer.transactionedExecute(RepositoryContainer.java:580)
   at org.alfresco.repo.web.scripts.RepositoryContainer.transactionedExecuteAs(RepositoryContainer.java:649)
   at org.alfresco.repo.web.scripts.RepositoryContainer.executeScriptInternal(RepositoryContainer.java:421)
   at org.alfresco.repo.web.scripts.RepositoryContainer.executeScript(RepositoryContainer.java:301)
   at org.springframework.extensions.webscripts.AbstractRuntime.executeScript(AbstractRuntime.java:378)
   at org.springframework.extensions.webscripts.AbstractRuntime.executeScript(AbstractRuntime.java:209)
   at org.springframework.extensions.webscripts.servlet.WebScriptServlet.service(WebScriptServlet.java:132)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at com.knowings.kmsj.web.app.servlet.SessionBindingFilter.doFilter(SessionBindingFilter.java:75)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at com.knowings.kmsj.web.app.servlet.AbstractLocaleFilter.doFilter(AbstractLocaleFilter.java:243)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at com.knowings.kmsj.web.app.servlet.SealFilter.doFilter(SealFilter.java:78)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at com.knowings.kmsj.web.app.servlet.BasicHttpAuthenticationFilter.doFilter(BasicHttpAuthenticationFilter.java:144)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at com.knowings.kmsj.web.app.servlet.FeedBackFilter.doFilter(FeedBackFilter.java:31)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
   at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
   at com.googlecode.psiprobe.Tomcat70AgentValve.invoke(Tomcat70AgentValve.java:38)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
   at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:423)
   at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1079)
   at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
   at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2522)
   at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2511)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
   at java.lang.Thread.run(Thread.java:745)
Caused by: org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.executor.ExecutorException: Error preparing statement.  Cause: org.hibernate.HibernateException: connnection proxy not usable after transaction completion
   at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:76)
   at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:399)
   at com.sun.proxy.$Proxy20.selectOne(Unknown Source)
   at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:165)
   at org.alfresco.repo.domain.node.ibatis.NodeDAOImpl.selectNodeByNodeRef(NodeDAOImpl.java:438)
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl$NodesCacheCallbackDAO.findByValue(AbstractNodeDAOImpl.java:952)
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl$NodesCacheCallbackDAO.findByValue(AbstractNodeDAOImpl.java:1)
   at org.alfresco.repo.cache.lookup.EntityLookupCache.getByValue(EntityLookupCache.java:398)
   at org.alfresco.repo.domain.node.AbstractNodeDAOImpl.exists(AbstractNodeDAOImpl.java:975)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.exists_aroundBody2(DbNodeServiceImpl.java:207)
   at org.alfresco.repo.node.db.DbNodeServiceImpl$AjcClosure3.run(DbNodeServiceImpl.java:1)
   at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
   at org.alfresco.traitextender.RouteExtensions.intercept(RouteExtensions.java:93)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.exists(DbNodeServiceImpl.java:204)
   at sun.reflect.GeneratedMethodAccessor308.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
   at org.alfresco.repo.lock.mem.LockableAspectInterceptor.invoke(LockableAspectInterceptor.java:234)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at com.sun.proxy.$Proxy30.exists(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor308.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
   at org.alfresco.repo.tenant.MultiTNodeServiceInterceptor.invoke(MultiTNodeServiceInterceptor.java:104)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at com.sun.proxy.$Proxy30.exists(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor308.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:224)
   at com.sun.proxy.$Proxy52.exists(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor308.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
   at org.alfresco.repo.node.MLPropertyInterceptor.invoke(MLPropertyInterceptor.java:305)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:269)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
   at com.sun.proxy.$Proxy30.exists(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor308.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:198)
   at com.sun.proxy.$Proxy30.exists(Unknown Source)
   at org.alfresco.repo.security.person.PersonServiceImpl.getPersonOrNullImpl(PersonServiceImpl.java:557)
   at org.alfresco.repo.security.person.PersonServiceImpl.getPersonImpl(PersonServiceImpl.java:489)
   at org.alfresco.repo.security.person.PersonServiceImpl.getPersonOrNull(PersonServiceImpl.java:468)
   at org.alfresco.repo.security.person.PersonServiceImpl.personExists(PersonServiceImpl.java:519)
   at org.alfresco.repo.model.Repository$4.execute(Repository.java:316)
   at org.alfresco.repo.model.Repository$4.execute(Repository.java:1)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:461)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:348)
   at org.alfresco.repo.model.Repository.getFullyAuthenticatedPerson(Repository.java:324)
   at org.alfresco.repo.web.scripts.RepositoryContainer.addRepoParameters(RepositoryContainer.java:280)
   at org.alfresco.repo.web.scripts.RepositoryContainer.access$200(RepositoryContainer.java:75)
   at org.alfresco.repo.web.scripts.RepositoryContainer$1.execute(RepositoryContainer.java:254)
   at org.alfresco.repo.web.scripts.RepositoryContainer$1.execute(RepositoryContainer.java:248)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:461)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:348)
   at org.alfresco.repo.web.scripts.RepositoryContainer.getTemplateParameters(RepositoryContainer.java:247)
   at org.springframework.extensions.webscripts.AbstractWebScript.createTemplateParameters(AbstractWebScript.java:790)
   at org.springframework.extensions.webscripts.DeclarativeWebScript.execute(DeclarativeWebScript.java:91)
   … 47 more
Caused by: org.apache.ibatis.executor.ExecutorException: Error preparing statement.  Cause: org.hibernate.HibernateException: connnection proxy not usable after transaction completion
   at org.apache.ibatis.executor.statement.BaseStatementHandler.prepare(BaseStatementHandler.java:94)
   at org.apache.ibatis.executor.statement.RoutingStatementHandler.prepare(RoutingStatementHandler.java:57)
   at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:73)
   at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:59)
   at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:267)
   at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:137)
   at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:96)
   at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:77)
   at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:108)
   at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:102)
   at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:66)
   at sun.reflect.GeneratedMethodAccessor200.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   at java.lang.reflect.Method.invoke(Method.java:497)
   at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:386)
   … 120 more
Caused by: org.hibernate.HibernateException: connnection proxy not usable after transaction completion
   at org.hibernate.jdbc.BorrowedConnectionProxy.invoke(BorrowedConnectionProxy.java:142)
   at com.sun.proxy.$Proxy18.prepareStatement(Unknown Source)
   at org.apache.ibatis.executor.statement.PreparedStatementHandler.instantiateStatement(PreparedStatementHandler.java:75)
   at org.apache.ibatis.executor.statement.BaseStatementHandler.prepare(BaseStatementHandler.java:85)
   … 134 more
[/font]

Did anybody experienced that ?

[loftux]

Did you ever get a solution for this issue?

I'm seeing the same with 5.2 201612 GA and filed this issue

Alfresco - Alfresco JIRA 

[aowian]

I restarted Alfresco, and the problem stopped temporarily... until it came back randomly. 

Before the HibernateException referred to above, I found the following in the logs:
ERROR [repo.transaction.RetryingTransactionHelper] [http-apr-8080-exec-18] Rollback failure. Normal retry behaviour will resume.
java.lang.IllegalStateException: Already value [org.mybatis.spring.SqlSessionHolder@561071fc] for key [org.apache.ibatis.session.defaults.DefaultSqlSessionFactory@29ca37b2] bound to thread [http-apr-8080-exec-18]
...

I wonder if they are related.

Our DBA checked the database, and there were no errors. 

This was the sql we think was running when the error occurred:

SELECT  acs.id             AS id            ,         acs.commit_time_ms AS commit_time_ms,         COUNT(acl_id)      AS acl_countFROM    alf_acl_change_set acs         JOIN alf_access_control_list acl         ON                (                         acl.acl_change_set = acs.id                )WHERE   EXISTS        (                 SELECT 1 FROM alf_node admnode WHERE admnode.acl_id = acl.id        )         AND acs.id >= :1        AND acs.id  < :2GROUP BY acs.commit_time_ms,         acs.idORDER BY acs.commit_time_ms ASC,         acs.id ASC

This link makes me think that it could be an Alfresco bug.

[anujs1986]

Does anyone got any solution?

Mostly, Its occurring during batch job run.