net.sf.ehcache.constructs.blocking.LockTimeoutException: Lock timeout. Waited more than 60000ms to acquire lock for key DuraCloud Admin on blocking cache transferInfoCache

Sakai JIRA | Danny Bernstein | 1 year ago
  1. 0

    We saw this in the NYARC setup. The aitsync user had not been added to the account and then given read/write access to the nyarc archive-it space. It appears that the attempt to access the duracloud space is causing an access error which is getting caught in an infinite loop. The resolution will be to provider user feedback when the problem exists and possibly deactivate the account util the issue is fixed. The issue would be resolved by preventing the loop and providing the user with useful feedback in order to correct the problem. WARN 2015/08/05 14:33:22 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:24 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:27 [Thread-2310] (ContentIterator.java:113) [retryBuildContentList()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:33 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:33 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:34 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:36 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:39 [Thread-2310] (ContentIterator.java:113) [retryBuildContentList()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:46 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function ERROR 2015/08/05 14:33:49 [Thread-2310] (RemoteRepoImpl.java:131) [getNewResources()] - unable to resolve destination list org.duracloud.error.UnauthorizedException: Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function at org.duracloud.client.ContentStoreImpl.doGetSpace(ContentStoreImpl.java:354) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.access$200(ContentStoreImpl.java:61) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$4.retry(ContentStoreImpl.java:314) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$4.retry(ContentStoreImpl.java:310) ~[storeclient-3.3.0.jar:na] at org.duracloud.common.retry.Retrier.execute(Retrier.java:100) ~[common-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.execute(ContentStoreImpl.java:222) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.getSpace(ContentStoreImpl.java:310) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.buildContentList(ContentIterator.java:122) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.retryBuildContentList(ContentIterator.java:110) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.<init>(ContentIterator.java:59) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.<init>(ContentIterator.java:46) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$3.retry(ContentStoreImpl.java:296) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$3.retry(ContentStoreImpl.java:292) ~[storeclient-3.3.0.jar:na] at org.duracloud.common.retry.Retrier.execute(Retrier.java:100) ~[common-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.execute(ContentStoreImpl.java:222) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.getSpaceContents(ContentStoreImpl.java:292) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.getSpaceContents(ContentStoreImpl.java:281) ~[storeclient-3.3.0.jar:na] at org.duracloud.aitsync.repo.RemoteRepoImpl.removeIfAlreadyTransferred(RemoteRepoImpl.java:149) ~[RemoteRepoImpl.class:na] at org.duracloud.aitsync.repo.RemoteRepoImpl.getNewResources(RemoteRepoImpl.java:128) ~[RemoteRepoImpl.class:na] at org.duracloud.aitsync.watch.RepoWatcherImpl$CheckForNewResourcesThread.doCheck(RepoWatcherImpl.java:180) [RepoWatcherImpl$CheckForNewResourcesThread.class:na] at org.duracloud.aitsync.watch.RepoWatcherImpl$CheckForNewResourcesThread.run(RepoWatcherImpl.java:139) [RepoWatcherImpl$CheckForNewResourcesThread.class:na] Caused by: org.duracloud.error.UnauthorizedException: User is not authorized to perform the requested function at org.duracloud.client.ContentStoreImpl.checkResponse(ContentStoreImpl.java:960) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.doGetSpace(ContentStoreImpl.java:328) ~[storeclient-3.3.0.jar:na] ... 20 common frames omitted ERROR 2015/08/05 14:33:49 [Thread-2310] (RepoWatcherImpl.java:218) [doCheck()] - Failed to retrieve resources from org.duracloud.aitsync.repo.SourceAccountInfo@2732c492[username=DuraCloud Admin,organization=NYARC]:org.duracloud.error.UnauthorizedException: Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function ARN 2015/08/05 14:34:59 [TP-Processor16] (ContentIterator.java:113) [retryBuildContentList()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function net.sf.ehcache.constructs.blocking.LockTimeoutException: Lock timeout. Waited more than 60000ms to acquire lock for key DuraCloud Admin on blocking cache transferInfoCache at net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey(BlockingCache.java:190) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:158) at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get(SelfPopulatingCache.java:68) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:318) at org.duracloud.aitsync.accountinfo.AccountInfoManagerImpl.getTransferInfo(AccountInfoManagerImpl.java:170) at org.duracloud.aitsync.controller.AccountInfoController.getStatus(AccountInfoController.java:75) at sun.reflect.GeneratedMethodAccessor122.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:215) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:749)

    Sakai JIRA | 1 year ago | Danny Bernstein
    net.sf.ehcache.constructs.blocking.LockTimeoutException: Lock timeout. Waited more than 60000ms to acquire lock for key DuraCloud Admin on blocking cache transferInfoCache
  2. 0

    We saw this in the NYARC setup. The aitsync user had not been added to the account and then given read/write access to the nyarc archive-it space. It appears that the attempt to access the duracloud space is causing an access error which is getting caught in an infinite loop. The resolution will be to provider user feedback when the problem exists and possibly deactivate the account util the issue is fixed. The issue would be resolved by preventing the loop and providing the user with useful feedback in order to correct the problem. WARN 2015/08/05 14:33:22 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:24 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:27 [Thread-2310] (ContentIterator.java:113) [retryBuildContentList()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:33 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:33 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:34 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:36 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:39 [Thread-2310] (ContentIterator.java:113) [retryBuildContentList()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function WARN 2015/08/05 14:33:46 [Thread-2310] (ContentStoreImpl.java:100) [handle()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function ERROR 2015/08/05 14:33:49 [Thread-2310] (RemoteRepoImpl.java:131) [getNewResources()] - unable to resolve destination list org.duracloud.error.UnauthorizedException: Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function at org.duracloud.client.ContentStoreImpl.doGetSpace(ContentStoreImpl.java:354) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.access$200(ContentStoreImpl.java:61) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$4.retry(ContentStoreImpl.java:314) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$4.retry(ContentStoreImpl.java:310) ~[storeclient-3.3.0.jar:na] at org.duracloud.common.retry.Retrier.execute(Retrier.java:100) ~[common-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.execute(ContentStoreImpl.java:222) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.getSpace(ContentStoreImpl.java:310) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.buildContentList(ContentIterator.java:122) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.retryBuildContentList(ContentIterator.java:110) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.<init>(ContentIterator.java:59) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentIterator.<init>(ContentIterator.java:46) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$3.retry(ContentStoreImpl.java:296) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl$3.retry(ContentStoreImpl.java:292) ~[storeclient-3.3.0.jar:na] at org.duracloud.common.retry.Retrier.execute(Retrier.java:100) ~[common-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.execute(ContentStoreImpl.java:222) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.getSpaceContents(ContentStoreImpl.java:292) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.getSpaceContents(ContentStoreImpl.java:281) ~[storeclient-3.3.0.jar:na] at org.duracloud.aitsync.repo.RemoteRepoImpl.removeIfAlreadyTransferred(RemoteRepoImpl.java:149) ~[RemoteRepoImpl.class:na] at org.duracloud.aitsync.repo.RemoteRepoImpl.getNewResources(RemoteRepoImpl.java:128) ~[RemoteRepoImpl.class:na] at org.duracloud.aitsync.watch.RepoWatcherImpl$CheckForNewResourcesThread.doCheck(RepoWatcherImpl.java:180) [RepoWatcherImpl$CheckForNewResourcesThread.class:na] at org.duracloud.aitsync.watch.RepoWatcherImpl$CheckForNewResourcesThread.run(RepoWatcherImpl.java:139) [RepoWatcherImpl$CheckForNewResourcesThread.class:na] Caused by: org.duracloud.error.UnauthorizedException: User is not authorized to perform the requested function at org.duracloud.client.ContentStoreImpl.checkResponse(ContentStoreImpl.java:960) ~[storeclient-3.3.0.jar:na] at org.duracloud.client.ContentStoreImpl.doGetSpace(ContentStoreImpl.java:328) ~[storeclient-3.3.0.jar:na] ... 20 common frames omitted ERROR 2015/08/05 14:33:49 [Thread-2310] (RepoWatcherImpl.java:218) [doCheck()] - Failed to retrieve resources from org.duracloud.aitsync.repo.SourceAccountInfo@2732c492[username=DuraCloud Admin,organization=NYARC]:org.duracloud.error.UnauthorizedException: Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function ARN 2015/08/05 14:34:59 [TP-Processor16] (ContentIterator.java:113) [retryBuildContentList()] - Error attempting to get space 'archive-it' due to: User is not authorized to perform the requested function net.sf.ehcache.constructs.blocking.LockTimeoutException: Lock timeout. Waited more than 60000ms to acquire lock for key DuraCloud Admin on blocking cache transferInfoCache at net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey(BlockingCache.java:190) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:158) at net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get(SelfPopulatingCache.java:68) at net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:318) at org.duracloud.aitsync.accountinfo.AccountInfoManagerImpl.getTransferInfo(AccountInfoManagerImpl.java:170) at org.duracloud.aitsync.controller.AccountInfoController.getStatus(AccountInfoController.java:75) at sun.reflect.GeneratedMethodAccessor122.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:601) at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:215) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:749)

    Sakai JIRA | 1 year ago | Danny Bernstein
    net.sf.ehcache.constructs.blocking.LockTimeoutException: Lock timeout. Waited more than 60000ms to acquire lock for key DuraCloud Admin on blocking cache transferInfoCache

    Root Cause Analysis

    1. net.sf.ehcache.constructs.blocking.LockTimeoutException

      Lock timeout. Waited more than 60000ms to acquire lock for key DuraCloud Admin on blocking cache transferInfoCache

      at net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey()
    2. Ehcache
      BlockingCache.get
      1. net.sf.ehcache.constructs.blocking.BlockingCache.acquiredLockForKey(BlockingCache.java:190)
      2. net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:158)
      3. net.sf.ehcache.constructs.blocking.SelfPopulatingCache.get(SelfPopulatingCache.java:68)
      4. net.sf.ehcache.constructs.blocking.BlockingCache.get(BlockingCache.java:318)
      4 frames
    3. org.duracloud.aitsync
      AccountInfoController.getStatus
      1. org.duracloud.aitsync.accountinfo.AccountInfoManagerImpl.getTransferInfo(AccountInfoManagerImpl.java:170)
      2. org.duracloud.aitsync.controller.AccountInfoController.getStatus(AccountInfoController.java:75)
      2 frames
    4. Java RT
      Method.invoke
      1. sun.reflect.GeneratedMethodAccessor122.invoke(Unknown Source)
      2. sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      3. java.lang.reflect.Method.invoke(Method.java:601)
      3 frames
    5. Spring
      InvocableHandlerMethod.invokeForRequest
      1. org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:215)
      2. org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132)
      2 frames
    6. Spring MVC
      RequestMappingHandlerAdapter.invokeHandleMethod
      1. org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
      2. org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:749)
      2 frames