DistributedStreamIteratorTest.testIterationDuringInitialTransfer random failures -------------------------------------------------------------------------------- Key: ISPN-11569 URL: https://issues.redhat.com/browse/ISPN-11569 Project: Infinispan Issue Type: Bug Components: Core, Streams, Test Suite Affects Versions: 11.0.0.Dev03 Reporter: Dan Berindei Assignee: Dan Berindei Priority: Major Labels: testsuite_stability Fix For: 11.0.0.Dev04 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}}. {noformat} 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/:?] {noformat}