LockAcquisitionException while adding content in repository.

As we transition to the new Hyland Community, some post links may be temporarily disrupted as we finalize redirects. We apologize for the inconvenience and are working to resolve this as quickly as possible. Details.

rupeshsawaliya1

Hi,
I am facing one issue while running test script through Jmeter, issue is related to dead lock in Alfresco.
Following is the environment I am having:
Server:Websphere v7.0
DatabaseB2
Alfresco Version:2.1.1
Testing tool: Jmeter

I have developed one test script, which tests Alfresco’s Add Content Functionality.
Scenario is:- 10 thread activate to add 4500 document.
After adding around 300 document Alfresco throws an exception, that is
“org.hibernate.exception.LockAcquisitionException: could not execute query”
with  “DB2 SQL error: SQLCODE: -911, SQLSTATE: 40001, SQLERRMC: 2”
sql status.

I am copying the complete stack trace, please help me.

Caused by: org.hibernate.exception.LockAcquisitionException: could not execute query
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:82)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.loader.Loader.doList(Loader.java:2214)
   at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2095)
   at org.hibernate.loader.Loader.list(Loader.java:2090)
   at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:388)
   at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
   at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
   at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
   at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
   at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:804)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl$4.doInHibernate(HibernateNodeDaoServiceImpl.java:698)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:367)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:333)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl.setChildNameUnique(HibernateNodeDaoServiceImpl.java:701)
   at sun.reflect.GeneratedMethodAccessor174.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
   at org.alfresco.repo.transaction.TransactionalDaoInterceptor.invoke(TransactionalDaoInterceptor.java:68)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
   at $Proxy23.setChildNameUnique(Unknown Source)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.setChildUniqueName(DbNodeServiceImpl.java:2049)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.setProperties(DbNodeServiceImpl.java:1005)
   at sun.reflect.GeneratedMethodAccessor143.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
   at org.alfresco.repo.transaction.TransactionResourceInterceptor.invoke(TransactionResourceInterceptor.java:138)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
   at $Proxy25.setProperties(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor143.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:221)
   at $Proxy26.setProperties(Unknown Source)
   at org.alfresco.repo.node.MLPropertyInterceptor.invoke(MLPropertyInterceptor.java:220)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:236)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:236)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
   at $Proxy25.setProperties(Unknown Source)
   at org.alfresco.repo.audit.AuditableAspect$SetAuditProperties.doWork(AuditableAspect.java:269)
   at org.alfresco.repo.audit.AuditableAspect$SetAuditProperties.doWork(AuditableAspect.java:237)
   at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:269)
   at org.alfresco.repo.audit.AuditableAspect.onAddAudit(AuditableAspect.java:158)
   at sun.reflect.GeneratedMethodAccessor397.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.alfresco.repo.policy.JavaBehaviour$JavaMethodInvocationHandler.invoke(JavaBehaviour.java:179)
   at $Proxy29.onAddAspect(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor264.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.alfresco.repo.policy.TransactionInvocationHandlerFactory$TransactionHandler.invoke(TransactionInvocationHandlerFactory.java:134)
   at $Proxy29.onAddAspect(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor264.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.alfresco.repo.policy.PolicyFactory$MultiHandler.invoke(PolicyFactory.java:251)
   at org.alfresco.repo.policy.$Proxy101.onAddAspect(Unknown Source)
   at org.alfresco.repo.node.AbstractNodeServiceImpl.invokeOnAddAspect(AbstractNodeServiceImpl.java:387)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.addDefaultAspects(DbNodeServiceImpl.java:387)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.createNode(DbNodeServiceImpl.java:342)
   at sun.reflect.GeneratedMethodAccessor331.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
   at org.alfresco.repo.transaction.TransactionResourceInterceptor.invoke(TransactionResourceInterceptor.java:138)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
   at $Proxy25.createNode(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor331.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:221)
   at $Proxy26.createNode(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor331.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
   at org.alfresco.repo.node.MLPropertyInterceptor.invoke(MLPropertyInterceptor.java:241)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.node.MLPropertyInterceptor.invoke(MLPropertyInterceptor.java:241)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:175)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:175)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
   at $Proxy25.createNode(Unknown Source)
   at org.alfresco.repo.model.filefolder.FileFolderServiceImpl.create(FileFolderServiceImpl.java:737)
   at sun.reflect.GeneratedMethodAccessor398.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
   at org.alfresco.repo.model.filefolder.TempFileMarkerInterceptor.invoke(TempFileMarkerInterceptor.java:83)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.model.ml.MLContentInterceptor.invoke(MLContentInterceptor.java:131)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.model.filefolder.MLTranslationInterceptor.invoke(MLTranslationInterceptor.java:210)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:80)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:49)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.alfresco.repo.audit.AuditComponentImpl.audit(AuditComponentImpl.java:241)
   at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:69)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
   at $Proxy62.create(Unknown Source)
   at org.alfresco.web.bean.content.BaseContentWizard.saveContent(BaseContentWizard.java:417)
   at org.alfresco.web.bean.content.AddContentDialog.finishImpl(AddContentDialog.java:100)
   at org.alfresco.web.bean.dialog.BaseDialogBean$1.execute(BaseDialogBean.java:118)
   at org.alfresco.web.bean.dialog.BaseDialogBean$1.execute(BaseDialogBean.java:115)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:236)
   at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:166)
   at org.alfresco.web.bean.dialog.BaseDialogBean.finish(BaseDialogBean.java:124)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:45)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
   at java.lang.reflect.Method.invoke(Method.java:599)
   at org.apache.myfaces.el.MethodBindingImpl.invoke(MethodBindingImpl.java:132)
   at org.apache.myfaces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:61)
   at javax.faces.component.UICommand.broadcast(UICommand.java:109)
   at javax.faces.component.UIViewRoot._broadcastForPhase(UIViewRoot.java:97)
   at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:171)
   at org.apache.myfaces.lifecycle.InvokeApplicationExecutor.execute(InvokeApplicationExecutor.java:32)
   at org.apache.myfaces.lifecycle.LifecycleImpl.executePhase(LifecycleImpl.java:95)
   at org.apache.myfaces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:70)
   at javax.faces.webapp.FacesServlet.service(FacesServlet.java:139)
   at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1443)
   at com.ibm.ws.webcontainer.servlet.ServletWrapper.service(ServletWrapper.java:1384)
   at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:131)
   at org.alfresco.web.app.servlet.AuthenticationFilter.doFilter(AuthenticationFilter.java:81)
   at com.ibm.ws.webcontainer.filter.FilterInstanceWrapper.doFilter(FilterInstanceWrapper.java:188)
   at com.ibm.ws.webcontainer.filter.WebAppFilterChain.doFilter(WebAppFilterChain.java:116)
   at com.ibm.ws.webcontainer.filter.WebAppFilterChain._doFilter(WebAppFilterChain.java:77)
   at com.ibm.ws.webcontainer.filter.WebAppFilterManager.doFilter(WebAppFilterManager.java:852)
   at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:785)
   at com.ibm.ws.webcontainer.servlet.ServletWrapper.handleRequest(ServletWrapper.java:443)
   at com.ibm.ws.webcontainer.servlet.ServletWrapperImpl.handleRequest(ServletWrapperImpl.java:175)
   at com.ibm.ws.webcontainer.servlet.CacheServletWrapper.handleRequest(CacheServletWrapper.java:91)
   at com.ibm.ws.webcontainer.WebContainer.handleRequest(WebContainer.java:859)
   at com.ibm.ws.webcontainer.WSWebContainer.handleRequest(WSWebContainer.java:1557)
   at com.ibm.ws.webcontainer.channel.WCChannelLink.ready(WCChannelLink.java:173)
   at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleDiscrimination(HttpInboundLink.java:455)
   at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.handleNewInformation(HttpInboundLink.java:384)
   at com.ibm.ws.http.channel.inbound.impl.HttpInboundLink.ready(HttpInboundLink.java:272)
   at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.sendToDiscriminators(NewConnectionInitialReadCallback.java:214)
   at com.ibm.ws.tcp.channel.impl.NewConnectionInitialReadCallback.complete(NewConnectionInitialReadCallback.java:113)
   at com.ibm.ws.tcp.channel.impl.AioReadCompletionListener.futureCompleted(AioReadCompletionListener.java:165)
   at com.ibm.io.async.AbstractAsyncFuture.invokeCallback(AbstractAsyncFuture.java:217)
   at com.ibm.io.async.AsyncChannelFuture.fireCompletionActions(AsyncChannelFuture.java:161)
   at com.ibm.io.async.AsyncFuture.completed(AsyncFuture.java:138)
   at com.ibm.io.async.ResultHandler.complete(ResultHandler.java:202)
   at com.ibm.io.async.ResultHandler.runEventProcessingLoop(ResultHandler.java:766)
   at com.ibm.io.async.ResultHandler$2.run(ResultHandler.java:896)
   at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1527)
