Details
-
Bug
-
Resolution: Done
-
Major
-
12.1.4.Final, 13.0.0.Dev02
-
None
Description
When ScatteredStateConsumerImpl receives the keys of a segment, the segment is supposed to stay in the VALUE_TRANSFER state until the values are also received.
But if all the key requests (aka inbound transfers) finish before ScatteredStateConsumerImpl starts the first value transfer, the chunk counter stays at 0 and the segment goes directly into the OWNED state.
Scattered caches use null values both during value transfer and as tombstones, so a read or iteration operation will see the keys without values and ignore them.
This is only temporary: eventually the values are received and they replace the null values, even if state transfer is supposed to be over.
Found as a random failure in ScatteredStreamIteratorTest, after fixing ISPN-13134.
15:57:53,370 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [StateConsumerImpl] Received new topology for cache testCache, isRebalance = true, isMember = true, topology = CacheTopology{id=9, phase=TRANSITORY, rebalanceId=5, currentCH=ScatteredConsistentHash{ns=3, rebalanced=false, owners = (2)[Test-NodeA: 1, Test-NodeC: 1]}, pendingCH=ScatteredConsistentHash{ns=3, rebalanced=true, owners = (2)[Test-NodeA: 3, Test-NodeC: 0]}, unionCH=ScatteredConsistentHash{ns=3, rebalanced=false, owners = (2)[Test-NodeA: 3, Test-NodeC: 0]}, actualMembers=[Test-NodeA, Test-NodeC], persistentUUIDs=[8ada3e41-5429-4117-841f-33f855092f6b, 13437aff-05a6-401c-935b-aacc91ab14d2]}
15:57:53,370 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [ScatteredVersionManagerImpl] Node Test-NodeA blocks access to segment 1
15:57:53,370 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [ScatteredStateConsumerImpl] Revoking all segments, chunk counter reset to 0
15:57:53,371 TRACE (jgroups-10,Test-NodeA:[]) [ScatteredVersionManagerImpl] Node Test-NodeA, segment 1 expects key transfer
15:57:53,376 TRACE (jgroups-10,Test-NodeA:[testCache]) [AbstractInternalDataContainer] Store MetadataImmortalCacheEntry{key=MagicKey{178/DC144FBD/1@Test-NodeB}, value=null, internalMetadata=null, metadata=RemoteMetadata{address=Test-NodeC, version=SimpleClusteredVersion{topologyId=7, version=1}}} in container
15:57:53,378 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [ClusterPublisherManagerImpl] Segments {1} not completed - retrying
15:57:53,378 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [ClusterPublisherManagerImpl] Targets determined to be {Test-NodeA={1}} on topology 9
15:57:53,379 TRACE (jgroups-10,Test-NodeA:[testCache]) [ScatteredVersionManagerImpl] Node Test-NodeA, segment 1 has all keys in, expects value transfer
15:57:53,379 TRACE (jgroups-10,Test-NodeA:[testCache]) [ScatteredStateConsumerImpl] Retrieving values, chunk counter is 1
15:57:53,381 TRACE (jgroups-10,Test-NodeA:[testCache]) [StateConsumerImpl] Removing inbound transfers from node {1-2} for segments Test-NodeC
15:57:53,381 TRACE (jgroups-10,Test-NodeA:[testCache]) [ScatteredStateConsumerImpl] Inbound transfer removed, chunk counter is 2
15:57:53,382 DEBUG (jgroups-10,Test-NodeA:[]) [StateConsumerImpl] Finished receiving of segments for cache testCache for topology 9.
15:57:53,382 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [PrefetchInterceptor] Retrieving iterator for Cache 'testCache'@Test-NodeA in topology 9, blocked segments are []
### segment 1 is now OWNED
15:57:53,382 DEBUG (jgroups-10,Test-NodeA:[]) [ScatteredVersionManagerImpl] Node Test-NodeA received values for all segments in topology 9
### finished iterating segment 1, skipping MagicKey{178/DC144FBD/1@Test-NodeB}
15:57:53,382 TRACE (non-blocking-thread-Test-NodeA-p592-t5:[]) [PublisherHandler] Completing segment 1 for Test-NodeA#159
15:57:53,384 TRACE (jgroups-14,Test-NodeA:[]) [ScatteredStateConsumerImpl] Backed up entries, chunk counter is 1
### value update
15:57:53,384 TRACE (jgroups-8,Test-NodeA:[]) [AbstractInternalDataContainer] Store MetadataImmortalCacheEntry{key=MagicKey{178/DC144FBD/1@Test-NodeB}, value=MagicKey{178/DC144FBD/1@Test-NodeB}, internalMetadata=null, metadata=EmbeddedExpirableMetadata{version=SimpleClusteredVersion{topologyId=7, version=1}, lifespan=-1, maxIdle=-1}} in container
15:57:53,384 TRACE (jgroups-8,Test-NodeA:[]) [ScatteredStateConsumerImpl] Applied values, chunk counter is 0
15:58:01,218 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.scattered.stream.ScatteredStreamIteratorTest.verifyNodeLeavesBeforeGettingData[SCATTERED_SYNC, tx=false]
java.lang.AssertionError: Entry wasn't found:MagicKey{178/DC144FBD/1@Test-NodeB}=MagicKey{178/DC144FBD/1@Test-NodeB}
at org.testng.AssertJUnit.fail(AssertJUnit.java:59) ~[testng-6.14.3.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24) ~[testng-6.14.3.jar:?]
at org.infinispan.stream.DistributedStreamIteratorTest.verifyNodeLeavesBeforeGettingData(DistributedStreamIteratorTest.java:154) ~[test-classes/:?]