AnsweredAssumed Answered

Create Content + Submit to Staging == 'Lock Wait' exception

Question asked by laura_ on Aug 17, 2009
In Alfresco Community 3.2 (and the in-progress v3.3), a single webscript that performs both of the following steps will get a "Lock Wait Timeout" stack trace:
    Create a piece of content
    Submit the content to the staging sandbox
This was possible in Alfresco <=3.1, but in the latest versions this generates an exception in both JavaScript- and Java-backed webscripts.  Did something change regarding transaction management in 3.2 that prevents some actions from being bundled together?  Or is there some better way that can be used to pull this off (e.g. is it possible to initiate web scripts WITHIN other web scripts.. yet inside of another transaction)? 

Below is some more info; it's very simple to reproduce. 

SAMPLE WEB SCRIPT
Note that the code below assumes there's an "admin" user and a web project named "poc".

logger.log("Starting our script");
var containingFolder = avm.lookupNode("poc–admin:/www/avm_webapps/ROOT");
var parentContainer = containingFolder.createNode("OurTest", "wcm:avmplainfolder");
var usersandboxes = webprojects.getWebProject("poc").getSandboxes("admin");
logger.log("This next line will hang the server");
usersandboxes[0].submit( ["/www/avm_webapps/ROOT/OurTest"], "Label", "Comment");
logger.log("We never get here…");

STACK TRACE

