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

    • Type: Bug
    • Status: Verified (View Workflow)
    • Priority: Critical
    • Resolution: Done
    • Affects Version/s: 7.0.0.ER7
    • Fix Version/s: 7.1.0.DR12
    • Component/s: Clustering
    • Labels:
      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.

        Gliffy Diagrams

          Attachments

            Issue Links

            cloned to

            Bug - A problem which 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 - An upcoming version that is affected by this issue cannot be released until it's addressed. A critical bug is one that crashes the application, causes loss of data or severe memory leak.
            • Closed
            is caused by

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

            • Critical - An upcoming version that is affected by this issue cannot be released until it's addressed. A critical bug is one that crashes the application, causes loss of data or severe memory leak.
            • Resolved
            is incorporated by

            Bug - A problem which 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 - An upcoming version that is affected by this issue cannot be released until it's addressed. A critical bug is one that crashes the application, causes loss of data or severe memory leak.
            • Closed

            Component Upgrade - A task tracking an update to a bundled component JBEAP-7048 Upgrade Infinispan to 8.2.5.Final

            • Major - A request that should be considered seriously but is not a show stopper.
            • Verified

              Activity

                People

                • Assignee:
                  rhusar Radoslav Husar
                  Reporter:
                  mvinkler Michal Vinkler
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  8 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: