AnsweredAssumed Answered

CannotAcquireLockException

Question asked by dranakan on May 11, 2011
Latest reply on May 16, 2011 by dranakan
Hello,

I have a custom rule splitting PDF file with Alfresco 32r2. All is working great.
I have updated the code to use Alfresco 3.4D but I get some problems sometime (if I start 20 times the action, 1 time there is the bug…). The rule is not executed in background.
(I'am on Redhat with Mysql Bundle)

Here the logs after bug

15:17:46,230 User:scannerusr ERROR [manageoffice.workers.NodeManager] Error adding file.
org.alfresco.service.cmr.repository.ContentIOException: 04110009 Failed to set content property on stream closure:
   node: workspace://SpacesStore/2c81aebe-83a3-4e99-9e68-bcf77d38242f
   property: {http://www.alfresco.org/model/content/1.0}content
   writer: ContentAccessor[ contentUrl=store://2011/5/11/15/16/381e155c-b20c-47da-b4d4-3401eb57bebd.bin, mimetype=application/pdf, size=513922, encoding=UTF-8, locale=en_US]
org.springframework.dao.CannotAcquireLockException: SqlMapClient operation; SQL [];
— The error occurred in alfresco/ibatis/#resource.dialect#/usage-insert-SqlMap.xml.
— The error occurred while applying a parameter map.
— Check the alfresco.usage.insert_UsageDelta-InlineParameterMap.
— Check the statement (update failed).
— Cause: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:
— The error occurred in alfresco/ibatis/#resource.dialect#/usage-insert-SqlMap.xml.
— The error occurred while applying a parameter map.
— Check the alfresco.usage.insert_UsageDelta-InlineParameterMap.
— Check the statement (update failed).
— Cause: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at org.alfresco.repo.content.ContentServiceImpl$WriteStreamListener.contentStreamClosedImpl(ContentServiceImpl.java:674)
        at org.alfresco.repo.content.AbstractContentStreamListener$1.execute(AbstractContentStreamListener.java:50)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:381)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:272)
        at org.alfresco.repo.content.AbstractContentStreamListener.contentStreamClosed(AbstractContentStreamListener.java:57)
        at org.alfresco.repo.content.AbstractContentAccessor$CallbackFileChannel.fireChannelClosed(AbstractContentAccessor.java:333)
        at org.alfresco.repo.content.AbstractContentAccessor$CallbackFileChannel.implCloseChannel(AbstractContentAccessor.java:317)
        at java.nio.channels.spi.AbstractInterruptibleChannel.close(AbstractInterruptibleChannel.java:97)
        at java.nio.channels.Channels$1.close(Channels.java:138)
        at java.io.FilterOutputStream.close(FilterOutputStream.java:143)
        at org.springframework.util.FileCopyUtils.copy(FileCopyUtils.java:126)
        at org.alfresco.repo.content.AbstractContentWriter.putContent(AbstractContentWriter.java:417)
        at ch.custom.manageoffice.workers.NodeManager.addContentToFileFromFile(NodeManager.java:557)
        at ch.custom.manageoffice.workers.NodeManager.createNode(NodeManager.java:307)
        at ch.custom.manageoffice.workers.NodeManager.writeTree(NodeManager.java:750)
        at ch.custom.manageoffice.workers.NodeManager.createDirectoriesIfNotExisted(NodeManager.java:807)
        at ch.custom.manageoffice.workers.NodeManager.writeTree(NodeManager.java:717)
        at ch.custom.manageoffice.workers.NodeManager.createDirectoriesIfNotExisted(NodeManager.java:807)
        at ch.custom.manageoffice.workers.NodeManager.writeTree(NodeManager.java:717)
        at ch.custom.manageoffice.workers.NodeManager.createDirectoriesIfNotExisted(NodeManager.java:807)
        at ch.custom.manageoffice.workers.NodeManager.writeTree(NodeManager.java:667)
        at ch.custom.manageoffice.workers.NodeManager$2.execute(NodeManager.java:1138)
        at ch.custom.manageoffice.workers.NodeManager$2.execute(NodeManager.java:1)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:381)
        at ch.custom.manageoffice.workers.NodeManager.moveFilesAndAddMetaInTransaction(NodeManager.java:1123)
        at ch.custom.manageoffice.actions.ReadBarcodesSplit.readBarcodesSplit(ReadBarcodesSplit.java:252)
        at ch.custom.manageoffice.actions.ReadBarcodesSplit.executeImpl(ReadBarcodesSplit.java:167)
        at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:133)
        at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:749)
        at org.alfresco.repo.action.executer.CompositeActionExecuter.executeImpl(CompositeActionExecuter.java:66)
        at org.alfresco.repo.action.executer.ActionExecuterAbstractBase.execute(ActionExecuterAbstractBase.java:133)
        at org.alfresco.repo.action.ActionServiceImpl.directActionExecution(ActionServiceImpl.java:749)
        at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:675)
        at org.alfresco.repo.action.ActionServiceImpl.executeActionImpl(ActionServiceImpl.java:675)
        at org.alfresco.repo.action.ActionServiceImpl.executeAction(ActionServiceImpl.java:540)
        at sun.reflect.GeneratedMethodAccessor638.invoke(Unknown Source)
        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:307)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at org.alfresco.repo.security.permissions.impl.AlwaysProceedMethodInterceptor.invoke(AlwaysProceedMethodInterceptor.java:34)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:44)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.alfresco.repo.audit.AuditMethodInterceptor.proceedWithAudit(AuditMethodInterceptor.java:217)
        at org.alfresco.repo.audit.AuditMethodInterceptor.proceed(AuditMethodInterceptor.java:184)
        at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:137)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
        at $Proxy34.executeAction(Unknown Source)
        at org.alfresco.repo.rule.RuleServiceImpl.executeRule(RuleServiceImpl.java:1165)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRule(RuleServiceImpl.java:1133)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRulesImpl(RuleServiceImpl.java:1092)
        at org.alfresco.repo.rule.RuleServiceImpl.executePendingRules(RuleServiceImpl.java:1065)
        at org.alfresco.repo.rule.RuleTransactionListener.beforeCommit(RuleTransactionListener.java:57)
        at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.doBeforeCommit(AlfrescoTransactionSupport.java:732)
        at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.doBeforeCommit(AlfrescoTransactionSupport.java:712)
        at org.alfresco.repo.transaction.AlfrescoTransactionSupport$TransactionSynchronizationImpl.beforeCommit(AlfrescoTransactionSupport.java:672)
        at org.springframework.transaction.support.TransactionSynchronizationUtils.triggerBeforeCommit(TransactionSynchronizationUtils.java:95)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:927)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:737)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:394)
        at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:472)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:403)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:253)
        at org.alfresco.filesys.alfresco.AlfrescoDiskDriver.doInWriteTransaction(AlfrescoDiskDriver.java:181)
        at org.alfresco.filesys.repo.ContentDiskDriver.closeFile(ContentDiskDriver.java:2437)
        at org.alfresco.jlan.smb.server.NTProtocolHandler.procCloseFile(NTProtocolHandler.java:1405)
        at org.alfresco.jlan.smb.server.NTProtocolHandler.runProtocol(NTProtocolHandler.java:257)
        at org.alfresco.jlan.smb.server.SMBSrvSession.runHandler(SMBSrvSession.java:1366)
        at org.alfresco.jlan.smb.server.SMBSrvSession.processPacket(SMBSrvSession.java:1458)
        at org.alfresco.jlan.smb.server.nio.NIOCIFSThreadRequest.runRequest(NIOCIFSThreadRequest.java:105)
        at org.alfresco.jlan.server.thread.ThreadRequestPool$ThreadWorker.run(ThreadRequestPool.java:153)
        at java.lang.Thread.run(Thread.java:619)
