[infinispan-issues] [Red Hat JIRA] (ISPN-12468) Prevent from unnecessary WARN messages ISPN000299 to acquire a lock for expiration handling

[ https://issues.redhat.com/browse/ISPN-12468?page=com.atlassian.jira.plugi... ] Dan Berindei commented on ISPN-12468: ------------------------------------- On the node where the lock acquisition failed, the lock acquisition timeout is also logged as an ERROR in addition to the WARN message in the description: {noformat} 12:52:27,364+0100 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (expiration-thread--p5-t1) ISPN000136: Error executing command RemoveExpiredCommand on Cache 'PACS008_ACTIVATOR', writing keys [[4619b98805e540c3a39cfb3b377aa0e3|BARRIT26|2021-02-05T12:50:49.570646+01:00]]: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 0 milliseconds for key [4619b98805e540c3a39cfb3b377aa0e3|BARRIT26|2021-02-05T12:50:49.570646+01:00] and requestor GlobalTransaction{id=185255, addr=ebaipm1tpbe91-48322, remote=false, xid=null, internalId=-1}. Lock is held by GlobalTransaction{id=183703, addr=ebaipm1tpbe91-48322, remote=false, xid=null, internalId=-1} at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:292) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:222) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:440) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.toInvocationStage(InfinispanLock.java:412) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:252) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:276) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAndRecord(AbstractLockingInterceptor.java:277) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockKey(AbstractTxLockingInterceptor.java:137) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockOrRegisterBackupLock(AbstractTxLockingInterceptor.java:65) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireLocalLock(PessimisticLockingInterceptor.java:92) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireLocalLockAndInvokeNext(PessimisticLockingInterceptor.java:285) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataWriteCommand(PessimisticLockingInterceptor.java:150) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitRemoveCommand(AbstractLockingInterceptor.java:102) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.Visitor.visitRemoveExpiredCommand(Visitor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.write.RemoveExpiredCommand.acceptVisitor(RemoveExpiredCommand.java:46) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:155) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.impl.TxInterceptor.handleWriteCommand(TxInterceptor.java:394) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.impl.TxInterceptor.visitRemoveCommand(TxInterceptor.java:232) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.Visitor.visitRemoveExpiredCommand(Visitor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.write.RemoveExpiredCommand.acceptVisitor(RemoveExpiredCommand.java:46) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:59) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:53) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.partitionhandling.impl.PartitionHandlingInterceptor.handleSingleWrite(PartitionHandlingInterceptor.java:89) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.partitionhandling.impl.PartitionHandlingInterceptor.visitRemoveCommand(PartitionHandlingInterceptor.java:62) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.Visitor.visitRemoveExpiredCommand(Visitor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.write.RemoveExpiredCommand.acceptVisitor(RemoveExpiredCommand.java:46) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:59) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.statetransfer.StateTransferInterceptor.handleTxWriteCommand(StateTransferInterceptor.java:259) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:249) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.statetransfer.StateTransferInterceptor.visitRemoveCommand(StateTransferInterceptor.java:108) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.Visitor.visitRemoveExpiredCommand(Visitor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.write.RemoveExpiredCommand.acceptVisitor(RemoveExpiredCommand.java:46) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:155) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitRemoveCommand(CacheMgmtInterceptor.java:484) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.Visitor.visitRemoveExpiredCommand(Visitor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.write.RemoveExpiredCommand.acceptVisitor(RemoveExpiredCommand.java:46) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:128) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:61) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:53) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.DDAsyncInterceptor.visitRemoveCommand(DDAsyncInterceptor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.Visitor.visitRemoveExpiredCommand(Visitor.java:64) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.commands.write.RemoveExpiredCommand.acceptVisitor(RemoveExpiredCommand.java:46) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:49) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:226) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.cache.impl.InvocationHelper.doInvokeAsync(InvocationHelper.java:293) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.cache.impl.InvocationHelper.executeCommandAsyncWithInjectedTx(InvocationHelper.java:219) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.cache.impl.InvocationHelper.invokeAsync(InvocationHelper.java:146) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.cache.impl.CacheImpl.performRemoveExpiredCommand(CacheImpl.java:719) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.cache.impl.CacheImpl.removeLifespanExpired(CacheImpl.java:700) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.cache.impl.DecoratedCache.removeLifespanExpired(DecoratedCache.java:415) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.expiration.impl.ClusterExpirationManager.removeLifespan(ClusterExpirationManager.java:244) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.expiration.impl.ClusterExpirationManager.handleEitherExpiration(ClusterExpirationManager.java:268) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.expiration.impl.ClusterExpirationManager.handleLifespanExpireEntry(ClusterExpirationManager.java:240) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.expiration.impl.ClusterExpirationManager.purgeInMemoryContents(ClusterExpirationManager.java:159) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] at org.infinispan.expiration.impl.ClusterExpirationManager.processExpiration(ClusterExpirationManager.java:100) [infinispan-core-11.0.9.Final-redhat-00001.jar:11.0.9.Final-redhat-00001] {noformat} -- This message was sent by Atlassian Jira (v8.13.1#813001)