cancel
Showing results for 
Search instead for 
Did you mean: 

WebService causing Lock timeout Errors

steel
Champ in-the-making
Champ in-the-making
My web service is adding lots of content ~13000 documents and in the Alfresco log it intermitently gives the following error.  The application creates the node, sets its contents, adds the titled aspect and also the versionable aspect.  The 2 add aspect calls are in separate queries.  The objects seems to be put in the repository just fine, but response time is god awful slow.  Adding the versionable aspect can take 2 minutes and sometimes causing the web service to timeout.

I am trying to pinpoint the culprit. There is a lag in communicating with the database server but I am not sure if it would cause such slow performance.

I do not think its the alfresco installation as this dedicated server box is much faster than my laptop development box.  And yet the laptop processes these web service queries faster, but its database is located on the same machine.  No errors on the laptop though.

Is there someway to view the hibernate statistics so see if the database is the culprit?  Maybe tomcat 5.5.15 is slow? We're using native library as well for tomcat.

Some help would be greatly appreciated.

thanks!

02:27:50,953 ERROR [hibernate.util.JDBCExceptionReporter] Lock wait timeout exceeded; try restarting transaction
02:27:50,953 ERROR [event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:91)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:79)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:202)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:230)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:41)
   at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:978)
   at org.hibernate.impl.AbstractSessionImpl.getHQLQueryPlan(AbstractSessionImpl.java:135)
   at org.hibernate.impl.AbstractSessionImpl.getNamedQuery(AbstractSessionImpl.java:60)
   at org.hibernate.impl.SessionImpl.getNamedQuery(SessionImpl.java:1245)
   at sun.reflect.GeneratedMethodAccessor518.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.orm.hibernate3.HibernateTemplate$CloseSuppressingInvocationHandler.invoke(HibernateTemplate.java:1178)
   at $Proxy69.getNamedQuery(Unknown Source)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl$3.doInHibernate(HibernateNodeDaoServiceImpl.java:436)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:365)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:333)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl.getNodeAssoc(HibernateNodeDaoServiceImpl.java:448)
   at sun.reflect.GeneratedMethodAccessor552.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
   at org.alfresco.repo.transaction.NodeDaoServiceTransactionInterceptor.invoke(NodeDaoServiceTransactionInterceptor.java:61)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
   at $Proxy1.getNodeAssoc(Unknown Source)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.createAssociation(DbNodeServiceImpl.java:1061)
   at sun.reflect.GeneratedMethodAccessor551.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:165)
   at $Proxy2.createAssociation(Unknown Source)
   at org.alfresco.repo.version.VersionServiceImpl.createVersion(VersionServiceImpl.java:362)
   at org.alfresco.repo.version.VersionServiceImpl.createVersion(VersionServiceImpl.java:178)
   at org.alfresco.repo.action.executer.CreateVersionActionExecuter.executeImpl(CreateVersionActionExecuter.java:63)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:91)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:472)
   at org.alfresco.repo.action.executer.CompositeActionExecuter.executeImpl(CompositeActionExecuter.java:64)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:91)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:472)
   at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:404)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:331)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:319)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:480)
   at sun.reflect.GeneratedMethodAccessor543.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
   at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:116)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:32)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:37)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
   at $Proxy18.executeAction(Unknown Source)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:779)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:715)
   at org.alfresco.repo.rule.RuleTransactionListener.beforeCommit(RuleTransactionListener.java:61)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.beforeCommit(AlfrescoTransactionSupport.java:581)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:657)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:482)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:469)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCommitTransactionAfterReturning(TransactionAspectSupport.java:266)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:396)
   at org.alfresco.repo.webservice.repository.RepositoryWebService.update(RepositoryWebService.java:496)
   at sun.reflect.GeneratedMethodAccessor446.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:397)
   at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:186)
   at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
   at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
   at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
   at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
   at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:453)
   at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
   at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
   at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
   at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:831)
   at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:639)
   at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1203)
   at java.lang.Thread.run(Thread.java:595)
Caused by: java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:648)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:195)
   … 99 more
02:27:50,968 ERROR [repo.action.ActionServiceImpl] An error was encountered whilst executing the action 'composite-action'.
org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: Could not execute JDBC batch update; uncategorized SQLException for SQL [update version_count set version_count=? where protocol=? and identifier=?]; SQL state [41000]; error code [1205]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:648)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:195)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:230)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:41)
   at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:978)
   at org.hibernate.impl.AbstractSessionImpl.getHQLQueryPlan(AbstractSessionImpl.java:135)
   at org.hibernate.impl.AbstractSessionImpl.getNamedQuery(AbstractSessionImpl.java:60)
   at org.hibernate.impl.SessionImpl.getNamedQuery(SessionImpl.java:1245)
   at sun.reflect.GeneratedMethodAccessor518.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.orm.hibernate3.HibernateTemplate$CloseSuppressingInvocationHandler.invoke(HibernateTemplate.java:1178)
   at $Proxy69.getNamedQuery(Unknown Source)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl$3.doInHibernate(HibernateNodeDaoServiceImpl.java:436)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:365)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:333)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl.getNodeAssoc(HibernateNodeDaoServiceImpl.java:448)
   at sun.reflect.GeneratedMethodAccessor552.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
   at org.alfresco.repo.transaction.NodeDaoServiceTransactionInterceptor.invoke(NodeDaoServiceTransactionInterceptor.java:61)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
   at $Proxy1.getNodeAssoc(Unknown Source)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.createAssociation(DbNodeServiceImpl.java:1061)
   at sun.reflect.GeneratedMethodAccessor551.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:165)
   at $Proxy2.createAssociation(Unknown Source)
   at org.alfresco.repo.version.VersionServiceImpl.createVersion(VersionServiceImpl.java:362)
   at org.alfresco.repo.version.VersionServiceImpl.createVersion(VersionServiceImpl.java:178)
   at org.alfresco.repo.action.executer.CreateVersionActionExecuter.executeImpl(CreateVersionActionExecuter.java:63)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:91)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:472)
   at org.alfresco.repo.action.executer.CompositeActionExecuter.executeImpl(CompositeActionExecuter.java:64)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:91)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:472)
   at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:404)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:331)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:319)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:480)
   at sun.reflect.GeneratedMethodAccessor543.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
   at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:116)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:32)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:37)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
   at $Proxy18.executeAction(Unknown Source)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:779)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:715)
   at org.alfresco.repo.rule.RuleTransactionListener.beforeCommit(RuleTransactionListener.java:61)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.beforeCommit(AlfrescoTransactionSupport.java:581)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:657)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:482)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:469)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCommitTransactionAfterReturning(TransactionAspectSupport.java:266)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:396)
   at org.alfresco.repo.webservice.repository.RepositoryWebService.update(RepositoryWebService.java:496)
   at sun.reflect.GeneratedMethodAccessor446.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:397)
   at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:186)
   at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
   at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
   at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
   at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
   at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:453)
   at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
   at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
   at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
   at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:831)
   at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:639)
   at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1203)
   at java.lang.Thread.run(Thread.java:595)
