Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-3946

TimeoutException: Unable to acquire lock after 15 seconds in repl-async stress tests

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Critical
    • 7.1.0.DR12
    • 7.0.0.ER7
    • Clustering
    • None

    Description

      Scenarios:
      stress-ejbservlet-repl-async
      stress-session-repl-async

      When the number of clients reaches 1600, servers start logging TimeoutExceptions (approx 500 occurrences in each server), which definitely results in client getting 500:

      [JBossINF] [0m[31m08:44:32,765 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (default task-126) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key pL7oPBPQV9X21ErUIku54-wkPMvaHTWwbknWx4OW and requestor GlobalTransaction:<perf19>:1121985:local. Lock is held by GlobalTransaction:<perf19>:1120208:local
[JBossINF] 	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236)
[JBossINF] 	at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAndRecord(AbstractLockingInterceptor.java:190)
[JBossINF] 	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockKey(AbstractTxLockingInterceptor.java:192)
[JBossINF] 	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockOrRegisterBackupLock(AbstractTxLockingInterceptor.java:113)
[JBossINF] 	at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:70)
[JBossINF] 	at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:77)
[JBossINF] 	at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
[JBossINF] 	at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:345)
[JBossINF] 	at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:330)
[JBossINF] 	at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113)
[JBossINF] 	at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)
[JBossINF] 	at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
[JBossINF] 	at org.infinispan.statetransfer.StateTransferInterceptor.visitReadCommand(StateTransferInterceptor.java:176)
[JBossINF] 	at org.infinispan.statetransfer.StateTransferInterceptor.visitGetKeyValueCommand(StateTransferInterceptor.java:153)
[JBossINF] 	at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)
[JBossINF] 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:107)
[JBossINF] 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:76)
[JBossINF] 	at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)
[JBossINF] 	at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
[JBossINF] 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)
[JBossINF] 	at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:411)
[JBossINF] 	at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:443)
[JBossINF] 	at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:286)
[JBossINF] 	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:72)
[JBossINF] 	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:62)
[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:61)
[JBossINF] 	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:40)
[JBossINF] 	at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:235)
[JBossINF] 	at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:148)
[JBossINF] 	at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:726)
[JBossINF] 	at io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:370)
[JBossINF] 	at org.jboss.weld.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
[JBossINF] 	at org.jboss.weld.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:234)
[JBossINF] 	at org.jboss.weld.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
[JBossINF] 	at io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:245)
[JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:284)
[JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:264)
[JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
[JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:175)
[JBossINF] 	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)
[JBossINF] 	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:792)
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[JBossINF] 	at java.lang.Thread.run(Thread.java:745)

      Client:

      2016/03/21 08:41:45:760 EDT [WARN ][Runner - 244] 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:163)
	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:745)

      stress-ejbservlet-repl-async
      Server link: http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-stress-ejbservlet-repl-async/12/console-perf19/
      Client link: http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-stress-ejbservlet-repl-async/12/console-perf23/

      stress-session-repl-async
      Server link: http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-stress-session-repl-async/9/console-perf18/
      Client link: http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-stress-session-repl-async/9/console-perf23/

      Performance report:
      http://download.eng.brq.redhat.com/scratch/mvinkler/reports/2016-03-24_11-27-03/stress.html

      The issue looks very similar to JBEAP-2273.

      Attachments

        Issue Links

          is caused by

          Bug - A problem that impairs or prevents the functions of the product. ISPN-7064 RPC to leaver times out instead of finishing immediately

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed
          is cloned by

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-11886 [GSS](7.0.z) TimeoutException: Unable to acquire lock after 15 seconds in repl-async stress tests

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed
          is incorporated by

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-11886 [GSS](7.0.z) TimeoutException: Unable to acquire lock after 15 seconds in repl-async stress tests

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed

          Component Upgrade - A task tracking an update to a bundled component or revision of component upstream of the project. JBEAP-7048 Upgrade Infinispan to 8.2.5.Final

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Verified

          Activity

            People

              rhn-engineering-rhusar Radoslav Husar
              mvinkler1@redhat.com Michal Vinkler
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: