2 Replies Latest reply on May 20, 2018 8:55 AM by hasithajayan

    Replication timeout for [server]

    hasithajayan
    hasithajayan May 18, 2018 10:17 AM

      Hi,

       

      I am using Wildfly 10.1.0.final. I have setup cluster and domain which has master server and two slaves. I have followed guide (Clustering and Domain Setup Walkthrough - WildFly 10 - Project Documentation Editor ). Everything is work fine. My problem is when i give high load to the server using performance testing tool (JMeater) simulating (300-500) concurrent users i got following errors. I extracted those errors from three servers log files.

       

      2018-05-17 07:42:57,299 ERROR [io.undertow.request] (default task-10) UT005023: Exception handling request to /municipality/VAADIN/themes/Municipality/img/comment-icon.svg: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key SessionCreationMetaDataKey(3K66vPCSeHkZQZRpBgwv6m8RKw5kkXO7bdh5trcC) and requestor GlobalTransaction:<slave2:server-three-slave>:26730:local. Lock is held by GlobalTransaction:<slave1:server-three-slave>:37184:remote

      at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:238)

      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAndRecord(AbstractLockingInterceptor.java:193)

      at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockKey(AbstractTxLockingInterceptor.java:193)

      at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockOrRegisterBackupLock(AbstractTxLockingInterceptor.java:116)

      at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:71)

      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:80)

      at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:43)

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)

      at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:346)

      at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:331)

      at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:43)

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)

      at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113)

      at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)

      at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:43)

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)

      at org.infinispan.statetransfer.StateTransferInterceptor.visitReadCommand(StateTransferInterceptor.java:177)

      at org.infinispan.statetransfer.StateTransferInterceptor.visitGetKeyValueCommand(StateTransferInterceptor.java:154)

      at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:43)

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)

      at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:114)

      at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:83)

      at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)

      at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:43)

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99)

      at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113)

      at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:85)

      at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:43)

      at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:335)

      at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:411)

      at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:443)

      at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:286)

      at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:70)

      at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:60)

      at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:36)

      at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)

      at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:38)

      at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:233)

      at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:148)

      at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:772)

      at io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:370)

      at org.jboss.weld.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)

      at org.jboss.weld.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:234)

      at org.jboss.weld.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)

      at io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)

      at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)

      at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)

      at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)

      at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)

      at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)

      at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)

      at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)

      at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)

      at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)

      at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:805)

      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

      at java.lang.Thread.run(Thread.java:748)

       

      -------------------------------------------------------------------------------------------------------------------------------------

       

      2018-05-17 07:41:25,862 ERROR [io.undertow.request] (default task-6) UT005023: Exception handling request to /municipality/VAADIN/themes/Municipality/img/comment-icon.svg: org.infinispan.util.concurrent.TimeoutException: Replication timeout for slave2:server-three-slave

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:801)

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$1(JGroupsTransport.java:642)

      at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602)

      at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)

      at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)

      at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962)

      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:47)

      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:16)

      at java.util.concurrent.FutureTask.run(FutureTask.java:266)

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

      at java.lang.Thread.run(Thread.java:748)

       

      ---------------------------------------------------------------------------------------------------------------------------------

       

      2018-05-17 07:41:49,805 ERROR [io.undertow.request] (default task-17) UT005023: Exception handling request to /municipality/VAADIN/themes/Municipality/img/comment-icon.svg: org.infinispan.commons.CacheException: javax.transaction.SystemException: Unable to rollback transaction

      at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:74)

      at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:156)

      at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:772)

      at io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:370)

      at org.jboss.weld.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)

      at org.jboss.weld.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:234)

      at org.jboss.weld.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)

      at io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)

      at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)

      at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)

      at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)

      at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)

      at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)

      at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

      at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)

      at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)

      at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)

      at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)

      at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:805)

      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

      at java.lang.Thread.run(Thread.java:748)

      Caused by: javax.transaction.SystemException: Unable to rollback transaction

      at org.infinispan.transaction.tm.DummyTransaction.rollback(DummyTransaction.java:131)

      at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:69)

      ... 26 more

      Caused by: javax.transaction.HeuristicMixedException

      at org.infinispan.transaction.tm.DummyTransaction.finishResource(DummyTransaction.java:439)

      at org.infinispan.transaction.tm.DummyTransaction.rollbackResources(DummyTransaction.java:459)

      at org.infinispan.transaction.tm.DummyTransaction.runCommit(DummyTransaction.java:318)

      at org.infinispan.transaction.tm.DummyTransaction.rollback(DummyTransaction.java:128)

      ... 27 more

      Caused by: javax.transaction.xa.XAException

      at org.infinispan.transaction.impl.TransactionCoordinator.rollback(TransactionCoordinator.java:182)

      at org.infinispan.transaction.xa.TransactionXaAdapter.rollback(TransactionXaAdapter.java:127)

      at org.infinispan.transaction.tm.DummyTransaction.finishResource(DummyTransaction.java:406)

      ... 30 more

      Caused by: org.infinispan.util.concurrent.TimeoutException: Replication timeout for slave2:server-three-slave

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:801)

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$1(JGroupsTransport.java:642)

      at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602)

      at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)

      at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)

      at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962)

      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:47)

      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:16)

      at java.util.concurrent.FutureTask.run(FutureTask.java:266)

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

      ... 3 more

       

      I would like to know what happen here and what are the cause of this problem? Any configuration changes needs in order to work this?

       

      Thanks

      • 556 Views
      • Tags:
        • 1. Re: Replication timeout for [server]
          andey
          andey May 18, 2018 12:23 PM (in response to hasithajayan)

          The javax.transaction.HeuristicMixedException is the worst heuristic exception. It is thrown to indicate that parts of the transaction were committed, while other parts were rolled back. The transaction manager throws this exception when some recoverable resources did a heuristic commit, while other recoverable resources did a heuristic rollback.

           

          XAResource.recover calls only during designated resynchronization stage which occurs when application server is restared after crash/failure. This is a design oversight, but further explanation is beyond the scope of this solution.

           

          If XAResource.recover call against DB resource happens when transactions are in indoubt state, this transaction will be excluded from natural XA transaction flow and will stay indoubt even after commit is invoked. It can only be processed during re-synchronization stage.

           

          Disable automatic xa recovery and clean up any genuinely stuck xids in the db by hand after any crashes (or temporarily re-enable the recovery for just that, then turn it off again before resuming normal service)

          1 of 1 people found this helpful
            • Actions
          • 2. Re: Replication timeout for [server]
            hasithajayan
            hasithajayan May 20, 2018 8:55 AM (in response to andey)

            I think i found the issue. I used non XA data source for this distributed environment. When i used XA data source instead of non XA here i did't get such errors.

             

            Thanks for your support.

              • Actions