02:27:50,984 ERROR [util.transaction.SpringAwareUserTransaction] Transaction didn't commit
org.springframework.jdbc.UncategorizedSQLException: Hibernate operation: Could not execute JDBC batch update; uncategorized SQLException for SQL [update version_count set version_count=? where protocol=? and identifier=?]; SQL state [41000]; error code [1205]; Lock wait timeout exceeded; try restarting transaction; nested exception is java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:648)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:195)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:230)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:141)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:41)
   at org.hibernate.impl.SessionImpl.autoFlushIfRequired(SessionImpl.java:978)
   at org.hibernate.impl.AbstractSessionImpl.getHQLQueryPlan(AbstractSessionImpl.java:135)
   at org.hibernate.impl.AbstractSessionImpl.getNamedQuery(AbstractSessionImpl.java:60)
   at org.hibernate.impl.SessionImpl.getNamedQuery(SessionImpl.java:1245)
   at sun.reflect.GeneratedMethodAccessor518.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.orm.hibernate3.HibernateTemplate$CloseSuppressingInvocationHandler.invoke(HibernateTemplate.java:1178)
   at $Proxy69.getNamedQuery(Unknown Source)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl$3.doInHibernate(HibernateNodeDaoServiceImpl.java:436)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:365)
   at org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:333)
   at org.alfresco.repo.node.db.hibernate.HibernateNodeDaoServiceImpl.getNodeAssoc(HibernateNodeDaoServiceImpl.java:448)
   at sun.reflect.GeneratedMethodAccessor552.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
   at org.alfresco.repo.transaction.NodeDaoServiceTransactionInterceptor.invoke(NodeDaoServiceTransactionInterceptor.java:61)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
   at $Proxy1.getNodeAssoc(Unknown Source)
   at org.alfresco.repo.node.db.DbNodeServiceImpl.createAssociation(DbNodeServiceImpl.java:1061)
   at sun.reflect.GeneratedMethodAccessor551.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:165)
   at $Proxy2.createAssociation(Unknown Source)
   at org.alfresco.repo.version.VersionServiceImpl.createVersion(VersionServiceImpl.java:362)
   at org.alfresco.repo.version.VersionServiceImpl.createVersion(VersionServiceImpl.java:178)
   at org.alfresco.repo.action.executer.CreateVersionActionExecuter.executeImpl(CreateVersionActionExecuter.java:63)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:91)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:472)
   at org.alfresco.repo.action.executer.CompositeActionExecuter.executeImpl(CompositeActionExecuter.java:64)
   at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:91)
   at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:472)
   at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:404)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:331)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:319)
   at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:480)
   at sun.reflect.GeneratedMethodAccessor543.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:335)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:181)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:148)
   at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:116)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:32)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:37)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
   at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:170)
   at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:176)
   at $Proxy18.executeAction(Unknown Source)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:779)
   at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:715)
   at org.alfresco.repo.rule.RuleTransactionListener.beforeCommit(RuleTransactionListener.java:61)
   at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.beforeCommit(AlfrescoTransactionSupport.java:581)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:657)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:482)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:469)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCommitTransactionAfterReturning(TransactionAspectSupport.java:266)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:396)
   at org.alfresco.repo.webservice.repository.RepositoryWebService.update(RepositoryWebService.java:496)
   at sun.reflect.GeneratedMethodAccessor446.invoke(Unknown Source)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:585)
   at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:397)
   at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:186)
   at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
   at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
   at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
   at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
   at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:453)
   at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
   at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
   at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
   at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:831)
   at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:639)
   at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1203)
   at java.lang.Thread.run(Thread.java:595)
8 REPLIES 8

davidc
Star Contributor
Star Contributor
Is it just adding the Versionable Aspect that's slow or all web service calls?

Do you have a simple test client that reproduces the problem?

steel
Champ in-the-making
Champ in-the-making
Is it just adding the Versionable Aspect that's slow or all web service calls?

Do you have a simple test client that reproduces the problem?

It seems only addin the Versionable Aspect is slow.  Titled aspect and setting contents are very quick, then it gets stuck on adding the versionable aspect for a while.

I do not have an isolated test client to reproduce the problem. The problems seems to be specific to the current installation as other deployments of alfresco do not suffer this problem. Is there anything in adding the Versionable Aspect that stresses the system/db?

steel
Champ in-the-making
Champ in-the-making
I will try to run a profiler on the tomcat server to see what the bottleneck is after the current import job is done.

pparkinson
Champ in-the-making
Champ in-the-making
Hey Steel,

We're getting the same error running a webservice adding similarly about 15000 docs.  Did you pinpoint it to the versionable aspect?

steel
Champ in-the-making
Champ in-the-making
Hey Steel,

We're getting the same error running a webservice adding similarly about 15000 docs.  Did you pinpoint it to the versionable aspect?

What version of alfresco are you running? I was using Alfresco 1.2.1 which doesn't optimized to handle so much volume.  From what I heard, 1.3+ has an updated DB schema which should make larger repositories more responsive.  However, I have not had time to test it.

pparkinson
Champ in-the-making
Champ in-the-making
We're currently running ALF 1.3.0.  Like yourself the documents are added pretty fast.  As fast as I would expect anyway and they do get inserted but I'll get that timeout error occasionally. 

Is there a default lock wait timeout value that is configurable?

steel
Champ in-the-making
Champ in-the-making
We're currently running ALF 1.3.0.  Like yourself the documents are added pretty fast.  As fast as I would expect anyway and they do get inserted but I'll get that timeout error occasionally. 

Is there a default lock wait timeout value that is configurable?

There is a lock wait timeout in the Repository.Properties file I believe. I have not toyed with it though.

csiege
Champ in-the-making
Champ in-the-making
From our experience on 1.3.1E, the versionable aspect add a lot of overhead on added documents that increases as the number of versioned documents in the system increases.

We were initially going to have all documents in our system "versionable" by default.  This was such a problem, we had to let that idea go.

I have heard from support that this should be much better in 1.4, but I have not tested it yet.

Without having everything versionable (only those that really need it for now), we have had pretty good performance overall.

Chris