Caused by: org.springframework.dao.CannotAcquireLockException: SqlMapClient operation; SQL [];
— The error occurred in alfresco/ibatis/#resource.dialect#/usage-insert-SqlMap.xml.
— The error occurred while applying a parameter map.
— Check the alfresco.usage.insert_UsageDelta-InlineParameterMap.
— Check the statement (update failed).
— Cause: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:
— The error occurred in alfresco/ibatis/#resource.dialect#/usage-insert-SqlMap.xml.
— The error occurred while applying a parameter map.
— Check the alfresco.usage.insert_UsageDelta-InlineParameterMap.
— Check the statement (update failed).
— Cause: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:261)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
        at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:203)
        at org.springframework.orm.ibatis.SqlMapClientTemplate.insert(SqlMapClientTemplate.java:364)
        at org.alfresco.repo.domain.usage.ibatis.UsageDAOImpl.insertUsageDeltaEntity(UsageDAOImpl.java:73)
        at org.alfresco.repo.domain.usage.AbstractUsageDAOImpl.insertDelta(AbstractUsageDAOImpl.java:111)
        at org.alfresco.repo.usage.UsageServiceImpl.insertDelta(UsageServiceImpl.java:44)
        at sun.reflect.GeneratedMethodAccessor939.invoke(Unknown Source)
        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:307)
        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:202)
        at $Proxy54.insertDelta(Unknown Source)
        at org.alfresco.repo.usage.ContentUsageImpl.incrementUserUsage(ContentUsageImpl.java:459)
        at org.alfresco.repo.usage.ContentUsageImpl.onUpdateProperties(ContentUsageImpl.java:295)
        at sun.reflect.GeneratedMethodAccessor633.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.alfresco.repo.policy.JavaBehaviour$JavaMethodInvocationHandler.invoke(JavaBehaviour.java:173)
        at $Proxy11.onUpdateProperties(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor318.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.alfresco.repo.policy.PolicyFactory$MultiHandler.invoke(PolicyFactory.java:300)
        at org.alfresco.repo.policy.$Proxy209.onUpdateProperties(Unknown Source)
        at org.alfresco.repo.node.AbstractNodeServiceImpl.invokeOnUpdateProperties(AbstractNodeServiceImpl.java:407)
        at org.alfresco.repo.node.db.DbNodeServiceImpl.addAspectsAndProperties(DbNodeServiceImpl.java:542)
        at org.alfresco.repo.node.db.DbNodeServiceImpl.addAspectsAndProperties(DbNodeServiceImpl.java:439)
        at org.alfresco.repo.node.db.DbNodeServiceImpl.setProperty(DbNodeServiceImpl.java:1402)
        at sun.reflect.GeneratedMethodAccessor444.invoke(Unknown Source)
        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:307)
        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:202)
        at $Proxy7.setProperty(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor444.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.alfresco.repo.service.StoreRedirectorProxyFactory$RedirectorInvocationHandler.invoke(StoreRedirectorProxyFactory.java:215)
        at $Proxy8.setProperty(Unknown Source)
        at org.alfresco.repo.node.MLPropertyInterceptor.invoke(MLPropertyInterceptor.java:249)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:260)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.alfresco.repo.node.NodeRefPropertyMethodInterceptor.invoke(NodeRefPropertyMethodInterceptor.java:260)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
        at $Proxy7.setProperty(Unknown Source)
        at org.alfresco.repo.content.ContentServiceImpl$WriteStreamListener.contentStreamClosedImpl(ContentServiceImpl.java:654)
        … 76 more
