ISPN000476: Timed out waiting for responses for request 73 from

Question

while trying to use EmbeddedCacheManager from infinispan(9.4.11.Final) with below configuration, I get an exception on server.

/**
 * Configure infinispan to run with a default clustered jgroups setup.
 */
@Bean
public InfinispanGlobalConfigurer infinispanRemoteConfigurer(
        @Value("foo") String clusterName) {
    return () -> GlobalConfigurationBuilder
            .defaultClusteredBuilder()
            .transport()
            .clusterName(clusterName)
            .addProperty("configurationFile", "default-configs/default-jgroups-udp.xml")
            .globalJmxStatistics()
            .build();
}

/**
 * Configures the bar cache.
 */
@Bean(name = "bar")
public org.infinispan.configuration.cache.Configuration platformsCache() {
    return new ConfigurationBuilder()
            .clustering().cacheMode(CacheMode.REPL_SYNC)
            .memory().size(1000L)
            .memory().evictionType(EvictionType.COUNT)
            .build();
}

/**
 * Configures the bla cache.
 */
@Bean(name = "bla")
public org.infinispan.configuration.cache.Configuration undoStacksCache() {
    return new ConfigurationBuilder()
            .clustering().cacheMode(CacheMode.REPL_SYNC)
            .memory().size(1000L)
            .memory().evictionType(EvictionType.COUNT)
            .build();
}

/**
 * Configures the bla1.
 * This will never be clustered.
 */
@Bean(name = "bla1")
public org.infinispan.configuration.cache.Configuration arePlatformsCache() {
    return new ConfigurationBuilder()
            .clustering().cacheMode(CacheMode.LOCAL)
            .memory().size(1000L)
            .memory().evictionType(EvictionType.COUNT)
            .build();
}

/**
 * Configures the bla2.
 * Not intended to be clustered.
 */
@Bean(name = "bla2")
public org.infinispan.configuration.cache.Configuration areOperationsCache() {
    return new ConfigurationBuilder()
            .clustering().cacheMode(CacheMode.LOCAL)
            .memory().size(1000L)
            .memory().evictionType(EvictionType.COUNT)
            .build();
}

The exception trace are as below:

2019-10-14 18:35:37 [remote-thread--p2-t3] ERROR o.i.i.i.InvocationContextInterceptor - ISPN000136: Error executing command PutKeyValueCommand, writing keys [bar]
org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 10 seconds for key bar and requestor CommandInvocation:XXX.XXX.XXX.XX-44468:4. Lock is held by CommandInvocation:XXX.XXX.XXX.XX-44468:3
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:218)
    at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:436)
    at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.toInvocationStage(InfinispanLock.java:408)
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:248)
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:272)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.nonTxLockAndInvokeNext(AbstractLockingInterceptor.java:294)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:126)
    at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:82)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
    at org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(StateTransferInterceptor.java:306)
    at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:252)
    at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:96)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
    at org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:214)
    at org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:179)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
    at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
    at org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
    at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:56)
    at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
    at org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
    at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234)
    at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommandAsync(BaseRpcInvokingCommand.java:63)
    at org.infinispan.commands.remote.SingleRpcCommand.invokeAsync(SingleRpcCommand.java:57)
    at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:117)
    at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
    at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
    at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

2019-10-14 18:35:38 [remote-thread--p2-t3] WARN  o.i.r.i.NonTotalOrderPerCacheInboundInvocationHandler - ISPN000071: Caught exception when handling command SingleRpcCommand{cacheName='bar', command=PutKeyValueCommand{key=bar, successful=true, topologyId=13}}
org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 10 seconds for key bar and requestor CommandInvocation:XXX.XXX.XXX.XX-44468:4. Lock is held by CommandInvocation:XXX.XXX.XXX.XX-44468:3
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:218)
    at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:436)
    at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.toInvocationStage(InfinispanLock.java:408)
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:248)
    at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:272)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.nonTxLockAndInvokeNext(AbstractLockingInterceptor.java:294)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:126)
    at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
    at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:82)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
    at org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(StateTransferInterceptor.java:306)
    at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:252)
    at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:96)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
    at org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:214)
    at org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:179)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
    at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
    at org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
    at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
    at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:56)
    at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
    at org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
    at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:73)
    at org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
    at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234)
    at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommandAsync(BaseRpcInvokingCommand.java:63)
    at org.infinispan.commands.remote.SingleRpcCommand.invokeAsync(SingleRpcCommand.java:57)
    at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:117)
    at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
    at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
    at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

2019-10-14 18:35:43 [timeout-thread--p3-t1] ERROR o.i.i.i.InvocationContextInterceptor - ISPN000136: Error executing command PutKeyValueCommand, writing keys [bar]
org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 15 from XXX.XXX.XXX.XX-44468
    at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
    at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
    at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

2019-10-14 18:35:43 [timeout-thread--p3-t1] WARN  o.i.r.i.NonTotalOrderPerCacheInboundInvocationHandler - ISPN000071: Caught exception when handling command SingleRpcCommand
org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 15 from XXX.XXX.XXX.XX-44468
    at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
    at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
    at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

The time out is perhaps taken as the default from the jgroup as defined in the xsd, when the configuration is programatically defined rather than declarative(using xml). So programtically, increased the remote-timout as 60 seconds /** * Configures the bar cache. */ @Bean(name = "bar") public org.infinispan.configuration.cache.Configuration bar() { return new ConfigurationBuilder() .clustering().cacheMode(CacheMode.REPL_SYNC).remoteTimeout(60, TimeUnit.SECONDS) — Debender Prasad, Oct 18 '19 at 08:50
What does the rest of the code look like? Key `bar` is updated, but no code above shown. It's odd for a lock not to be released in a non-transactional situation, like above. — Galder Zamarreño, Nov 04 '19 at 05:58
Cross-posted: https://developer.jboss.org/message/991244?et=watches.email.thread#991244 — Galder Zamarreño, Nov 04 '19 at 11:33
This is the full code for the spring boot infinispan configuration in cluster mode. can you please tell me which part of the code you are looking for? is there a lock by default? do I need to make an explicit release of the lock? — Debender Prasad, Nov 04 '19 at 12:59
The code that interacts with the cache, that puts data. Are you running some kind of load test? How many threads are involved in your test? — Galder Zamarreño, Nov 07 '19 at 12:32
If not doing a load test, you should enable TRACE on `org.infinispan` and get some thread dumps before/after timeouts in all nodes to see what might be holding things. It's odd to see such situations these days. — Galder Zamarreño, Nov 07 '19 at 12:59
I suggest running with `-Djava.net.preferIPv4Stack=true`, IPv6 and UDP multicast have weird interactions (https://issues.jboss.org/browse/ISPN-9345). Alternative workarounds are setting `` or switching to TCP. — Dan Berindei, Nov 07 '19 at 13:41

ISPN000476: Timed out waiting for responses for request 73 from

0 Answers0