[MNT-16272] User usages prevent some CMIS sessions from starting under load Created: 10-May-16  Updated: 20-Jul-16  Resolved: 03-Jun-16

Status: Closed
Project: Service Packs and Hot Fixes
Component/s: Benchmarking, CMIS, User Authorisation
Affects Version/s: 5.1.1
Fix Version/s: 5.1.1

Type: Bug
Reporter: Derek Hulley [X] (Inactive) Assignee: Closed Bugs (Inactive)
Resolution: Fixed Votes: 0
Labels: rn511
Remaining Estimate: 0 minutes
Time Spent: 2 days, 2 hours
Original Estimate: Not Specified
Environment:

Alfresco Enterprise v5.1.1
(r126277-b96) schema 9030
BM Lab 4xAlfresco cluster


Issue Links:
Related
Bug Priority:
Category 1
Build Location: https://releases.alfresco.com/Enterprise-5.1/5.1.1/5.1.1/build-00138/ALL/
Cloud or Enterprise: Enterprise Only

 Description   

When running a mildly concurrent load test that initiates CMIS sessions, the "lock taken by another process" is causing a failure rate in the region of 33%.

The test being run is the doc-workflow running against a 4 node Alfresco cluster.

To Reproduce:

  1. Run the Enterprise Signup Test to create 5000 users.
  2. Run the doc-workflow test with 2000 sessions

Actual:

  • Errors as below

Expected:

  • No concurrency issues when authenticating users
