[infinispan-issues] [JBoss JIRA] (ISPN-5280) Random TimeoutException in Infinispan Hibernate L2 cache when put a load

Eranga Samararathna (JIRA) issues at jboss.org
Wed Mar 11 05:14:18 EDT 2015


    [ https://issues.jboss.org/browse/ISPN-5280?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13048819#comment-13048819 ] 

Eranga Samararathna commented on ISPN-5280:
-------------------------------------------

The TimeoutException is expected here and not to be considered a problem. So presumably nothing should be logged in ERROR level.

> Random TimeoutException in Infinispan Hibernate L2 cache when put a load
> ------------------------------------------------------------------------
>
>                 Key: ISPN-5280
>                 URL: https://issues.jboss.org/browse/ISPN-5280
>             Project: Infinispan
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 5.3.0.Final
>            Reporter: Eranga Samararathna
>
> I am using Infinispan as a hibernate L2 cache. In a normal load system running without an issue. But when load put into the system the following exception was thrown from the cache cluster. Even though this not causing a functional impact reporting an ERROR seems a problem.
> Error log
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.interceptors.CallInterceptor - Executing command: RemoveCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@ac27701, value=null, flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], ignorePreviousValue=false}.
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.commands.write.RemoveCommand - Nothing to remove since the entry is null or we have a null entry
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.remoting.rpc.RpcManagerImpl - cosmos-db2-30512 invoking RemoveCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@ac27701, value=null, flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], ignorePreviousValue=false} to recipient list null with options RpcOptions{timeout=20000, unit=MILLISECONDS, fifoOrder=true, totalOrder=false, responseFilter=null, responseMode=SYNCHRONOUS, skipReplicationQueue=false}
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.remoting.transport.jgroups.JGroupsTransport - dests=null, command=SingleRpcCommand{cacheName='Order', command=RemoveCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@ac27701, value=null, flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], ignorePreviousValue=false}}, mode=SYNCHRONOUS, timeout=20000
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher - Replication task sending SingleRpcCommand{cacheName='Order', command=RemoveCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@ac27701, value=null, flags=[SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP], ignorePreviousValue=false}} to single recipient cosmos-db2-29372 with response mode GET_ALL
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.marshall.AdaptiveBufferSizePredictor - Next predicted buffer size for object type 'org.infinispan.commands.remote.SingleRpcCommand' will be 1536
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.marshall.VersionAwareMarshaller - Wrote version 510
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Start unmarshaller after retrieving marshaller from thread local
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.VersionAwareMarshaller - Read version 510
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.marshall.AdaptiveBufferSizePredictor - Next predicted buffer size for object type 'org.infinispan.commands.remote.SingleRpcCommand' will be 512
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Start unmarshaller after retrieving marshaller from factory
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.VersionAwareMarshaller - Read version 510
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Stop unmarshaller
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.marshall.VersionAwareMarshaller - Wrote version 510
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Stop unmarshaller
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher - Attempting to execute command: SingleRpcCommand{cacheName='Order', command=PutKeyValueCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2022, array=0x0301fe0409000000..}, cachedHashCode=1103892469}@40c6375, flags=[ZERO_LOCK_ACQUISITION_TIMEOUT, FORCE_ASYNCHRONOUS, SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP, PUT_FOR_EXTERNAL_READ], putIfAbsent=true, metadata=EmbeddedMetadata{version=null}, successful=true}} [sender=cosmos-db2-29372]
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Stop marshaller
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [remote-thread-0] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Stop marshaller
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.remoting.InboundInvocationHandlerImpl - Calling perform() on SingleRpcCommand{cacheName='Order', command=PutKeyValueCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2022, array=0x0301fe0409000000..}, cachedHashCode=1103892469}@40c6375, flags=[ZERO_LOCK_ACQUISITION_TIMEOUT, FORCE_ASYNCHRONOUS, SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP, PUT_FOR_EXTERNAL_READ], putIfAbsent=true, metadata=EmbeddedMetadata{version=null}, successful=true}}
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.commands.remote.BaseRpcInvokingCommand - Invoking command PutKeyValueCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2022, array=0x0301fe0409000000..}, cachedHashCode=1103892469}@40c6375, flags=[ZERO_LOCK_ACQUISITION_TIMEOUT, FORCE_ASYNCHRONOUS, SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP, PUT_FOR_EXTERNAL_READ], putIfAbsent=true, metadata=EmbeddedMetadata{version=null}, successful=true}, with originLocal flag set to false
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.interceptors.InvocationContextInterceptor - Invoked with command PutKeyValueCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2022, array=0x0301fe0409000000..}, cachedHashCode=1103892469}@40c6375, flags=[ZERO_LOCK_ACQUISITION_TIMEOUT, FORCE_ASYNCHRONOUS, SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP, PUT_FOR_EXTERNAL_READ], putIfAbsent=true, metadata=EmbeddedMetadata{version=null}, successful=true} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext at 49559866]
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Marshallable type 'org.infinispan.marshall.MarshalledValue' known and is marshallable=true
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Marshallable type 'org.infinispan.marshall.MarshalledValue' known and is marshallable=true
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.statetransfer.StateTransferInterceptor - handleTopologyAffectedCommand for command PutKeyValueCommand{key=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2, value=MarshalledValue{instance=<serialized>, serialized=ByteArray{size=2022, array=0x0301fe0409000000..}, cachedHashCode=1103892469}@40c6375, flags=[ZERO_LOCK_ACQUISITION_TIMEOUT, FORCE_ASYNCHRONOUS, SKIP_CACHE_LOAD, SKIP_REMOTE_LOOKUP, PUT_FOR_EXTERNAL_READ], putIfAbsent=true, metadata=EmbeddedMetadata{version=null}, successful=true}
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor - Are (cosmos-db2-30512) we the lock owners for key 'MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2'? true
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.util.concurrent.locks.LockManagerImpl - Attempting to lock MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2 with acquisition timeout of 0 millis
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.util.concurrent.locks.containers.ReentrantPerEntryLockContainer - Timed out attempting to acquire lock for key MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2 after 0 milliseconds
> 2015-03-09 11:33:07 DEBUG [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.util.concurrent.locks.LockManagerImpl - Failed to acquire lock MarshalledValue{instance=<serialized>, serialized=ByteArray{size=1267, array=0x0301fe0409000000..}, cachedHashCode=1519}@545404b2, owner is Thread[remote-thread-0,5,main]
> 2015-03-09 11:33:07 DEBUG [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.util.concurrent.locks.LockManagerImpl - This transaction (Thread[Incoming-1,cosmos-db2-30512,5,main]) already owned locks []
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Start unmarshaller after retrieving marshaller from thread local
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.VersionAwareMarshaller - Read version 510
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Stop unmarshaller
> 2015-03-09 11:33:07 ERROR [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.interceptors.InvocationContextInterceptor - ISPN000136: Execution error
> org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [0 milliseconds] on key [Order#1] for requestor [Thread[Incoming-1,cosmos-db2-30512,5,main]]! Lock held by [Thread[remote-thread-0,5,main]]
>     at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:214)
>     at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:197)
>     at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:149)
>     at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:145)
>     at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:69)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.MarshalledValueInterceptor.visitPutKeyValueCommand(MarshalledValueInterceptor.java:154)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     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:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:160)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.interceptors.IsMarshallableInterceptor.visitPutKeyValueCommand(IsMarshallableInterceptor.java:111)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     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:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.hibernate.cache.infinispan.impl.ClassLoaderAwareCache$ClassLoaderAwareCommandInterceptor.handleDefault(ClassLoaderAwareCache.java:79)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     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:122)
>     at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:205)
>     at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:111)
>     at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:281)
>     at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:233)
>     at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:460)
>     at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:377)
>     at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:247)
>     at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:667)
>     at org.jgroups.JChannel.up(JChannel.java:730)
>     at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1019)
>     at org.jgroups.stack.Protocol.up(Protocol.java:409)
>     at org.jgroups.protocols.RSVP.up(RSVP.java:221)
>     at org.jgroups.protocols.FRAG2.up(FRAG2.java:182)
>     at org.jgroups.protocols.FlowControl.up(FlowControl.java:434)
>     at org.jgroups.protocols.FlowControl.up(FlowControl.java:434)
>     at org.jgroups.stack.Protocol.up(Protocol.java:409)
>     at org.jgroups.protocols.SEQUENCER.up(SEQUENCER.java:270)
>     at org.jgroups.stack.Protocol.up(Protocol.java:409)
>     at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:294)
>     at org.jgroups.protocols.UNICAST3.removeAndDeliver(UNICAST3.java:792)
>     at org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:704)
>     at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:382)
>     at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:600)
>     at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147)
>     at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:184)
>     at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:301)
>     at org.jgroups.protocols.MERGE3.up(MERGE3.java:303)
>     at org.jgroups.protocols.Discovery.up(Discovery.java:379)
>     at org.jgroups.protocols.TP.passMessageUp(TP.java:1405)
>     at org.jgroups.protocols.TP$MyHandler.run(TP.java:1591)
>     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>     at java.lang.Thread.run(Thread.java:745)
> 2015-03-09 11:33:07 ERROR [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.remoting.InboundInvocationHandlerImpl - Exception executing command
> org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [0 milliseconds] on key [Order#1] for requestor [Thread[Incoming-1,cosmos-db2-30512,5,main]]! Lock held by [Thread[remote-thread-0,5,main]]
>     at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:214)
>     at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:197)
>     at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:149)
>     at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:145)
>     at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:69)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.MarshalledValueInterceptor.visitPutKeyValueCommand(MarshalledValueInterceptor.java:154)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     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:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:160)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.interceptors.IsMarshallableInterceptor.visitPutKeyValueCommand(IsMarshallableInterceptor.java:111)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     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:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120)
>     at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134)
>     at org.hibernate.cache.infinispan.impl.ClassLoaderAwareCache$ClassLoaderAwareCommandInterceptor.handleDefault(ClassLoaderAwareCache.java:79)
>     at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54)
>     at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83)
>     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:122)
>     at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:205)
>     at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:111)
>     at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:281)
>     at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:233)
>     at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:460)
>     at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:377)
>     at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:247)
>     at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:667)
>     at org.jgroups.JChannel.up(JChannel.java:730)
>     at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1019)
>     at org.jgroups.stack.Protocol.up(Protocol.java:409)
>     at org.jgroups.protocols.RSVP.up(RSVP.java:221)
>     at org.jgroups.protocols.FRAG2.up(FRAG2.java:182)
>     at org.jgroups.protocols.FlowControl.up(FlowControl.java:434)
>     at org.jgroups.protocols.FlowControl.up(FlowControl.java:434)
>     at org.jgroups.stack.Protocol.up(Protocol.java:409)
>     at org.jgroups.protocols.SEQUENCER.up(SEQUENCER.java:270)
>     at org.jgroups.stack.Protocol.up(Protocol.java:409)
>     at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:294)
>     at org.jgroups.protocols.UNICAST3.removeAndDeliver(UNICAST3.java:792)
>     at org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:704)
>     at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:382)
>     at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:600)
>     at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147)
>     at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:184)
>     at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:301)
>     at org.jgroups.protocols.MERGE3.up(MERGE3.java:303)
>     at org.jgroups.protocols.Discovery.up(Discovery.java:379)
>     at org.jgroups.protocols.TP.passMessageUp(TP.java:1405)
>     at org.jgroups.protocols.TP$MyHandler.run(TP.java:1591)
>     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>     at java.lang.Thread.run(Thread.java:745)
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [Incoming-1,cosmos-db2-30512] org.infinispan.remoting.InboundInvocationHandlerImpl - Unable to execute command, got invalid response ExceptionResponse
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [OOB-4,cosmos-db2-30512] org.infinispan.marshall.jboss.AbstractJBossMarshaller - Start unmarshaller after retrieving marshaller from thread local
> 2015-03-09 11:33:07 TRACE [tid=cosmos-db2-150309112549721-1602836942-0-1] [OOB-4,cosmos-db2-30512] org.infinispan.marshall.VersionAwareMarshaller - Read version 510



--
This message was sent by Atlassian JIRA
(v6.3.11#6341)


More information about the infinispan-issues mailing list