19:57:06,662 User:admin DEBUG [repo.jscript.ScriptLogger] Starting our script
19:57:20,293 User:admin DEBUG [repo.jscript.ScriptLogger] This next line will hang the server
19:57:25,946 User:admin DEBUG [repo.avm.AVMSyncServiceImpl] update: poc–admin:/www/avm_webapps/ROOT/OurTest[-1] > poc–workflow-37b3fb76-fc1b-4ecc-b2da-00c12
4bd9297:/www/avm_webapps/ROOT/OurTest[-1]
19:58:17,889 User:admin DEBUG [hibernate.util.JDBCExceptionReporter] could not execute update query [update avm_nodes set vers=vers+1, store_new_id=null where store_new_i
d=?]
java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3515)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3447)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1951)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2101)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2554)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1761)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2046)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1964)
        at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1949)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:102)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:102)
        at org.hibernate.hql.ast.exec.BasicExecutor.execute(BasicExecutor.java:75)
        at org.hibernate.hql.ast.QueryTranslatorImpl.executeUpdate(QueryTranslatorImpl.java:396)
        at org.hibernate.engine.query.HQLQueryPlan.performExecuteUpdate(HQLQueryPlan.java:259)
        at org.hibernate.impl.SessionImpl.executeUpdate(SessionImpl.java:1141)
        at org.hibernate.impl.QueryImpl.executeUpdate(QueryImpl.java:94)
        at org.alfresco.repo.avm.hibernate.AVMNodeDAOHibernate.clearNewInStore(AVMNodeDAOHibernate.java:301)
        at org.alfresco.repo.avm.AVMStoreImpl.createSnapshot(AVMStoreImpl.java:262)
        at org.alfresco.repo.avm.AVMRepository.createSnapshot(AVMRepository.java:897)
        at org.alfresco.repo.avm.AVMServiceImpl.createSnapshot(AVMServiceImpl.java:628)
        at org.alfresco.repo.avm.MultiTAVMService.createSnapshot(MultiTAVMService.java:145)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at org.alfresco.repo.transaction.CheckTransactionAdvice.invoke(CheckTransactionAdvice.java:52)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.alfresco.repo.transaction.SingleEntryTransactionResourceInterceptor.invokeInternal(SingleEntryTransactionResourceInterceptor.java:163)
        at org.alfresco.repo.transaction.SingleEntryTransactionResourceInterceptor.invoke(SingleEntryTransactionResourceInterceptor.java:138)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy8.createSnapshot(Unknown Source)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at org.alfresco.repo.search.AVMSnapShotTriggeredIndexingMethodInterceptor.invoke(AVMSnapShotTriggeredIndexingMethodInterceptor.java:93)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy8.createSnapshot(Unknown Source)
        at org.alfresco.repo.avm.AVMSyncServiceImpl.update(AVMSyncServiceImpl.java:439)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at org.alfresco.repo.transaction.CheckTransactionAdvice.invoke(CheckTransactionAdvice.java:52)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.alfresco.repo.transaction.RetryingTransactionAdvice$1.execute(RetryingTransactionAdvice.java:70)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:326)
        at org.alfresco.repo.transaction.RetryingTransactionAdvice.invoke(RetryingTransactionAdvice.java:73)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy42.update(Unknown Source)
        at org.alfresco.wcm.sandbox.SandboxServiceImpl.createWorkflowSandbox(SandboxServiceImpl.java:769)
        at org.alfresco.wcm.sandbox.SandboxServiceImpl$3.execute(SandboxServiceImpl.java:650)
        at org.alfresco.wcm.sandbox.SandboxServiceImpl$3.execute(SandboxServiceImpl.java:646)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:326)
        at org.alfresco.wcm.sandbox.SandboxServiceImpl.submitViaWorkflow(SandboxServiceImpl.java:655)
        at org.alfresco.wcm.sandbox.SandboxServiceImpl.submitListAssets(SandboxServiceImpl.java:585)
        at org.alfresco.wcm.sandbox.SandboxServiceImpl.submitList(SandboxServiceImpl.java:561)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:304)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
        at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:40)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:49)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.alfresco.repo.audit.AuditComponentImpl.audit(AuditComponentImpl.java:275)
        at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:69)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy89.submitList(Unknown Source)
        at org.alfresco.wcm.sandbox.script.Sandbox.submit(Sandbox.java:155)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.mozilla.javascript.MemberBox.invoke(MemberBox.java:155)
        at org.mozilla.javascript.NativeJavaMethod.call(NativeJavaMethod.java:243)
        at org.mozilla.javascript.Interpreter.interpretLoop(Interpreter.java:3237)
        at org.mozilla.javascript.Interpreter.interpret(Interpreter.java:2394)
        at org.mozilla.javascript.InterpretedFunction.call(InterpretedFunction.java:162)
        at org.mozilla.javascript.ContextFactory.doTopCall(ContextFactory.java:393)
        at org.mozilla.javascript.ScriptRuntime.doTopCall(ScriptRuntime.java:2834)
        at org.mozilla.javascript.InterpretedFunction.exec(InterpretedFunction.java:173)
        at org.alfresco.repo.jscript.RhinoScriptProcessor.executeScriptImpl(RhinoScriptProcessor.java:457)
        at org.alfresco.repo.jscript.RhinoScriptProcessor.execute(RhinoScriptProcessor.java:174)
        at org.alfresco.repo.processor.ScriptServiceImpl.executeScript(ScriptServiceImpl.java:274)
        at org.alfresco.repo.web.scripts.RepositoryScriptProcessor.executeScript(RepositoryScriptProcessor.java:108)
        at org.alfresco.web.scripts.AbstractWebScript.executeScript(AbstractWebScript.java:819)
        at org.alfresco.web.scripts.DeclarativeWebScript.execute(DeclarativeWebScript.java:90)
        at org.alfresco.repo.web.scripts.RepositoryContainer$2.execute(RepositoryContainer.java:357)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:326)
        at org.alfresco.repo.web.scripts.RepositoryContainer.transactionedExecute(RepositoryContainer.java:407)
        at org.alfresco.repo.web.scripts.RepositoryContainer.transactionedExecuteAs(RepositoryContainer.java:424)
        at org.alfresco.repo.web.scripts.RepositoryContainer.executeScript(RepositoryContainer.java:288)
        at org.alfresco.web.scripts.AbstractRuntime.executeScript(AbstractRuntime.java:262)
        at org.alfresco.web.scripts.AbstractRuntime.executeScript(AbstractRuntime.java:139)
        at org.alfresco.web.scripts.servlet.WebScriptServlet.service(WebScriptServlet.java:122)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454)
        at java.lang.Thread.run(Thread.java:619)
19:58:20,237 User:admin WARN  [hibernate.util.JDBCExceptionReporter] SQL Error: 1205, SQLState: 41000
19:58:20,250 User:admin ERROR [hibernate.util.JDBCExceptionReporter] Lock wait timeout exceeded; try restarting transaction

Outcomes