Caused by: com.ibatis.common.jdbc.exception.NestedSQLException:
Caused by: com.ibatis.common.jdbc.exception.NestedSQLException:
— The error occurred in alfresco/ibatis/#resource.dialect#/usage-insert-SqlMap.xml.
— The error occurred while applying a parameter map.
— Check the alfresco.usage.insert_UsageDelta-InlineParameterMap.
— Check the statement (update failed).
— Cause: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeUpdate(MappedStatement.java:107)
        at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.insert(SqlMapExecutorDelegate.java:393)
        at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.insert(SqlMapSessionImpl.java:82)
        at org.springframework.orm.ibatis.SqlMapClientTemplate$8.doInSqlMapClient(SqlMapClientTemplate.java:366)
        at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:200)
        … 130 more
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1075)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3566)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3498)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1959)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2113)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568)
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2113)
        at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1364)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
        at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:169)
        at com.ibatis.sqlmap.engine.execution.SqlExecutor.executeUpdate(SqlExecutor.java:100)
        at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.sqlExecuteUpdate(MappedStatement.java:216)
        at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeUpdate(MappedStatement.java:94)
        … 134 more

here the code at ch.custom.manageoffice.workers.NodeManager.addContentToFileFromFile(NodeManager.java:557)

/**
    * Add the content of the file to the NodeRef.
    *
    * @param nodeRef
    * @param file
    * @return true if all ok
    */
   public boolean addContentToFileFromFile(NodeRef nodeRef, File file) {
      if (file != null) {
         try {
            InputStream contentStream = new FileInputStream(file);
            // Write the content of the NodeRef
            ContentWriter writer = contentService.getWriter(nodeRef,
                  ContentModel.PROP_CONTENT, true);
            writer.setMimetype(mimetypeService.guessMimetype(file
                  .getAbsolutePath()));
            writer.setEncoding(ENCODING);
            writer.putContent(contentStream);
            contentStream.close();
            return true;
         } catch (Exception e) {
            logger.error(
                  "Error adding file. The temp directory has perhaps been automaticly cleared (scheduled-jobs-context.xml)",
                  e);
         }
      }
      return false;
   }

The transaction is done like this at ch.custom.manageoffice.workers.NodeManager.moveFilesAndAddMetaInTransaction(NodeManager.java:1123)

public boolean moveFilesAndAddMetaInTransaction(
         final String directoryTMPFromLocal,
         final List<PDFFromERP> listDocumentsSplitted,
         final String modeStorage, final NodeRef destination) {
      boolean resultMoveFile = false;
      final NodeManager nodeManagerF = this;
      try {
         resultMoveFile = transactionService
               .getRetryingTransactionHelper()
               .doInTransaction(
                     new RetryingTransactionHelper.RetryingTransactionCallback<Boolean>() {
                        public Boolean execute() throws Throwable {
                           /*
                            * Move the splitted files (from tmp to
                            * Alfresco Space)
                            */
                           if (logger.isDebugEnabled()) {
                              logger.debug("Add the splitted files in Alfresco and add metadata");
                           }

                           DirectoryNode directoryNode_begin = nodeManagerF
                                 .createTree(listDocumentsSplitted,
                                       modeStorage, destination);
                           boolean successful = true;
                           if (!nodeManagerF.writeTree(
                                 directoryNode_begin,
                                 directoryTMPFromLocal + "/")) {
                              successful = false;
                           }

                           if (!successful) {
                              /*
                               * Retry and rollback if always problem
                               */
                              // throw new
                              // IllegalStateException(
                              // "Problem during moveFilesAndAddMeta");
                              // Try 1 time
                              throw new java.sql.SQLException(
                              // Try 20 times
                                    "Problem during moveFilesAndAddMeta'");
                           }
                           return true;
                        }
                     }, false, true);
      } catch (Exception e) {
         logger.error("", e);
         return false;
      }
      return resultMoveFile;
   }

What could be the problem ?

(Also on french forum : http://forums.alfresco.com/fr/viewtopic.php?f=11&t=4917&p=22484#p22484)

Outcomes