Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-3090

"Lock obtain timed out" is thrown while querying using Infinispan directory_provider with jdbc cache store

XMLWordPrintable

      Pre-requisites:

      You can find the used configuration attached (clustered-config.xml).
      The main cache is configured so that, the default.directory_provider is set to infinispan.
      The index caches are redefined and jdbc string based cache store is declared for them.

      The test which is run for this configuration is a performance test. The point is to start a several nodes, make sure that the replication takes place, then put indexed entries into the cache and perform queries on that cache. All these actions are done in parallel.

      Problem 1:

      Configuration: JDBC cache store - shared=false, indexLocalOnly=false

      a) When starting 2 nodes which perform puts in parallel into the cache (putting indexed entries), everything goes smoothly no problem appears.

      b) As soon as the number of nodes is increased to 3, the following exception is thrown while trying to put data into the cache (see below). Please note, that in case of 3 nodes, this exception is thrown just in the beginning while verifying that the cluster is formed, i.e. put is done into the cache and then it is expected that the data is replicated to the rest nodes. The exception is thrown during the put, but it doesn't harm the further work of the test and the next steps described above succeed properly:

       
14:45:50,190 ERROR [InvocationContextInterceptor] ISPN000136: Execution error
org.hibernate.search.SearchException: HSEARCH000103: Unable to initialize IndexManager query
	at org.hibernate.search.indexes.impl.IndexManagerHolder.createIndexManager(IndexManagerHolder.java:230)
	at org.hibernate.search.indexes.impl.IndexManagerHolder.buildEntityIndexBinding(IndexManagerHolder.java:102)
	at org.hibernate.search.spi.SearchFactoryBuilder.initDocumentBuilders(SearchFactoryBuilder.java:414)
	at org.hibernate.search.spi.SearchFactoryBuilder.buildIncrementalSearchFactory(SearchFactoryBuilder.java:169)
	at org.hibernate.search.spi.SearchFactoryBuilder.buildSearchFactory(SearchFactoryBuilder.java:149)
	at org.hibernate.search.impl.MutableSearchFactory.addClasses(MutableSearchFactory.java:194)
	at org.infinispan.query.backend.QueryInterceptor.enableClassesIncrementally(QueryInterceptor.java:225)
	at org.infinispan.query.backend.QueryInterceptor.updateKnownTypesIfNeeded(QueryInterceptor.java:250)
	at org.infinispan.query.backend.QueryInterceptor.processPutKeyValueCommand(QueryInterceptor.java:426)
	at org.infinispan.query.backend.QueryInterceptor.visitPutKeyValueCommand(QueryInterceptor.java:128)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:73)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216)
	at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194)
	at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
	at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61)
	at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70)
	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:101)
	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:122)
	at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:86)
	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247)
	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220)
	at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484)
	at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391)
	at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249)
	at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:598)
	at org.jgroups.JChannel.up(JChannel.java:707)
	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1020)
	at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:504)
	at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)
	at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896)
	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245)
	at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:453)
	at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:751)
	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:609)
	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
	at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
	at org.jgroups.protocols.Discovery.up(Discovery.java:359)
	at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2616)
	at org.jgroups.protocols.TP.passMessageUp(TP.java:1263)
	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1825)
	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1798)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)
Caused by: org.hibernate.search.SearchException: Could not initialize index
	at org.hibernate.search.store.impl.DirectoryProviderHelper.initializeIndexIfNeeded(DirectoryProviderHelper.java:162)
	at org.hibernate.search.infinispan.impl.InfinispanDirectoryProvider.start(InfinispanDirectoryProvider.java:103)
	at org.hibernate.search.indexes.impl.DirectoryBasedIndexManager.initialize(DirectoryBasedIndexManager.java:104)
	at org.hibernate.search.indexes.impl.IndexManagerHolder.createIndexManager(IndexManagerHolder.java:227)
	... 65 more
