[jboss-jira] [JBoss JIRA] (WFLY-9936) TimeoutException: Could not acquire lock on SessionCreationMetaDataKey
Paul Ferraro (Jira)
issues at jboss.org
Thu Apr 4 15:18:03 EDT 2019
[ https://issues.jboss.org/browse/WFLY-9936?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Paul Ferraro closed WFLY-9936.
------------------------------
Resolution: Explained
This can happen under high load.
> TimeoutException: Could not acquire lock on SessionCreationMetaDataKey
> ----------------------------------------------------------------------
>
> Key: WFLY-9936
> URL: https://issues.jboss.org/browse/WFLY-9936
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Affects Versions: 12.0.0.Beta1
> Reporter: Michal Vinkler
> Assignee: Paul Ferraro
> Priority: Major
>
> Seen during failover testing in scenario: failover-http-session-shutdown-dist-sync
> The server perf21 logged 12 times this error:
> {code}
> [JBossINF] [0m[31m12:59:39,711 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (default task-16) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on SessionCreationMetaDataKey(4O0iDN62dBiJjhT8UvI9vNozBNrM4hX7FpUb9KEB) in behalf of transaction GlobalTx:perf21:120972. Current owner GlobalTx:perf18:59049.
> [JBossINF] at org.infinispan.util.concurrent.locks.impl.DefaultPendingLockManager.timeout(DefaultPendingLockManager.java:262)
> [JBossINF] at org.infinispan.util.concurrent.locks.impl.DefaultPendingLockManager.checkForPendingLock(DefaultPendingLockManager.java:230)
> [JBossINF] at org.infinispan.util.concurrent.locks.impl.DefaultPendingLockManager.awaitPendingTransactionsForKey(DefaultPendingLockManager.java:129)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockKey(AbstractTxLockingInterceptor.java:159)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockOrRegisterBackupLock(AbstractTxLockingInterceptor.java:83)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireLocalLock(PessimisticLockingInterceptor.java:93)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:70)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:110)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
> [JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:374)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
> [JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:189)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommand(BaseStateTransferInterceptor.java:191)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.visitGetKeyValueCommand(BaseStateTransferInterceptor.java:174)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:127)
> [JBossINF] at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:96)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:60)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitGetKeyValueCommand(DDAsyncInterceptor.java:106)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
> [JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248)
> [JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:500)
> [JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:495)
> [JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
> [JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:637)
> [JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:74)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:64)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:36)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:60)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:38)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:191)
> [JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:176)
> [JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
> [JBossINF] at io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:414)
> [JBossINF] at org.jboss.weld.module.web.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
> [JBossINF] at org.jboss.weld.module.web.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:241)
> [JBossINF] at org.jboss.weld.module.web.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
> [JBossINF] at io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
> [JBossINF] at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
> [JBossINF] at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
> [JBossINF] at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
> [JBossINF] at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
> [JBossINF] at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> {code}
> Followed immediately by
> {code}
> [JBossINF] [0m[31m12:59:39,719 ERROR [io.undertow.request] (default task-16) UT005023: Exception handling request to /clusterbench/session: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on SessionCreationMetaDataKey(4O0iDN62dBiJjhT8UvI9vNozBNrM4hX7FpUb9KEB) in behalf of transaction GlobalTx:perf21:120972. Current owner GlobalTx:perf18:59049.
> [JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
> [JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:500)
> [JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:495)
> [JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
> [JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:637)
> [JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:74)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:64)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:36)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:60)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:38)
> [JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:191)
> [JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:176)
> [JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
> [JBossINF] at io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:414)
> [JBossINF] at org.jboss.weld.module.web.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
> [JBossINF] at org.jboss.weld.module.web.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:241)
> [JBossINF] at org.jboss.weld.module.web.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
> [JBossINF] at io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
> [JBossINF] at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
> [JBossINF] at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
> [JBossINF] at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
> [JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
> [JBossINF] at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
> [JBossINF] at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on SessionCreationMetaDataKey(4O0iDN62dBiJjhT8UvI9vNozBNrM4hX7FpUb9KEB) in behalf of transaction GlobalTx:perf21:120972. Current owner GlobalTx:perf18:59049.
> [JBossINF] at org.infinispan.util.concurrent.locks.impl.DefaultPendingLockManager.timeout(DefaultPendingLockManager.java:262)
> [JBossINF] at org.infinispan.util.concurrent.locks.impl.DefaultPendingLockManager.checkForPendingLock(DefaultPendingLockManager.java:230)
> [JBossINF] at org.infinispan.util.concurrent.locks.impl.DefaultPendingLockManager.awaitPendingTransactionsForKey(DefaultPendingLockManager.java:129)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockKey(AbstractTxLockingInterceptor.java:159)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockOrRegisterBackupLock(AbstractTxLockingInterceptor.java:83)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireLocalLock(PessimisticLockingInterceptor.java:93)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:70)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:110)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
> [JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:374)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
> [JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:189)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommand(BaseStateTransferInterceptor.java:191)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.visitGetKeyValueCommand(BaseStateTransferInterceptor.java:174)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:127)
> [JBossINF] at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:96)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:60)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitGetKeyValueCommand(DDAsyncInterceptor.java:106)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:38)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
> [JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248)
> [JBossINF] ... 38 more
> {code}
> There is no obvious connection to a topology change (perf20 was shut down 18 seconds before first occurence).
> Client logged sampling error at the same time:
> {code}
> 2018/02/16 12:59:39:717 EST [WARN ][Runner - 1759] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Invalid response code: 500 Content: <html><head><title>Error</title></head><body>Internal Server Error</body></html>>
> org.jboss.smartfrog.loaddriver.RequestProcessingException: Invalid response code: 500 Content: <html><head><title>Error</title></head><body>Internal Server Error</body></html>
> at org.jboss.smartfrog.loaddriver.http.HttpRequestProcessorFactoryImpl$HttpRequestProcessor.processRequest(HttpRequestProcessorFactoryImpl.java:164)
> at org.jboss.smartfrog.loaddriver.CompoundRequestProcessorFactoryImpl$CompoundRequestProcessor.processRequest(CompoundRequestProcessorFactoryImpl.java:52)
> at org.jboss.smartfrog.loaddriver.Runner.run(Runner.java:103)
> at java.lang.Thread.run(Thread.java:748)
> {code}
> Links:
> perf21: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync/26/console-perf21/
> perf17: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync/26/console-perf17/
--
This message was sent by Atlassian Jira
(v7.12.1#712002)
More information about the jboss-jira
mailing list