Problem: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds]
Few months ago a colleague suggested to use infinispan for a web application that required caching a bunch of images and wav files. Me being no expert on jboss or infinispan or jgroups I tried (I needed a fast solution) to adapt the quickest and easiest solution to have the cache up and running. Unfortunately we now (in production) face TimeoutExcpetions and the cache does not serve content at all. Here are the specs:
- Java 7 (1.7.0.21)
- 2 JBoss 7.1 servers running in a cluster
- Infinispan 5.2.6.Final
I could not use Jboss configuration (ie in standalone.xml) to configure the caches so I chose the standalone infinispan solution. I tried to set the caches in replication cluster mode (because of JBoss cluster), but as far as I have noticed the caches are not replicated (although I see in jmx console that (component=CacheManager,name="DefaultCacheManager",type=CacheManager) infinispan is cluster aware. Additionally instead of setting the expiration time in the configuration I set it whenever an entry is put in the cache (we need to be able to change the cache period). Here is my infinicpan-config.xml
https://gist.github.com/anonymous/6882267
<?xml version="1.0" encoding="UTF-8"?> <infinispan xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="urn:infinispan:config:5.2 http://www.infinispan.org/schemas/infinispan-config-5.2.xsd urn:infinispan:config:jdbc:5.2 http://www.infinispan.org/schemas/infinispan-cachestore-jdbc-config-5.2.xsd" xmlns="urn:infinispan:config:5.2" xmlns:jdbc="urn:infinispan:config:jdbc:5.2"> <global> <evictionScheduledExecutor factory="org.infinispan.executors.DefaultScheduledExecutorFactory"> <properties> <property name="threadNamePrefix" value="EvictionThread" /> </properties> </evictionScheduledExecutor> <globalJmxStatistics enabled="true" /> <transport clusterName="File-Cluster-Cache"></transport> </global> <default> <eviction strategy="LRU" maxEntries="2000" /> <expiration lifespan="3600000" maxIdle="3500000" /> <jmxStatistics enabled="true" /> </default> <namedCache name="TuneCache"> <clustering mode="replication"> <stateTransfer chunkSize="0" fetchInMemoryState="false" timeout="240000" /> <async useReplQueue="true" replQueueInterval="10000" replQueueMaxElements="100" /> </clustering> <eviction strategy="LRU" maxEntries="2000" /> <jmxStatistics enabled="true" /> </namedCache> <namedCache name="PictureCache"> <clustering mode="replication"> <stateTransfer chunkSize="0" fetchInMemoryState="false" timeout="240000" /> <async useReplQueue="true" replQueueInterval="10000" replQueueMaxElements="100" /> </clustering> <eviction strategy="LRU" maxEntries="2000" /> <jmxStatistics enabled="true" /> </namedCache> </infinispan>
Only one server fails to server content from the cache. The second one works fine. Here is the stack trace from the failing server. https://gist.github.com/anonymous/6882013
Caused by: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [1129000157] for requestor [Thread[http--10.64.9.92-8080-245,5,main]]! Lock held by [Thread[http--10.64.9.92-8080-207,5,main]] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:948) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:827) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:734) [jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:812) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-api_3.0_spec-1.0.0.Final.jar:1.0.0.Final] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) [jbossweb-7.0.13.Final.jar:] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.13.Final.jar:] at org.jboss.weld.servlet.ConversationPropagationFilter.doFilter(ConversationPropagationFilter.java:62) [weld-core-1.1.5.AS71.Final.jar:2012-02-10 15:31] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:280) [jbossweb-7.0.13.Final.jar:] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.13.Final.jar:] at org.jboss.solder.servlet.exception.CatchExceptionFilter.doFilter(CatchExceptionFilter.java:65) [solder-impl-3.1.0.Final.jar:3.1.0.Final] ... 56 more Caused by: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [1129000157] for requestor [Thread[http--10.64.9.92-8080-245,5,main]]! Lock held by [Thread[http--10.64.9.92-8080-207,5,main]] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.lockKey(NonTransactionalLockingInterceptor.java:178) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:72) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:125) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.IsMarshallableInterceptor.visitPutKeyValueCommand(IsMarshallableInterceptor.java:111) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1186) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.CacheImpl.putInternal(CacheImpl.java:783) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.CacheImpl.put(CacheImpl.java:777) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.CacheImpl.put(CacheImpl.java:771) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.CacheSupport.put(CacheSupport.java:128) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at com.cri.rbtportal.services.ResourceManagementServiceImpl.getPicture(ResourceManagementServiceImpl.java:453) [classes:] at com.cri.rbtportal.controllers.BrowseRBTContentController.getPicture(BrowseRBTContentController.java:253) [classes:] at sun.reflect.GeneratedMethodAccessor144.invoke(Unknown Source) [:1.7.0_21] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_21] at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_21] at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:219) [spring-web-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132) [spring-web-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:745) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:686) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:936) [spring-webmvc-3.2.2.RELEASE.jar:3.2.2.RELEASE] ... 66 more 2013-10-08 11:47:35,142 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (Incoming-2,RBTWEB2-17443) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [1110000557] for requestor [Thread[Incoming-2,RBTWEB2-17443,5,main]]! Lock held by [Thread[http--10.64.9.92-8080-188,5,main]] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.lockKey(NonTransactionalLockingInterceptor.java:178) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:72) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:125) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.IsMarshallableInterceptor.visitPutKeyValueCommand(IsMarshallableInterceptor.java:111) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.remote.MultipleRpcCommand.perform(MultipleRpcCommand.java:77) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:101) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:122) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:86) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:598) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.JChannel.up(JChannel.java:707) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1020) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.RSVP.up(RSVP.java:188) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:797) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:606) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:187) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.MERGE2.up(MERGE2.java:205) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.Discovery.up(Discovery.java:359) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.TP.passMessageUp(TP.java:1263) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1825) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1793) [jgroups-3.2.7.Final.jar:3.2.7.Final] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_21] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_21] at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_21] 2013-10-08 11:47:35,173 ERROR [org.infinispan.remoting.InboundInvocationHandlerImpl] (Incoming-2,RBTWEB2-17443) Exception executing command: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [1110000557] for requestor [Thread[Incoming-2,RBTWEB2-17443,5,main]]! Lock held by [Thread[http--10.64.9.92-8080-188,5,main]] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.lockKey(NonTransactionalLockingInterceptor.java:178) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:72) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:125) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.IsMarshallableInterceptor.visitPutKeyValueCommand(IsMarshallableInterceptor.java:111) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.commands.remote.MultipleRpcCommand.perform(MultipleRpcCommand.java:77) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:101) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:122) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:86) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) [infinispan-core-5.2.6.Final.jar:5.2.6.Final] at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:598) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.JChannel.up(JChannel.java:707) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1020) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.RSVP.up(RSVP.java:188) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:797) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:606) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:187) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.MERGE2.up(MERGE2.java:205) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.Discovery.up(Discovery.java:359) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.TP.passMessageUp(TP.java:1263) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1825) [jgroups-3.2.7.Final.jar:3.2.7.Final] at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1793) [jgroups-3.2.7.Final.jar:3.2.7.Final] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_21] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_21] at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_21]
The code I use to put entries in the cache is simple:
pictureCache.put(imageId, file.getAbsolutePath(), jmxConfiguration.getCachingPeriod(), TimeUnit.MINUTES);
I do not use transactions nor I have set up lock settings.
Could please tell me what is wrong with all of the above?
Thank you in advance.
Katerina.
PS. I also see this in the jmx console (the picture cache is failing, the tune cache work OK)
| concurrencyLevel | R | int | The concurrency level that the MVCC Lock Manager has been configured with. | 32 |
| numberOfLocksAvailable | R | int | The number of exclusive locks that are available. | 0 |
| numberOfLocksHeld | R | int | The number of exclusive locks that are held. | 212 |