Caused by: com.ibm.db2.jcc.c.SqlException: DB2 SQL error: SQLCODE: -911, SQLSTATE: 40001, SQLERRMC: 2
   at com.ibm.db2.jcc.c.lf.b(lf.java:3265)
   at com.ibm.db2.jcc.b.kb.i(kb.java:220)
   at com.ibm.db2.jcc.b.kb.a(kb.java:180)
   at com.ibm.db2.jcc.b.kb.a(kb.java:35)
   at com.ibm.db2.jcc.b.x.a(x.java:30)
   at com.ibm.db2.jcc.b.j.Gb(j.java:341)
   at com.ibm.db2.jcc.c.lf.R(lf.java:3099)
   at com.ibm.db2.jcc.b.d.f(d.java:1044)
   at com.ibm.db2.jcc.c.s.a(s.java:189)
   at com.ibm.db2.jcc.c.lf.c(lf.java:312)
   at com.ibm.db2.jcc.c.lf.next(lf.java:283)
   at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:168)
   at org.hibernate.loader.Loader.doQuery(Loader.java:685)
   at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
   at org.hibernate.loader.Loader.doList(Loader.java:2211)
   … 172 more‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

Thanks in Advance.

Regards,
Rupesh Sawaliya
Cignex Technologies

dward