2016-05-09 19:17:08,901 ERROR [org.springframework.extensions.webscripts.AbstractRuntime] [ajp-apr-8009-exec-1] Exception from executeScript - redirecting to status template error: 04092914 Failed to release lock '{http://www.alfresco.org/model/system/1.0}repousagecomponent.users' using token '9766aaff-ab39-47df-b089-2290af15deed'.  The lock has expired and been taken by another process.
org.alfresco.repo.lock.LockAcquisitionException: 04092914 Failed to release lock '{http://www.alfresco.org/model/system/1.0}repousagecomponent.users' using token '9766aaff-ab39-47df-b089-2290af15deed'.  The lock has expired and been taken by another process.
        at org.alfresco.repo.domain.locks.AbstractLockDAOImpl.updateLocks(AbstractLockDAOImpl.java:244)
        at org.alfresco.repo.domain.locks.AbstractLockDAOImpl.releaseLock(AbstractLockDAOImpl.java:182)
        at org.alfresco.repo.lock.JobLockServiceImpl$3.execute(JobLockServiceImpl.java:459)
        at org.alfresco.repo.lock.JobLockServiceImpl$3.execute(JobLockServiceImpl.java:1)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:464)
        at org.alfresco.repo.lock.JobLockServiceImpl.releaseLock(JobLockServiceImpl.java:462)
        at org.alfresco.enterprise.repo.usage.EnterpriseRepoUsageComponentImpl.updateUsers(EnterpriseRepoUsageComponentImpl.java:297)
        at org.alfresco.enterprise.repo.usage.EnterpriseRepoUsageComponentImpl.updateUsage(EnterpriseRepoUsageComponentImpl.java:246)
        at org.alfresco.enterprise.repo.usage.EnterpriseRepoUsageComponentImpl.updateUsage(EnterpriseRepoUsageComponentImpl.java:218)
        at org.alfresco.repo.admin.RepoAdminServiceImpl.updateUsage(RepoAdminServiceImpl.java:886)
        at org.alfresco.enterprise.repo.authorization.AuthorizationServiceImpl$2.doWork(AuthorizationServiceImpl.java:335)
        at org.alfresco.enterprise.repo.authorization.AuthorizationServiceImpl$2.doWork(AuthorizationServiceImpl.java:332)
        at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:555)
        at org.alfresco.enterprise.repo.authorization.AuthorizationServiceImpl.authorize(AuthorizationServiceImpl.java:331)
        at org.alfresco.enterprise.repo.authorization.AuthorizationInterceptor$2$1.doWork(AuthorizationInterceptor.java:150)
        at org.alfresco.enterprise.repo.authorization.AuthorizationInterceptor$2$1.doWork(AuthorizationInterceptor.java:146)
        at org.alfresco.repo.security.authentication.AuthenticationUtil.runAs(AuthenticationUtil.java:555)
        at org.alfresco.repo.security.authentication.AuthenticationUtil.runAsSystem(AuthenticationUtil.java:589)
        at org.alfresco.enterprise.repo.authorization.AuthorizationInterceptor$2.execute(AuthorizationInterceptor.java:154)
        at org.alfresco.enterprise.repo.authorization.AuthorizationInterceptor$2.execute(AuthorizationInterceptor.java:142)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:464)
        at org.alfresco.enterprise.repo.authorization.AuthorizationInterceptor.checkAuthorization(AuthorizationInterceptor.java:141)
        at org.alfresco.enterprise.repo.authorization.AuthorizationInterceptor.invoke(AuthorizationInterceptor.java:70)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at com.sun.proxy.$Proxy232.authenticate(Unknown Source)
        at org.alfresco.repo.security.authentication.AuthenticationServiceImpl.authenticate(AuthenticationServiceImpl.java:75)
        at org.alfresco.repo.security.authentication.AbstractChainingAuthenticationService.authenticate(AbstractChainingAuthenticationService.java:202)
        at sun.reflect.GeneratedMethodAccessor945.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at net.sf.acegisecurity.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:80)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.alfresco.repo.security.permissions.impl.ExceptionTranslatorMethodInterceptor.invoke(ExceptionTranslatorMethodInterceptor.java:53)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.alfresco.repo.audit.AuditMethodInterceptor.invoke(AuditMethodInterceptor.java:166)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at com.sun.proxy.$Proxy81.authenticate(Unknown Source)
        at org.alfresco.repo.web.scripts.servlet.BasicHttpAuthenticatorFactory$BasicHttpAuthenticator.authenticate(BasicHttpAuthenticatorFactory.java:224)
        at org.alfresco.repo.web.scripts.servlet.RemoteUserAuthenticatorFactory$RemoteUserAuthenticator.authenticate(RemoteUserAuthenticatorFactory.java:140)
        at org.alfresco.rest.api.PublicApiAuthenticatorFactory$PublicApiAuthenticator.authenticate(PublicApiAuthenticatorFactory.java:192)
        at org.alfresco.repo.web.scripts.RepositoryContainer$2.execute(RepositoryContainer.java:385)
        at org.alfresco.repo.web.scripts.RepositoryContainer$2.execute(RepositoryContainer.java:382)
        at org.alfresco.repo.transaction.RetryingTransactionHelper.doInTransaction(RetryingTransactionHelper.java:464)
        at org.alfresco.repo.web.scripts.RepositoryContainer.executeScriptInternal(RepositoryContainer.java:424)
        at org.alfresco.repo.web.scripts.RepositoryContainer.executeScript(RepositoryContainer.java:308)
        at org.alfresco.rest.api.PublicApiRepositoryContainer.access$001(PublicApiRepositoryContainer.java:51)
        at org.alfresco.rest.api.PublicApiRepositoryContainer$1.doWork(PublicApiRepositoryContainer.java:106)
        at org.alfresco.repo.tenant.TenantUtil.runAsWork(TenantUtil.java:126)
        at org.alfresco.repo.tenant.TenantUtil.runAsTenant(TenantUtil.java:95)
        at org.alfresco.rest.api.PublicApiRepositoryContainer.executeScript(PublicApiRepositoryContainer.java:102)
        at org.springframework.extensions.webscripts.AbstractRuntime.executeScript(AbstractRuntime.java:382)
        at org.springframework.extensions.webscripts.AbstractRuntime.executeScript(AbstractRuntime.java:210)
        at org.alfresco.repo.web.scripts.TenantWebScriptServlet.service(TenantWebScriptServlet.java:82)
        at org.alfresco.rest.api.PublicApiWebScriptServlet.service(PublicApiWebScriptServlet.java:60)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.alfresco.module.aosmodule.service.ContextRootFilter.doFilter(ContextRootFilter.java:93)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.alfresco.repo.web.filter.beans.NullFilter.doFilter(NullFilter.java:75)
        at sun.reflect.GeneratedMethodAccessor974.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at org.alfresco.repo.management.subsystems.ChainingSubsystemProxyFactory$1.invoke(ChainingSubsystemProxyFactory.java:132)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at com.sun.proxy.$Proxy311.doFilter(Unknown Source)
        at org.alfresco.repo.web.filter.beans.BeanProxyFilter.doFilter(BeanProxyFilter.java:89)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.alfresco.web.app.servlet.GlobalLocalizationFilter.doFilter(GlobalLocalizationFilter.java:68)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
        at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:188)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
        at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2466)
        at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2455)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:745)

Generated at Sun Mar 07 18:28:25 GMT 2021 using Jira 7.13.15#713015-sha1:7c5ddd2c3e1709974ae9c48c17df8edd3919fe2c.