Caused by: org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@98f624d
	at org.apache.lucene.store.Lock.obtain(Lock.java:84)
	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1098)
	at org.hibernate.search.store.impl.DirectoryProviderHelper.initializeIndexIfNeeded(DirectoryProviderHelper.java:157)
	... 68 more

      c) If the number of nodes is increased to 4, then the exception described above is thrown always not only during cluster verification, but also during writing indexed data into the cache.

      Problem 2:

      Configuration: JDBC cache store - shared=true, indexLocalOnly=true

      In this case for both 3 and 4 nodes happens the case described in Problem 1.b .

      Problem 3:

      Configuration: JDBC cache store - shared=true, indexLocalOnly=false

      In this case for 3 node configuration, the Problem 1.b happens. For the 4 node configuration, the picture is a little bit different. First during cluster validation the exception is thrown given above.
      As soon as the test comes to the stage of writing indexed data into the cache, the following exception is continuously thrown:

      17:20:27,445 ERROR [InvocationContextInterceptor] ISPN000136: Execution error
org.infinispan.util.concurrent.TimeoutException: Replication timeout for amanukyan-2185
	at org.infinispan.remoting.transport.AbstractTransport.parseResponseAndAddToResponseList(AbstractTransport.java:113)
	at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:541)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:169)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:190)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:247)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:234)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:229)
	at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:208)
	at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:200)
	at org.infinispan.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:297)
	at org.infinispan.interceptors.ReplicationInterceptor.visitPutKeyValueCommand(ReplicationInterceptor.java:248)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:275)
	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:166)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.query.backend.QueryInterceptor.visitPutKeyValueCommand(QueryInterceptor.java:127)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:71)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216)
	at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194)
	at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
	at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1186)
	at org.infinispan.CacheImpl.putInternal(CacheImpl.java:783)
	at org.infinispan.CacheImpl.put(CacheImpl.java:777)
	at org.infinispan.CacheImpl.put(CacheImpl.java:771)
	at org.infinispan.CacheSupport.put(CacheSupport.java:53)
	at org.radargun.cachewrappers.InfinispanWrapper.put(InfinispanWrapper.java:244)
	at org.radargun.cachewrappers.InfinispanExplicitLockingWrapper.put(InfinispanExplicitLockingWrapper.java:72)
	at org.radargun.cachewrappers.InfinispanQueryWrapper.put(InfinispanQueryWrapper.java:79)
	at org.radargun.stressors.StressTestStressor$FixedSetPerThreadOperationLogic.init(StressTestStressor.java:313)
	at org.radargun.stressors.StressTestStressor$Stressor.run(StressTestStressor.java:541)
17:20:27,448 ERROR [InvocationContextInterceptor] ISPN000136: Execution error
org.infinispan.util.concurrent.TimeoutException: Replication timeout for amanukyan-2185
	at org.infinispan.remoting.transport.AbstractTransport.parseResponseAndAddToResponseList(AbstractTransport.java:113)
	at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:541)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:169)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:190)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:247)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:234)
	at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:229)
	at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:208)
	at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:200)
	at org.infinispan.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:297)
	at org.infinispan.interceptors.ReplicationInterceptor.visitPutKeyValueCommand(ReplicationInterceptor.java:248)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:275)
	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:166)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.query.backend.QueryInterceptor.visitPutKeyValueCommand(QueryInterceptor.java:127)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitPutKeyValueCommand(NonTransactionalLockingInterceptor.java:71)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216)
	at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194)
	at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92)
	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
	at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1186)
	at org.infinispan.CacheImpl.putInternal(CacheImpl.java:783)
	at org.infinispan.CacheImpl.put(CacheImpl.java:777)
	at org.infinispan.CacheImpl.put(CacheImpl.java:771)
	at org.infinispan.CacheSupport.put(CacheSupport.java:53)
	at org.radargun.cachewrappers.InfinispanWrapper.put(InfinispanWrapper.java:244)
	at org.radargun.cachewrappers.InfinispanExplicitLockingWrapper.put(InfinispanExplicitLockingWrapper.java:72)
	at org.radargun.cachewrappers.InfinispanQueryWrapper.put(InfinispanQueryWrapper.java:79)
	at org.radargun.stressors.StressTestStressor$FixedSetPerThreadOperationLogic.init(StressTestStressor.java:313)
	at org.radargun.stressors.StressTestStressor$Stressor.run(StressTestStressor.java:541)

..... and so on

      Problem 4:

      Configuration: JDBC cache store - shared=false, indexLocalOnly=true

      In this case for both 3 and 4 nodes happens the case described in Problem 1.b .

        1. clustered-config.xml
          7 kB

              Unassigned Unassigned
              amanukya@redhat.com Anna Manukyan
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated:
                Resolved: