[JBoss JIRA] (ISPN-9130) GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC] random failure
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-9130?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-9130:
-------------------------------
Attachment: RehashWithSharedStoreTest_ISPN-7977_NPE_during_shutdown_20180507.log.gz
> GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC] random failure
> ---------------------------------------------------------------------------------------------
>
> Key: ISPN-9130
> URL: https://issues.jboss.org/browse/ISPN-9130
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 9.3.0.Alpha1
> Reporter: Dan Berindei
> Assignee: Radim Vansa
> Labels: testsuite_stability
> Fix For: 9.3.0.Beta1
>
> Attachments: RehashWithSharedStoreTest_ISPN-7977_NPE_during_shutdown_20180507.log.gz
>
>
> {{ScatteredDistributionInterceptor.handleWriteCommand}} sends the {{PrimaryAckCommand}} to the originator too soon. It takes care of committing the entry to the data container instead of waiting for {{EntryWrappingInterceptor}} to do it, but it doesn't do anything about the stores:
> {noformat}
> 16:02:40,630 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=GroupKey{group='test-group', key=0}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvocation:Test-NodeB-46322:3254, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [SingleKeyNonTxInvocationContext{isLocked=false, key=null, cacheEntry=null, origin=null, lockOwner=CommandInvocation:Test-NodeB-46322:3254}]
> 16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [ScatteredDistributionInterceptor] Committing entry RepeatableReadEntry(4631a022){key=GroupKey{group='test-group', key=0}, value=null, isCreated=false, isChanged=true, isRemoved=true, isExpired=false, skipLookup=true, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}}, replaced MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}
> 16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
> 16:02:40,633 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [JGroupsTransport] Test-NodeD-54637 sending command to Test-NodeB-46322: PrimaryAckCommand{id=3254, success=true, value=SimpleClusteredVersion{topologyId=5, version=40}, waitFor=[Test-NodeF-20476]}
> 16:02:40,633 TRACE (jgroups-10,Test-NodeB-46322:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedMetadata{version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
> 16:02:40,634 TRACE (jgroups-10,Test-NodeB-46322:[]) [DistCacheWriterInterceptor] Stored entry null under key GroupKey{group='test-group', key=0}
> ---
> 16:02:40,634 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6314f4e7]
> 16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6dd409f2]
> 16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [DummyInMemoryStore] Processing entries in store null with filter org.infinispan.filter.CompositeKeyFilter@196d8e49 and callback org.infinispan.interceptors.impl.CacheLoaderInterceptor$1@54df66d9
> 16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [EntryFactoryImpl] Creating new entry for key GroupKey{group='test-group', key=0}
> 16:02:40,636 TRACE (jgroups-4,Test-NodeD-54637:[]) [JGroupsTransport] Test-NodeD-54637 sending response for request 21 to Test-NodeB-46322: SuccessfulResponse([MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}])
> ---
> 16:02:40,636 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DummyInMemoryStore] Store MarshalledEntryImpl{keyBytes=null, valueBytes=null, metadataBytes=null, key=GroupKey{group='test-group', key=0}, value=null, metadata=InternalMetadataImpl{actual=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}, created=-1, lastUsed=-1}, marshaller=org.infinispan.marshall.core.GlobalMarshaller@26ecc0d1} in dummy map store@5d185974
> ---
> 16:02:40,638 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC]
> java.lang.AssertionError:
> at org.testng.AssertJUnit.fail(AssertJUnit.java:59) ~[testng-6.9.9.jar:?]
> at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24) ~[testng-6.9.9.jar:?]
> at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:33) ~[testng-6.9.9.jar:?]
> at org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence(GetGroupKeysTest.java:162) ~[test-classes/:?]
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9130) GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC] random failure
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-9130?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-9130:
-------------------------------
Description:
{{ScatteredDistributionInterceptor.handleWriteCommand}} sends the {{PrimaryAckCommand}} to the originator too soon. It takes care of committing the entry to the data container instead of waiting for {{EntryWrappingInterceptor}} to do it, but it doesn't do anything about the stores:
{noformat}
16:02:40,630 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=GroupKey{group='test-group', key=0}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvocation:Test-NodeB-46322:3254, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [SingleKeyNonTxInvocationContext{isLocked=false, key=null, cacheEntry=null, origin=null, lockOwner=CommandInvocation:Test-NodeB-46322:3254}]
16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [ScatteredDistributionInterceptor] Committing entry RepeatableReadEntry(4631a022){key=GroupKey{group='test-group', key=0}, value=null, isCreated=false, isChanged=true, isRemoved=true, isExpired=false, skipLookup=true, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}}, replaced MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}
16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
16:02:40,633 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [JGroupsTransport] Test-NodeD-54637 sending command to Test-NodeB-46322: PrimaryAckCommand{id=3254, success=true, value=SimpleClusteredVersion{topologyId=5, version=40}, waitFor=[Test-NodeF-20476]}
16:02:40,633 TRACE (jgroups-10,Test-NodeB-46322:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedMetadata{version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
16:02:40,634 TRACE (jgroups-10,Test-NodeB-46322:[]) [DistCacheWriterInterceptor] Stored entry null under key GroupKey{group='test-group', key=0}
---
16:02:40,634 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6314f4e7]
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6dd409f2]
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [DummyInMemoryStore] Processing entries in store null with filter org.infinispan.filter.CompositeKeyFilter@196d8e49 and callback org.infinispan.interceptors.impl.CacheLoaderInterceptor$1@54df66d9
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [EntryFactoryImpl] Creating new entry for key GroupKey{group='test-group', key=0}
16:02:40,636 TRACE (jgroups-4,Test-NodeD-54637:[]) [JGroupsTransport] Test-NodeD-54637 sending response for request 21 to Test-NodeB-46322: SuccessfulResponse([MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}])
---
16:02:40,636 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DummyInMemoryStore] Store MarshalledEntryImpl{keyBytes=null, valueBytes=null, metadataBytes=null, key=GroupKey{group='test-group', key=0}, value=null, metadata=InternalMetadataImpl{actual=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}, created=-1, lastUsed=-1}, marshaller=org.infinispan.marshall.core.GlobalMarshaller@26ecc0d1} in dummy map store@5d185974
---
16:02:40,638 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC]
java.lang.AssertionError:
at org.testng.AssertJUnit.fail(AssertJUnit.java:59) ~[testng-6.9.9.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24) ~[testng-6.9.9.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:33) ~[testng-6.9.9.jar:?]
at org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence(GetGroupKeysTest.java:162) ~[test-classes/:?]
{noformat}
was:
{{ScatteredDistributionInterceptor.handleWriteCommand}} sends the {{PrimaryAckCommand}} to the originator too soon. It takes care of committing the entry to the data container instead of waiting for {{EntryWrappingInterceptor}} to do it, but it doesn't do anything about the stores:
{noformat}
16:02:40,630 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=GroupKey{group='test-group', key=0}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvocation:Test-NodeB-46322:3254, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [SingleKeyNonTxInvocationContext{isLocked=false, key=null, cacheEntry=null, origin=null, lockOwner=CommandInvocation:Test-NodeB-46322:3254}]
16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [ScatteredDistributionInterceptor] Committing entry RepeatableReadEntry(4631a022){key=GroupKey{group='test-group', key=0}, value=null, isCreated=false, isChanged=true, isRemoved=true, isExpired=false, skipLookup=true, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}}, replaced MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}
16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
16:02:40,633 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [JGroupsTransport] Test-NodeD-54637 sending command to Test-NodeB-46322: PrimaryAckCommand{id=3254, success=true, value=SimpleClusteredVersion{topologyId=5, version=40}, waitFor=[Test-NodeF-20476]}
16:02:40,633 TRACE (jgroups-10,Test-NodeB-46322:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedMetadata{version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
16:02:40,634 TRACE (jgroups-10,Test-NodeB-46322:[]) [DistCacheWriterInterceptor] Stored entry null under key GroupKey{group='test-group', key=0}
---
16:02:40,634 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6314f4e7]
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6dd409f2]
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [DummyInMemoryStore] Processing entries in store null with filter org.infinispan.filter.CompositeKeyFilter@196d8e49 and callback org.infinispan.interceptors.impl.CacheLoaderInterceptor$1@54df66d9
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [EntryFactoryImpl] Creating new entry for key GroupKey{group='test-group', key=0}
16:02:40,636 TRACE (jgroups-4,Test-NodeD-54637:[]) [JGroupsTransport] Test-NodeD-54637 sending response for request 21 to Test-NodeB-46322: SuccessfulResponse([MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}])
---
16:02:40,636 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DummyInMemoryStore] Store MarshalledEntryImpl{keyBytes=null, valueBytes=null, metadataBytes=null, key=GroupKey{group='test-group', key=0}, value=null, metadata=InternalMetadataImpl{actual=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}, created=-1, lastUsed=-1}, marshaller=org.infinispan.marshall.core.GlobalMarshaller@26ecc0d1} in dummy map store@5d185974
---
16:02:40,638 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC]
java.lang.AssertionError:
at org.testng.AssertJUnit.fail(AssertJUnit.java:59) ~[testng-6.9.9.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24) ~[testng-6.9.9.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:33) ~[testng-6.9.9.jar:?]
at org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence(GetGroupKeysTest.java:162) ~[test-classes/:?]
{noformat}
Happens pretty reliably on my machine with trace logs enabled.
> GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC] random failure
> ---------------------------------------------------------------------------------------------
>
> Key: ISPN-9130
> URL: https://issues.jboss.org/browse/ISPN-9130
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 9.3.0.Alpha1
> Reporter: Dan Berindei
> Assignee: Radim Vansa
> Labels: testsuite_stability
> Fix For: 9.3.0.Beta1
>
> Attachments: RehashWithSharedStoreTest_ISPN-7977_NPE_during_shutdown_20180507.log.gz
>
>
> {{ScatteredDistributionInterceptor.handleWriteCommand}} sends the {{PrimaryAckCommand}} to the originator too soon. It takes care of committing the entry to the data container instead of waiting for {{EntryWrappingInterceptor}} to do it, but it doesn't do anything about the stores:
> {noformat}
> 16:02:40,630 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=GroupKey{group='test-group', key=0}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvocation:Test-NodeB-46322:3254, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [SingleKeyNonTxInvocationContext{isLocked=false, key=null, cacheEntry=null, origin=null, lockOwner=CommandInvocation:Test-NodeB-46322:3254}]
> 16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [ScatteredDistributionInterceptor] Committing entry RepeatableReadEntry(4631a022){key=GroupKey{group='test-group', key=0}, value=null, isCreated=false, isChanged=true, isRemoved=true, isExpired=false, skipLookup=true, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}}, replaced MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}
> 16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
> 16:02:40,633 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [JGroupsTransport] Test-NodeD-54637 sending command to Test-NodeB-46322: PrimaryAckCommand{id=3254, success=true, value=SimpleClusteredVersion{topologyId=5, version=40}, waitFor=[Test-NodeF-20476]}
> 16:02:40,633 TRACE (jgroups-10,Test-NodeB-46322:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedMetadata{version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
> 16:02:40,634 TRACE (jgroups-10,Test-NodeB-46322:[]) [DistCacheWriterInterceptor] Stored entry null under key GroupKey{group='test-group', key=0}
> ---
> 16:02:40,634 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6314f4e7]
> 16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6dd409f2]
> 16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [DummyInMemoryStore] Processing entries in store null with filter org.infinispan.filter.CompositeKeyFilter@196d8e49 and callback org.infinispan.interceptors.impl.CacheLoaderInterceptor$1@54df66d9
> 16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [EntryFactoryImpl] Creating new entry for key GroupKey{group='test-group', key=0}
> 16:02:40,636 TRACE (jgroups-4,Test-NodeD-54637:[]) [JGroupsTransport] Test-NodeD-54637 sending response for request 21 to Test-NodeB-46322: SuccessfulResponse([MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}])
> ---
> 16:02:40,636 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DummyInMemoryStore] Store MarshalledEntryImpl{keyBytes=null, valueBytes=null, metadataBytes=null, key=GroupKey{group='test-group', key=0}, value=null, metadata=InternalMetadataImpl{actual=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}, created=-1, lastUsed=-1}, marshaller=org.infinispan.marshall.core.GlobalMarshaller@26ecc0d1} in dummy map store@5d185974
> ---
> 16:02:40,638 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC]
> java.lang.AssertionError:
> at org.testng.AssertJUnit.fail(AssertJUnit.java:59) ~[testng-6.9.9.jar:?]
> at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24) ~[testng-6.9.9.jar:?]
> at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:33) ~[testng-6.9.9.jar:?]
> at org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence(GetGroupKeysTest.java:162) ~[test-classes/:?]
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9130) GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC] random failure
by Dan Berindei (JIRA)
Dan Berindei created ISPN-9130:
----------------------------------
Summary: GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC] random failure
Key: ISPN-9130
URL: https://issues.jboss.org/browse/ISPN-9130
Project: Infinispan
Issue Type: Bug
Components: Core
Affects Versions: 9.3.0.Alpha1
Reporter: Dan Berindei
Assignee: Radim Vansa
Fix For: 9.3.0.Beta1
{{ScatteredDistributionInterceptor.handleWriteCommand}} sends the {{PrimaryAckCommand}} to the originator too soon. It takes care of committing the entry to the data container instead of waiting for {{EntryWrappingInterceptor}} to do it, but it doesn't do anything about the stores:
{noformat}
16:02:40,630 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=GroupKey{group='test-group', key=0}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=CommandInvocation:Test-NodeB-46322:3254, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [SingleKeyNonTxInvocationContext{isLocked=false, key=null, cacheEntry=null, origin=null, lockOwner=CommandInvocation:Test-NodeB-46322:3254}]
16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [ScatteredDistributionInterceptor] Committing entry RepeatableReadEntry(4631a022){key=GroupKey{group='test-group', key=0}, value=null, isCreated=false, isChanged=true, isRemoved=true, isExpired=false, skipLookup=true, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}}, replaced MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}
16:02:40,631 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
16:02:40,633 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [JGroupsTransport] Test-NodeD-54637 sending command to Test-NodeB-46322: PrimaryAckCommand{id=3254, success=true, value=SimpleClusteredVersion{topologyId=5, version=40}, waitFor=[Test-NodeF-20476]}
16:02:40,633 TRACE (jgroups-10,Test-NodeB-46322:[]) [DefaultDataContainer] Store MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=null, metadata=EmbeddedMetadata{version=SimpleClusteredVersion{topologyId=5, version=40}}} in container
16:02:40,634 TRACE (jgroups-10,Test-NodeB-46322:[]) [DistCacheWriterInterceptor] Stored entry null under key GroupKey{group='test-group', key=0}
---
16:02:40,634 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6314f4e7]
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [InvocationContextInterceptor] Invoked with command GetKeysInGroupCommand{groupName='test-group', flags=[]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@6dd409f2]
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [DummyInMemoryStore] Processing entries in store null with filter org.infinispan.filter.CompositeKeyFilter@196d8e49 and callback org.infinispan.interceptors.impl.CacheLoaderInterceptor$1@54df66d9
16:02:40,635 TRACE (jgroups-4,Test-NodeD-54637:[]) [EntryFactoryImpl] Creating new entry for key GroupKey{group='test-group', key=0}
16:02:40,636 TRACE (jgroups-4,Test-NodeD-54637:[]) [JGroupsTransport] Test-NodeD-54637 sending response for request 21 to Test-NodeB-46322: SuccessfulResponse([MetadataImmortalCacheEntry{key=GroupKey{group='test-group', key=0}, value=v0, metadata=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=21}}}])
---
16:02:40,636 TRACE (remote-thread-Test-NodeD-p5380-t5:[]) [DummyInMemoryStore] Store MarshalledEntryImpl{keyBytes=null, valueBytes=null, metadataBytes=null, key=GroupKey{group='test-group', key=0}, value=null, metadata=InternalMetadataImpl{actual=EmbeddedExpirableMetadata{lifespan=-1, maxIdle=-1, version=SimpleClusteredVersion{topologyId=5, version=40}}, created=-1, lastUsed=-1}, marshaller=org.infinispan.marshall.core.GlobalMarshaller@26ecc0d1} in dummy map store@5d185974
---
16:02:40,638 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence[NON_OWNER, SCATTERED_SYNC]
java.lang.AssertionError:
at org.testng.AssertJUnit.fail(AssertJUnit.java:59) ~[testng-6.9.9.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:24) ~[testng-6.9.9.jar:?]
at org.testng.AssertJUnit.assertTrue(AssertJUnit.java:33) ~[testng-6.9.9.jar:?]
at org.infinispan.distribution.groups.GetGroupKeysTest.testRemoveGroupKeysWithPersistence(GetGroupKeysTest.java:162) ~[test-classes/:?]
{noformat}
Happens pretty reliably on my machine with trace logs enabled.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9129) Failure to execute CLI due to linking with Aesh
by Gustavo Fernandes (JIRA)
Gustavo Fernandes created ISPN-9129:
---------------------------------------
Summary: Failure to execute CLI due to linking with Aesh
Key: ISPN-9129
URL: https://issues.jboss.org/browse/ISPN-9129
Project: Infinispan
Issue Type: Bug
Reporter: Gustavo Fernandes
{{ispn-cli.sh -c ':read-attribute(name=server-state)'}} returns error:
{noformat}
Failed to link org/jboss/as/patching/cli/PatchCommand (Module "org.jboss.as.patching" version
4.0.0.Final from local module loader @555590 (finder: local module finder @6d1e7682 (roots:
/opt/jboss/infinispan-server/modules,/opt/jboss/infinispan-server/modules/system/layers/base))):
org/aesh/command/Command
{noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9129) Failure to execute CLI due to linking with Aesh
by Gustavo Fernandes (JIRA)
[ https://issues.jboss.org/browse/ISPN-9129?page=com.atlassian.jira.plugin.... ]
Gustavo Fernandes updated ISPN-9129:
------------------------------------
Affects Version/s: 9.3.0.Alpha1
> Failure to execute CLI due to linking with Aesh
> -----------------------------------------------
>
> Key: ISPN-9129
> URL: https://issues.jboss.org/browse/ISPN-9129
> Project: Infinispan
> Issue Type: Bug
> Affects Versions: 9.3.0.Alpha1
> Reporter: Gustavo Fernandes
>
> {{ispn-cli.sh -c ':read-attribute(name=server-state)'}} returns error:
> {noformat}
> Failed to link org/jboss/as/patching/cli/PatchCommand (Module "org.jboss.as.patching" version
> 4.0.0.Final from local module loader @555590 (finder: local module finder @6d1e7682 (roots:
> /opt/jboss/infinispan-server/modules,/opt/jboss/infinispan-server/modules/system/layers/base))):
> org/aesh/command/Command
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9128) RehashWithSharedStoreTest.testRehashes random failures
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-9128?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-9128:
-------------------------------
Attachment: RehashWithSharedStoreTest_ISPN-7977_NPE_during_shutdown_20180507.log.gz
> RehashWithSharedStoreTest.testRehashes random failures
> ------------------------------------------------------
>
> Key: ISPN-9128
> URL: https://issues.jboss.org/browse/ISPN-9128
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 9.3.0.Alpha1
> Reporter: Dan Berindei
> Assignee: Radim Vansa
> Labels: testsuite_stability
> Fix For: 9.3.0.Beta1
>
> Attachments: RehashWithSharedStoreTest_ISPN-7977_NPE_during_shutdown_20180507.log.gz
>
>
> {noformat}
> 16:00:32,748 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.rehash.RehashWithSharedStoreTest.testRehashes[SCATTERED_SYNC, tx=false, numOwners=1, l1=false]
> java.lang.AssertionError: Should be able to see key on new owner
> at org.infinispan.distribution.rehash.RehashWithSharedStoreTest.testRehashes(RehashWithSharedStoreTest.java:94) ~[test-classes/:?]
> {noformat}
> This first got my attention because I was working on ISPN-7977 and I noticed this NPE after the test failure:
> {noformat}
> 16:00:32,874 ERROR (jgroups-7,Test-NodeF-62673:[]) [ScatteredStateConsumerImpl] ISPN000471: Failed processing values received from remote node during rebalance.
> java.lang.NullPointerException: null
> at org.infinispan.scattered.impl.ScatteredStateConsumerImpl.applyValues(ScatteredStateConsumerImpl.java:505) ~[classes/:?]
> at org.infinispan.scattered.impl.ScatteredStateConsumerImpl.lambda$getValuesAndApply$8(ScatteredStateConsumerImpl.java:475) ~[classes/:?]
> at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) [?:1.8.0_152]
> at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) [?:1.8.0_152]
> at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) [?:1.8.0_152]
> at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) [?:1.8.0_152]
> at org.infinispan.remoting.transport.AbstractRequest.complete(AbstractRequest.java:67) [classes/:?]
> at org.infinispan.remoting.transport.impl.SingleTargetRequest.receiveResponse(SingleTargetRequest.java:57) [classes/:?]
> at org.infinispan.remoting.transport.impl.SingleTargetRequest.onResponse(SingleTargetRequest.java:35) [classes/:?]
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9128) RehashWithSharedStoreTest.testRehashes random failures
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-9128?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-9128:
-------------------------------
Status: Open (was: New)
> RehashWithSharedStoreTest.testRehashes random failures
> ------------------------------------------------------
>
> Key: ISPN-9128
> URL: https://issues.jboss.org/browse/ISPN-9128
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 9.3.0.Alpha1
> Reporter: Dan Berindei
> Assignee: Radim Vansa
> Labels: testsuite_stability
> Fix For: 9.3.0.Beta1
>
> Attachments: RehashWithSharedStoreTest_ISPN-7977_NPE_during_shutdown_20180507.log.gz
>
>
> {noformat}
> 16:00:32,748 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.rehash.RehashWithSharedStoreTest.testRehashes[SCATTERED_SYNC, tx=false, numOwners=1, l1=false]
> java.lang.AssertionError: Should be able to see key on new owner
> at org.infinispan.distribution.rehash.RehashWithSharedStoreTest.testRehashes(RehashWithSharedStoreTest.java:94) ~[test-classes/:?]
> {noformat}
> This first got my attention because I was working on ISPN-7977 and I noticed this NPE after the test failure:
> {noformat}
> 16:00:32,874 ERROR (jgroups-7,Test-NodeF-62673:[]) [ScatteredStateConsumerImpl] ISPN000471: Failed processing values received from remote node during rebalance.
> java.lang.NullPointerException: null
> at org.infinispan.scattered.impl.ScatteredStateConsumerImpl.applyValues(ScatteredStateConsumerImpl.java:505) ~[classes/:?]
> at org.infinispan.scattered.impl.ScatteredStateConsumerImpl.lambda$getValuesAndApply$8(ScatteredStateConsumerImpl.java:475) ~[classes/:?]
> at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) [?:1.8.0_152]
> at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) [?:1.8.0_152]
> at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) [?:1.8.0_152]
> at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) [?:1.8.0_152]
> at org.infinispan.remoting.transport.AbstractRequest.complete(AbstractRequest.java:67) [classes/:?]
> at org.infinispan.remoting.transport.impl.SingleTargetRequest.receiveResponse(SingleTargetRequest.java:57) [classes/:?]
> at org.infinispan.remoting.transport.impl.SingleTargetRequest.onResponse(SingleTargetRequest.java:35) [classes/:?]
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9128) RehashWithSharedStoreTest.testRehashes random failures
by Dan Berindei (JIRA)
Dan Berindei created ISPN-9128:
----------------------------------
Summary: RehashWithSharedStoreTest.testRehashes random failures
Key: ISPN-9128
URL: https://issues.jboss.org/browse/ISPN-9128
Project: Infinispan
Issue Type: Bug
Components: Core
Affects Versions: 9.3.0.Alpha1
Reporter: Dan Berindei
Assignee: Radim Vansa
Fix For: 9.3.0.Beta1
{noformat}
16:00:32,748 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.distribution.rehash.RehashWithSharedStoreTest.testRehashes[SCATTERED_SYNC, tx=false, numOwners=1, l1=false]
java.lang.AssertionError: Should be able to see key on new owner
at org.infinispan.distribution.rehash.RehashWithSharedStoreTest.testRehashes(RehashWithSharedStoreTest.java:94) ~[test-classes/:?]
{noformat}
This first got my attention because I was working on ISPN-7977 and I noticed this NPE after the test failure:
{noformat}
16:00:32,874 ERROR (jgroups-7,Test-NodeF-62673:[]) [ScatteredStateConsumerImpl] ISPN000471: Failed processing values received from remote node during rebalance.
java.lang.NullPointerException: null
at org.infinispan.scattered.impl.ScatteredStateConsumerImpl.applyValues(ScatteredStateConsumerImpl.java:505) ~[classes/:?]
at org.infinispan.scattered.impl.ScatteredStateConsumerImpl.lambda$getValuesAndApply$8(ScatteredStateConsumerImpl.java:475) ~[classes/:?]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) [?:1.8.0_152]
at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) [?:1.8.0_152]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) [?:1.8.0_152]
at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) [?:1.8.0_152]
at org.infinispan.remoting.transport.AbstractRequest.complete(AbstractRequest.java:67) [classes/:?]
at org.infinispan.remoting.transport.impl.SingleTargetRequest.receiveResponse(SingleTargetRequest.java:57) [classes/:?]
at org.infinispan.remoting.transport.impl.SingleTargetRequest.onResponse(SingleTargetRequest.java:35) [classes/:?]
{noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9094) ArrayIndexOutOfBoundsException on server using scattered cache
by William Burns (JIRA)
[ https://issues.jboss.org/browse/ISPN-9094?page=com.atlassian.jira.plugin.... ]
William Burns updated ISPN-9094:
--------------------------------
Status: Resolved (was: Pull Request Sent)
Fix Version/s: 9.3.0.Beta1
Resolution: Done
> ArrayIndexOutOfBoundsException on server using scattered cache
> ---------------------------------------------------------------
>
> Key: ISPN-9094
> URL: https://issues.jboss.org/browse/ISPN-9094
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 9.2.1.Final
> Reporter: Paul Ferraro
> Assignee: Radim Vansa
> Fix For: 9.3.0.Beta1
>
>
> We hit ArrayIndexOutOfBoundsException when running tests for RFE EAP7-867.
> EAP distribution was built from {{https://github.com/pferraro/wildfly/tree/scattered}} .
> Test description: Positive stress test (no failover), 4-node EAP cluster, clients: starting with 400 clients in the beginning, raising the number of clients to 6000 in the end of the test.
> Error occured on server dev215 around 7th iteration (can be seen in the performance report, link below):
> {code}
> [JBossINF] [0m[31m04:26:11,708 ERROR [stderr] (transport-thread--p15-t25) Exception in thread "transport-thread--p15-t25" java.lang.ArrayIndexOutOfBoundsException: 129
> [JBossINF] [0m[31m04:26:11,708 ERROR [stderr] (transport-thread--p15-t25) at org.infinispan.scattered.impl.ScatteredVersionManagerImpl.lambda$tryRegularInvalidations$4(ScatteredVersionManagerImpl.java:413)
> [JBossINF] [0m[31m04:26:11,708 ERROR [stderr] (transport-thread--p15-t25) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] [0m[31m04:26:11,708 ERROR [stderr] (transport-thread--p15-t25) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] [0m[31m04:26:11,708 ERROR [stderr] (transport-thread--p15-t25) at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
> [JBossINF] [0m[31m04:26:11,708 ERROR [stderr] (transport-thread--p15-t25) at java.lang.Thread.run(Thread.java:748)
> {code}
> Clients were getting "SocketTimeoutException: Read timed out" exceptions even before the ArrayIndexOutOfBoundsException ocurred, but also after.
> Performance report (accessible only when connected to VPN):
> http://download.eng.brq.redhat.com/scratch/mvinkler/reports/2018-04-19_15...
> One can observe that dev215 CPU usage and network usage dropped after 7th iteration.
> dev215 server log link:
> https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/eap-7x-stress-se...
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months
[JBoss JIRA] (ISPN-9127) Remote commands can access components before they are started
by Dan Berindei (JIRA)
Dan Berindei created ISPN-9127:
----------------------------------
Summary: Remote commands can access components before they are started
Key: ISPN-9127
URL: https://issues.jboss.org/browse/ISPN-9127
Project: Infinispan
Issue Type: Bug
Components: Core
Affects Versions: 9.3.0.Alpha1, 9.2.2.Final
Reporter: Dan Berindei
Assignee: Dan Berindei
Fix For: 9.3.0.Beta1
{{PerCacheInboundInvocationHandler.handle()}} may be called before the component was started, because {{GlobalInboundInvocationHandler}} fetches it from the component registry without any checks. {{CommandsFactoryImpl.initializeReplicableCommand()}} doesn't wait for the components that it injects into remote commands to be started, either.
This started causing random test failures in {{ConcurrentStartForkChannelTest}} after ISPN-8515, which moved most initialization work from {{init()}} methods to {{start()}} methods. Because {{StateProviderImpl}} starts after {{StateTransferManagerImpl}}, it's possible for a node to receive a {{StateRequestCommand}} before {{StateProviderImpl}} has initialized:
{noformat}
16:15:09,549 TRACE (remote-thread-Test-NodeB-p51957-t2:[org.infinispan.CONFIG]) [StateProviderImpl] Starting outbound transfer to node Test-NodeA for cache null, topology id 2, segments {0-255}
16:15:09,551 WARN (remote-thread-Test-NodeB-p51957-t2:[]) [NonTotalOrderPerCacheInboundInvocationHandler] ISPN000071: Caught exception when handling command StateRequestCommand{cache=org.infinispan.CONFIG, origin=Test-NodeA, type=START_STATE_TRANSFER, topologyId=2, segments={0-255}}
java.lang.IllegalArgumentException: chunkSize must be greater than 0
at org.infinispan.statetransfer.OutboundTransferTask.<init>(OutboundTransferTask.java:114) ~[classes/:?]
at org.infinispan.statetransfer.StateProviderImpl.startOutboundTransfer(StateProviderImpl.java:273) ~[classes/:?]
at org.infinispan.statetransfer.StateRequestCommand.invokeAsync(StateRequestCommand.java:101) ~[classes/:?]
at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94) ~[classes/:?]
{noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 5 months