AnsweredAssumed Answered

JDBC batch update errors

Question asked by edgar on Jul 23, 2007
Latest reply on Jul 24, 2007 by kvc
Hi,

We are getting unpredictable JDBC batch update errors for various actions in the Alfresco Web Client. For instance we sometimes get it when creating a web content item but I have seen it in other actions as well (e.g. regenerate renditions). The errors are unpredictable in that the next time you attempt the same action the problem may be gone.

The log file shows:


INFO   | jvm 1    | 2007/07/23 13:22:02 | java.sql.BatchUpdateException: Lock wait timeout exceeded; try restarting transaction
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1237)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at com.mysql.jdbc.PreparedStatement.executeBatch(PreparedStatement.java:936)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:242)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:235)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:139)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.hibernate.AVMNodeDAOHibernate.flush(AVMNodeDAOHibernate.java:175)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.PlainDirectoryNodeImpl.removeChild(PlainDirectoryNodeImpl.java:251)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at sun.reflect.GeneratedMethodAccessor1091.invoke(Unknown Source)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at java.lang.reflect.Method.invoke(Method.java:585)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.invoke(CGLIBLazyInitializer.java:153)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.PlainDirectoryNode$$EnhancerByCGLIB$$67cd87d2.removeChild(<generated>)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.AVMStoreImpl.removeNode(AVMStoreImpl.java:641)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.AVMRepository.remove(AVMRepository.java:837)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.AVMServiceImpl.removeNode(AVMServiceImpl.java:505)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at sun.reflect.GeneratedMethodAccessor1004.invoke(Unknown Source)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at java.lang.reflect.Method.invoke(Method.java:585)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.search.AVMSnapShotTriggeredIndexingMethodInterceptor.invoke(AVMSnapShotTriggeredIndexingMethodInterceptor.java:154)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at $Proxy5.removeNode(Unknown Source)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.avm.AVMSyncServiceImpl.resetLayer(AVMSyncServiceImpl.java:791)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at sun.reflect.GeneratedMethodAccessor1008.invoke(Unknown Source)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at java.lang.reflect.Method.invoke(Method.java:585)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:281)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:187)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.repo.transaction.RetryingTransactionAdvice.invoke(RetryingTransactionAdvice.java:92)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:210)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at $Proxy46.resetLayer(Unknown Source)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.web.bean.wcm.CreateWebContentWizard.init(CreateWebContentWizard.java:221)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.web.bean.wizard.WizardManager.setCurrentWizard(WizardManager.java:123)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.web.app.AlfrescoNavigationHandler.handleWizardOpen(AlfrescoNavigationHandler.java:636)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.web.app.AlfrescoNavigationHandler.handleNavigation(AlfrescoNavigationHandler.java:118)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.myfaces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:82)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at javax.faces.component.UICommand.broadcast(UICommand.java:109)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at javax.faces.component.UIViewRoot._broadcastForPhase(UIViewRoot.java:97)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:171)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.myfaces.lifecycle.InvokeApplicationExecutor.execute(InvokeApplicationExecutor.java:32)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.myfaces.lifecycle.LifecycleImpl.executePhase(LifecycleImpl.java:95)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.myfaces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:70)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at javax.faces.webapp.FacesServlet.service(FacesServlet.java:139)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.alfresco.web.app.servlet.AuthenticationFilter.doFilter(AuthenticationFilter.java:81)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
INFO   | jvm 1    | 2007/07/23 13:22:02 |    at java.lang.Thread.run(Thread.java:595)

We also notice that the performance of the Alfresco s very slow. The save action when creating a new web content item for example takes a very long time (>1 minute).

Any ideas on how to resolve this? I do not know what the problem is but I have a feeling it has to do with the versioning system maybe? Can we disable versioning on web content items at all, to see if that is the issue?

We are running Alfresco 2.1R1 on Linux on MySQL.

regards,

Edgar

Outcomes