Your error message is documented here

http://publib.boulder.ibm.com/infocenter/db2luw/v8/topic/com.ibm.db2.udb.doc/core/rsql0900.htm

SQL0911N The current transaction has been rolled back because of a deadlock or timeout. Reason code 2

Reason code 2 is

transaction rolled back due to deadlock.

This is a perfectly normal occurrence when there are multiple competing transactions. In a transaction collision, one transaction will win and the others will have to be retried. Normally Alfresco's RetryingTransactionHelper will handle such LockAcquisitionExceptions by retrying the transaction after a random 'back off' interval, up to the number of times configured in

server.transaction.max-retries

Alfresco will only give up and log the exception if this number of retries is exceeded. The default is 40.

That is why, in the default Alfresco log4j configuration we have the following setting, which stops Hibernate from logging exceptions which are handled and retried by Alfresco.

log4j.logger.org.hibernate.util.JDBCExceptionReporter=fatal

Now the first thing to check is that your log configuration isn't allowing org.hibernate.util.JDBCExceptionReporter to report INFO, WARN or ERROR messages. I am not sure how this is controlled in Websphere, and I have a feeling that the default Websphere settings might be letting these through. So it may well be that you can ignore these messages if you can confirm they are coming from JDBCExceptionReporter.

If the transactions are actually getting retried 40 times and still failing then this suggests that the server is seriously overloaded. I would be surprised if this is the case.

You could experiment with different values for these parameters to see how it affects the frequency of these errors

server.transaction.max-retries
server.transaction.min-retry-wait-ms
server.transaction.max-retry-wait-ms
server.transaction.wait-increment-ms

Regards

Dave