[infinispan-issues] [JBoss JIRA] (ISPN-10239) FineGrainedAtomicMap.clear() concurrency issues

FineGrainedAtomicMap.clear() concurrency issues ----------------------------------------------- Key: ISPN-10239 URL: https://issues.jboss.org/browse/ISPN-10239 Project: Infinispan Issue Type: Bug Components: Core, Test Suite - Core Affects Versions: 10.0.0.Beta3, 9.4.14.Final Reporter: Dan Berindei Assignee: Dan Berindei Priority: Major Labels: testsuite_stability Fix For: 10.0.0.Beta4, 9.4.15.Final ISPN-7889 fixed the distribution interceptors to always access the invocation context from a single thread at a time. However, this only covers a single command invocation: it is still possible for an application to start multiple asynchronous operations in the same transaction and accessing the same {{AbstractCacheTransaction.lookedUpEntries}} map. {{FineGrainedAtomicMap.clear()}} does exactly that: {code} Cache<Object, Object> noReturn = cache.getAdvancedCache().withFlags(Flag.IGNORE_RETURN_VALUES); for (K key : keys) { cfs.add(noReturn.removeAsync(new AtomicKeySetImpl.Key<>(group, key))); } {code} And it's causing random failures in {{DistFineGrainedAtomicMapAPITest.testReplicationPutAndClearCommit}} when two commands insert an entry in the {{lookedUpEntries}} {{HashMap}} in parallel and one of them disappears: {noformat} 13:08:49,676 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=AtomicKeySetImpl.Key{group=map, key=existing}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@7ce5d574] 13:08:49,676 TRACE (testng-Test:[]) [JGroupsTransport] Test-NodeB-49901 sending request 102 to [Test-NodeA-29107]: LockControlCommand{cache=atomic, keys=[AtomicKeySetImpl.Key{group=map, key=existing}], flags=[IGNORE_RETURN_VALUES], unlock=false, gtx=GlobalTx:Test-NodeB-49901:55098} 13:08:49,677 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command RemoveCommand{key=AtomicKeySetImpl.Key{group=map, key=blah}, value=null, metadata=null, flags=[IGNORE_RETURN_VALUES], commandInvocationId=, valueMatcher=MATCH_ALWAYS, topologyId=-1} and InvocationContext [org.infinispan.context.impl.LocalTxInvocationContext@11d7f886] 13:08:49,677 TRACE (testng-Test:[]) [JGroupsTransport] Test-NodeB-49901 sending request 103 to [Test-NodeA-29107]: LockControlCommand{cache=atomic, keys=[AtomicKeySetImpl.Key{group=map, key=blah}], flags=[IGNORE_RETURN_VALUES], unlock=false, gtx=GlobalTx:Test-NodeB-49901:55098} 13:08:49,678 TRACE (jgroups-8,Test-NodeB-49901:[]) [JGroupsTransport] Test-NodeB-49901 received response for request 103 from Test-NodeA-29107: SuccessfulResponse(true) 13:08:49,678 TRACE (jgroups-4,Test-NodeB-49901:[]) [JGroupsTransport] Test-NodeB-49901 received response for request 102 from Test-NodeA-29107: SuccessfulResponse(true) 13:08:49,678 TRACE (jgroups-4,Test-NodeB-49901:[]) [QueueAsyncInvocationStage] Resuming invocation of command LockControlCommand{cache=atomic, keys=[AtomicKeySetImpl.Key{group=map, key=existing}], flags=[IGNORE_RETURN_VALUES], unlock=false, gtx=GlobalTx:Test-NodeB-49901:55098} with 1 handlers 13:08:49,678 TRACE (jgroups-8,Test-NodeB-49901:[]) [QueueAsyncInvocationStage] Resuming invocation of command LockControlCommand{cache=atomic, keys=[AtomicKeySetImpl.Key{group=map, key=blah}], flags=[IGNORE_RETURN_VALUES], unlock=false, gtx=GlobalTx:Test-NodeB-49901:55098} with 1 handlers 13:08:49,678 TRACE (jgroups-8,Test-NodeB-49901:[]) [EntryFactoryImpl] Updated context entry null -> RepeatableReadEntry(68ce9a19){key=AtomicKeySetImpl.Key{group=map, key=blah}, value=null, isCreated=false, isChanged=false, isRemoved=false, isExpired=false, skipLookup=false, metadata=null} 13:08:49,678 TRACE (jgroups-4,Test-NodeB-49901:[]) [EntryFactoryImpl] Updated context entry null -> RepeatableReadEntry(69aa0b31){key=AtomicKeySetImpl.Key{group=map, key=existing}, value=null, isCreated=false, isChanged=false, isRemoved=false, isExpired=false, skipLookup=false, metadata=null} 13:08:49,678 TRACE (jgroups-4,Test-NodeB-49901:[]) [CallInterceptor] Invoking: RemoveCommand 13:08:49,678 TRACE (jgroups-8,Test-NodeB-49901:[]) [CallInterceptor] Invoking: RemoveCommand 13:08:49,678 TRACE (jgroups-8,Test-NodeB-49901:[]) [EntryWrappingInterceptor] The return value is null 13:08:49,679 ERROR (jgroups-4,Test-NodeB-49901:[]) [InvocationContextInterceptor] ISPN000136: Error executing command RemoveCommand on Cache 'atomic', writing keys [AtomicKeySetImpl.Key{group=map, key=existing}] java.lang.NullPointerException: null 13:08:49,681 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.atomic.DistFineGrainedAtomicMapAPITest.testReplicationPutAndClearCommit java.lang.NullPointerException: null at org.infinispan.commands.write.RemoveCommand.perform(RemoveCommand.java:75) ~[classes/:?] at org.infinispan.interceptors.impl.CallInterceptor.visitCommand(CallInterceptor.java:29) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:152) ~[classes/:?] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.handleTxWriteCommand(TxDistributionInterceptor.java:427) ~[classes/:?] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitRemoveCommand(TxDistributionInterceptor.java:138) ~[classes/:?] at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:64) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(BaseAsyncInterceptor.java:98) ~[classes/:?] at org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:671) ~[classes/:?] at org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitRemoveCommand(EntryWrappingInterceptor.java:356) ~[classes/:?] at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:64) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54) ~[classes/:?] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54) ~[classes/:?] at org.infinispan.interceptors.DDAsyncInterceptor.visitRemoveCommand(DDAsyncInterceptor.java:65) ~[classes/:?] at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:64) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54) ~[classes/:?] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54) ~[classes/:?] at org.infinispan.interceptors.DDAsyncInterceptor.visitRemoveCommand(DDAsyncInterceptor.java:65) ~[classes/:?] at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:64) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54) ~[classes/:?] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lambda$new$0(AbstractTxLockingInterceptor.java:34) ~[classes/:?] at org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:25) ~[classes/:?] at org.infinispan.interceptors.SyncInvocationStage.addCallback(SyncInvocationStage.java:42) ~[classes/:?] at org.infinispan.interceptors.InvocationStage.thenApply(InvocationStage.java:45) ~[classes/:?] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireLocalLockAndInvokeNext(PessimisticLockingInterceptor.java:283) ~[classes/:?] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.lambda$visitDataWriteCommand$3(PessimisticLockingInterceptor.java:154) ~[classes/:?] at org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:25) ~[classes/:?] at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.invokeQueuedHandlers(QueueAsyncInvocationStage.java:118) ~[classes/:?] {noformat}