Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-11569

DistributedStreamIteratorTest.testIterationDuringInitialTransfer random failures

XMLWordPrintable

      Very similar to ISPN-11518, DistributedStreamIteratorTest.testIterationDuringInitialTransfer blocks StateProvider.startOutboundTransfer(), and with the recent non-blocking changes it also blocks the StateTransferStartCommand response, and the invocation of StateTransferLockImpl.transactionDataReceived() on the node that sent the StateTransferStartCommand.

      14:44:11,141 TRACE (non-blocking-thread-Test-NodeA-p24343-t1:[]) [StateTransferLockImpl] Signalling topology 15 is installed
      14:44:11,147 TRACE (non-blocking-thread-Test-NodeA-p24343-t1:[]) [TrianglePerCacheInboundInvocationHandler] Calling perform() on StateTransferStartCommand{topologyId=15, segments={0}, cacheName=testCache}
      14:44:11,150 TRACE (non-blocking-thread-Test-NodeA-p24343-t1:[]) [CheckPoint] Triggering event pre_invoked * 1 (available = 1, total = 1)
      14:44:11,150 TRACE (non-blocking-thread-Test-NodeA-p24343-t1:[]) [CheckPoint] Waiting for event pre_released * 1
      
      14:44:11,163 TRACE (testng-Test:[]) [JGroupsTransport] Test-NodeD sending single request 9 to Test-NodeA: InitialPublisherCommand{cacheName='testCache'}
      14:44:11,164 TRACE (jgroups-9,Test-NodeA:[]) [JGroupsTransport] Test-NodeA received request 9 from Test-NodeD: InitialPublisherCommand{cacheName='testCache'}
      14:44:11,164 TRACE (jgroups-9,Test-NodeA:[]) [StateTransferLockImpl] Waiting for transaction data for topology 15, current topology is 14
      
      14:44:31,155 WARN  (non-blocking-thread-Test-NodeA-p24343-t1:[]) [CLUSTER] ISPN000071: Caught exception when handling command StateTransferStartCommand{topologyId=15, segments={0}, cacheName=testCache}
      java.util.concurrent.TimeoutException: Timed out waiting for event pre_released
      	at org.infinispan.test.fwk.CheckPoint.awaitStrict(CheckPoint.java:50) ~[test-classes/:?]
      	at org.infinispan.test.fwk.CheckPoint.awaitStrict(CheckPoint.java:40) ~[test-classes/:?]
      	at org.infinispan.test.Mocks.lambda$blockingAnswer$0(Mocks.java:156) ~[test-classes/:?]
      	at org.mockito.internal.stubbing.StubbedInvocationMatcher.answer(StubbedInvocationMatcher.java:39) ~[mockito-core-2.27.0.jar:?]
      	at org.mockito.internal.handler.MockHandlerImpl.handle(MockHandlerImpl.java:96) ~[mockito-core-2.27.0.jar:?]
      	at org.mockito.internal.handler.NullResultGuardian.handle(NullResultGuardian.java:29) ~[mockito-core-2.27.0.jar:?]
      	at org.mockito.internal.handler.InvocationNotifierHandler.handle(InvocationNotifierHandler.java:35) ~[mockito-core-2.27.0.jar:?]
      	at org.mockito.internal.creation.bytebuddy.MockMethodInterceptor.doIntercept(MockMethodInterceptor.java:61) ~[mockito-core-2.27.0.jar:?]
      	at org.mockito.internal.creation.bytebuddy.MockMethodInterceptor.doIntercept(MockMethodInterceptor.java:49) ~[mockito-core-2.27.0.jar:?]
      	at org.mockito.internal.creation.bytebuddy.MockMethodInterceptor$DispatcherDefaultingToRealMethod.interceptAbstract(MockMethodInterceptor.java:126) ~[mockito-core-2.27.0.jar:?]
      	at org.infinispan.statetransfer.StateProvider$MockitoMock$193392642.startOutboundTransfer(Unknown Source) ~[classes/:?]
      	at org.infinispan.commands.statetransfer.StateTransferStartCommand.invokeAsync(StateTransferStartCommand.java:37) ~[classes/:?]
      	at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:115) ~[classes/:?]
      	at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:100) ~[classes/:?]
      	at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.lambda$runAsync$0(BaseBlockingRunnable.java:91) ~[classes/:?]
      	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
      	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) ~[?:?]
      	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
      	at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073) ~[?:?]
      	at org.infinispan.statetransfer.StateTransferLockImpl.notifyTopologyInstalled(StateTransferLockImpl.java:137) ~[classes/:?]
      	at org.infinispan.statetransfer.StateConsumerImpl.lambda$onTopologyUpdate$1(StateConsumerImpl.java:341) ~[classes/:?]
      	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
      	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
      	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:143) ~[?:?]
      	at org.infinispan.statetransfer.StateConsumerImpl.onTopologyUpdate(StateConsumerImpl.java:321) ~[classes/:?]
      	at org.infinispan.statetransfer.StateTransferManagerImpl.updateProviderAndConsumer(StateTransferManagerImpl.java:200) ~[classes/:?]
      	at org.infinispan.statetransfer.StateTransferManagerImpl.lambda$doTopologyUpdate$0(StateTransferManagerImpl.java:188) ~[classes/:?]
      	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
      	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
      	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:143) ~[?:?]
      	at org.infinispan.statetransfer.StateTransferManagerImpl.doTopologyUpdate(StateTransferManagerImpl.java:187) ~[classes/:?]
      	at org.infinispan.statetransfer.StateTransferManagerImpl.access$000(StateTransferManagerImpl.java:66) ~[classes/:?]
      	at org.infinispan.statetransfer.StateTransferManagerImpl$1.rebalance(StateTransferManagerImpl.java:124) ~[classes/:?]
      	at org.infinispan.topology.LocalTopologyManagerImpl.lambda$doHandleRebalance$19(LocalTopologyManagerImpl.java:578) ~[classes/:?]
      	at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
      	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
      	at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:143) ~[?:?]
      	at org.infinispan.topology.LocalTopologyManagerImpl.doHandleRebalance(LocalTopologyManagerImpl.java:574) ~[classes/:?]
      	at org.infinispan.topology.LocalTopologyManagerImpl.lambda$handleRebalance$16(LocalTopologyManagerImpl.java:532) ~[classes/:?]
      	at org.infinispan.topology.LocalTopologyManagerImpl.lambda$orderOnCache$24(LocalTopologyManagerImpl.java:737) ~[classes/:?]
      	at org.infinispan.util.concurrent.ActionSequencer.safeNonBlockingCall(ActionSequencer.java:57) [classes/:?]
      	at org.infinispan.util.concurrent.ActionSequencer.access$400(ActionSequencer.java:32) [classes/:?]
      	at org.infinispan.util.concurrent.ActionSequencer$SequenceEntry.run(ActionSequencer.java:226) [classes/:?]
      
      14:44:31,180 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.stream.DistributedStreamIteratorTest.testIterationDuringInitialTransfer[DIST_SYNC, tx=false]
      java.lang.IllegalStateException: Thread already timed out waiting for event pre_released
      	at org.infinispan.test.fwk.CheckPoint.trigger(CheckPoint.java:177) ~[test-classes/:?]
      	at org.infinispan.test.fwk.CheckPoint.triggerForever(CheckPoint.java:166) ~[test-classes/:?]
      	at org.infinispan.stream.DistributedStreamIteratorTest.testIterationDuringInitialTransfer(DistributedStreamIteratorTest.java:115) ~[test-classes/:?]
      

              dberinde@redhat.com Dan Berindei (Inactive)
              dberinde@redhat.com Dan Berindei (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: