[infinispan-issues] [JBoss JIRA] (ISPN-3406) Reading entry via HotRod fails in compatibility mode for non-local entry if stored via Embedded cache

Martin Gencur (JIRA) jira-events at lists.jboss.org
Tue Aug 13 04:54:26 EDT 2013 

Martin Gencur created ISPN-3406:
-----------------------------------

             Summary: Reading entry via HotRod fails in compatibility mode for non-local entry if stored via Embedded cache 
                 Key: ISPN-3406
                 URL: https://issues.jboss.org/browse/ISPN-3406
             Project: Infinispan
          Issue Type: Bug
    Affects Versions: 6.0.0.Alpha2
            Reporter: Martin Gencur
            Assignee: Mircea Markus


In DIST mode where numOwners<numNodes, reading an entry via HotRod fails if it was previously stored into an embedded cache and the entry is not local to the HotRod server endpoint.
The resulting value is a byte array instead of expected type:
expected:<v1> but was:<[B at 41c001f5>

The following test case fails in DIST mode and numOwners=1
{code:java}
public void testEmbeddedPutRestHotRodGet() throws Exception {
      final String key = "2";

      // 1. Put with Embedded
      assertEquals(null, cacheFactory2.getEmbeddedCache().put(key, "v1"));

      // 2. Get with Hot Rod
      assertEquals("v1", cacheFactory1.getHotRodCache().get(key));
//^^^^fails here
      // 3. Get with REST
      HttpMethod get = new GetMethod(cacheFactory2.getRestUrl() + "/" + key);
      cacheFactory2.getRestClient().executeMethod(get);
      assertEquals(HttpServletResponse.SC_OK, get.getStatusCode());
      assertEquals("v1", get.getResponseBodyAsString());
   }
{code}

The relevant part of trace log is here:
{code}
2013-08-13 10:42:35,299 INFO  (testng-DistEmbeddedRestHotRodTest) [org.infinispan.test.fwk.UnitTestTestNGListener] Starting test testEmbeddedPutRestHotRodGet(org.infinispan.it.compatibility.DistEmbeddedRestHotRodTest)
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.InvocationContextInterceptor] Invoked with command PutKeyValueCommand{key=2, value=v1, flags=null, putIfAbsent=false, metadata=EmbeddedMetadata{version=null}, successful=true} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext at 4677c9e2]
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.statetransfer.StateTransferInterceptor] handleTopologyAffectedCommand for command PutKeyValueCommand{key=2, value=v1, flags=null, putIfAbsent=false, metadata=EmbeddedMetadata{version=null}, successful=true}
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor] Are (DistEmbeddedRestHotRodTest-NodeB-63949) we the lock owners for key '2'? true
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.util.concurrent.locks.LockManagerImpl] Attempting to lock 2 with acquisition timeout of 10000 millis
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.util.concurrent.locks.containers.ReentrantPerEntryLockContainer] Creating and acquiring new lock instance for key 2
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.util.concurrent.locks.LockManagerImpl] Successfully acquired lock 2!
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.EntryWrappingInterceptor] Wrapping entry '2'? true
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.container.EntryFactoryImpl] Exists in context? null 
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.container.EntryFactoryImpl] Retrieved from container null
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.container.EntryFactoryImpl] Creating new entry.
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.container.EntryFactoryImpl] Wrap 2 for put. Entry=ReadCommittedEntry(62673892){key=2, value=null, oldValue=null, isCreated=true, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.distribution.NonTxDistributionInterceptor] Not doing a remote get for key 2 since entry is not affected by rehash or is already in data container. We are DistEmbeddedRestHotRodTest-NodeB-63949, owners are [DistEmbeddedRestHotRodTest-NodeB-63949]
2013-08-13 10:42:35,301 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.CallInterceptor] Executing command: PutKeyValueCommand{key=2, value=v1, flags=null, putIfAbsent=false, metadata=EmbeddedMetadata{version=null}, successful=true}.
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] I'm the primary owner, sending the command to all ([DistEmbeddedRestHotRodTest-NodeB-63949]) the recipients in order to be applied.
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.EntryWrappingInterceptor] About to commit entry ReadCommittedEntry(62673892){key=2, value=v1, oldValue=null, isCreated=true, isChanged=true, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.container.entries.ReadCommittedEntry] Updating entry (key=2 removed=false valid=true changed=true created=true loaded=false value=v1 metadata=EmbeddedMetadata{version=null})
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.interceptors.EntryWrappingInterceptor] The return value is null
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.util.concurrent.locks.LockManagerImpl] Attempting to unlock 2
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.util.concurrent.locks.containers.ReentrantPerEntryLockContainer] Unlocking lock instance for key 2
2013-08-13 10:42:35,302 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.statetransfer.StateTransferManagerImpl] CommandTopologyId=2, localTopologyId=2
2013-08-13 10:42:35,304 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop marshaller
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] Using consistent hash for determining the server: /127.0.0.1:15233
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TransportObjectFactory] Fetching from pool: TcpTransport{socket=Socket[addr=localhost/127.0.0.1,port=15233,localport=36161], serverAddress=localhost/127.0.0.1:15233, id =1} 
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] For server /127.0.0.1:15233: active = 1; idle = 0
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote byte 160
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote byte 12
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote byte 3
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote 0 bytes
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote byte 3
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote byte 0
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.protocol.Codec12] Wrote header for message 5. Operation code: 0x03. Flags: 0x0
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Wrote 4 bytes
2013-08-13 10:42:35,306 TRACE (testng-DistEmbeddedRestHotRodTest) [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransport] Flushed socket: Socket[addr=localhost/127.0.0.1,port=15233,localport=36161]
2013-08-13 10:42:35,306 TRACE (HotRodServerWorker-2) [org.infinispan.server.hotrod.HotRodDecoder] Decode using instance @62a7e5af
2013-08-13 10:42:35,307 TRACE (HotRodServerWorker-2) [org.infinispan.server.hotrod.Decoder10$] Operation code: 3 has been matched to GetRequest
2013-08-13 10:42:35,307 TRACE (HotRodServerWorker-2) [org.infinispan.server.hotrod.HotRodDecoder] Decoded header HotRodHeader{op=GetRequest, version=12, messageId=5, cacheName=, flag=0, clientIntelligence=3, topologyId=0}
2013-08-13 10:42:35,307 TRACE (HotRodServerWorker-2) [org.infinispan.server.hotrod.HotRodDecoder] Decode using instance @62a7e5af
2013-08-13 10:42:35,308 TRACE (HotRodServerWorker-2) [org.infinispan.interceptors.InvocationContextInterceptor] Invoked with command GetKeyValueCommand {key=[B0x033e0132..(4), flags=[OPERATION_HOTROD]} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext at 4bd56a3a]
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Start unmarshaller after retrieving marshaller from thread local
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop unmarshaller
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.statetransfer.StateTransferInterceptor] handleTopologyAffectedCommand for command GetKeyValueCommand {key=2, flags=[OPERATION_HOTROD]}
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.container.EntryFactoryImpl] Exists in context? null 
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.container.EntryFactoryImpl] Retrieved from container null
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.container.EntryFactoryImpl] Wrap 2 for read. Entry=null
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.interceptors.CallInterceptor] Executing command: GetKeyValueCommand {key=2, flags=[OPERATION_HOTROD]}.
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.commands.read.GetKeyValueCommand] Entry not found
2013-08-13 10:42:35,309 TRACE (HotRodServerWorker-2) [org.infinispan.interceptors.distribution.NonTxDistributionInterceptor] Doing a remote get for key 2
2013-08-13 10:42:35,311 TRACE (HotRodServerWorker-2) [org.infinispan.remoting.rpc.RpcManagerImpl] DistEmbeddedRestHotRodTest-NodeA-65464 invoking ClusteredGetCommand{key=2, flags=[OPERATION_HOTROD]} to recipient list [DistEmbeddedRestHotRodTest-NodeB-63949] with options RpcOptions{timeout=15000, unit=MILLISECONDS, fifoOrder=false, totalOrder=false, responseFilter=org.infinispan.remoting.responses.ClusteredGetResponseValidityFilter at 73d884a6, responseMode=WAIT_FOR_VALID_RESPONSE, skipReplicationQueue=false}
2013-08-13 10:42:35,311 TRACE (HotRodServerWorker-2) [org.infinispan.remoting.transport.jgroups.JGroupsTransport] dests=[DistEmbeddedRestHotRodTest-NodeB-63949], command=ClusteredGetCommand{key=2, flags=[OPERATION_HOTROD]}, mode=WAIT_FOR_VALID_RESPONSE, timeout=15000
2013-08-13 10:42:35,311 TRACE (HotRodServerWorker-2) [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] Replication task sending ClusteredGetCommand{key=2, flags=[OPERATION_HOTROD]} to addresses [DistEmbeddedRestHotRodTest-NodeB-63949] with response mode GET_FIRST
2013-08-13 10:42:35,311 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.MarshallableTypeHints] Cache a buffer size predictor for 'org.infinispan.commands.remote.ClusteredGetCommand' assuming its serializability is unknown
2013-08-13 10:42:35,311 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.AdaptiveBufferSizePredictor] Next predicted buffer size for object type 'org.infinispan.commands.remote.ClusteredGetCommand' will be 512
2013-08-13 10:42:35,311 TRACE (HotRodServerWorker-2) [org.infinispan.marshall.core.VersionAwareMarshaller] Wrote version 510
2013-08-13 10:42:35,312 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.MarshallableTypeHints] Cache a buffer size predictor for 'org.infinispan.commands.remote.ClusteredGetCommand' assuming its serializability is unknown
2013-08-13 10:42:35,312 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.AdaptiveBufferSizePredictor] Next predicted buffer size for object type 'org.infinispan.commands.remote.ClusteredGetCommand' will be 512
2013-08-13 10:42:35,312 TRACE (HotRodServerWorker-2) [org.infinispan.marshall.core.VersionAwareMarshaller] Wrote version 510
2013-08-13 10:42:35,312 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop marshaller
2013-08-13 10:42:35,312 TRACE (HotRodServerWorker-2) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop marshaller
2013-08-13 10:42:35,313 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Start unmarshaller after retrieving marshaller from thread local
2013-08-13 10:42:35,313 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.marshall.core.VersionAwareMarshaller] Read version 510
2013-08-13 10:42:35,313 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Start unmarshaller after retrieving marshaller from factory
2013-08-13 10:42:35,313 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.marshall.core.VersionAwareMarshaller] Read version 510
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop unmarshaller
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop unmarshaller
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] Attempting to execute command: ClusteredGetCommand{key=2, flags=[OPERATION_HOTROD]} [sender=DistEmbeddedRestHotRodTest-NodeA-65464]
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.remoting.InboundInvocationHandlerImpl] Calling perform() on ClusteredGetCommand{key=2, flags=[OPERATION_HOTROD]}
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.interceptors.InvocationContextInterceptor] Invoked with command GetKeyValueCommand {key=2, flags=[CACHE_MODE_LOCAL, SKIP_REMOTE_LOOKUP, OPERATION_HOTROD]} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext at 6d24bbbe]
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.statetransfer.StateTransferInterceptor] handleTopologyAffectedCommand for command GetKeyValueCommand {key=2, flags=[CACHE_MODE_LOCAL, SKIP_REMOTE_LOOKUP, OPERATION_HOTROD]}
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.container.EntryFactoryImpl] Exists in context? null 
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.container.EntryFactoryImpl] Retrieved from container ImmortalCacheEntry{key=2, value=v1}
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.container.EntryFactoryImpl] Wrap 2 for read. Entry=ImmortalCacheEntry{key=2, value=v1}
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.interceptors.CallInterceptor] Executing command: GetKeyValueCommand {key=2, flags=[CACHE_MODE_LOCAL, SKIP_REMOTE_LOOKUP, OPERATION_HOTROD]}.
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commands.read.GetKeyValueCommand] Found entry ImmortalCacheEntry{key=2, value=v1}
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.interceptors.EntryWrappingInterceptor] Entry for key 2 is not changed(ImmortalCacheEntry{key=2, value=v1}): not calling commitUpdate
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.MarshallableTypeHints] Cache a buffer size predictor for 'java.lang.String' assuming its serializability is unknown
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.AdaptiveBufferSizePredictor] Next predicted buffer size for object type 'java.lang.String' will be 512
2013-08-13 10:42:35,314 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop marshaller
2013-08-13 10:42:35,315 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.remoting.InboundInvocationHandlerImpl] About to send back response SuccessfulResponse{responseValue=ImmortalCacheValue {value=[B at 714d0d01}}  for command ClusteredGetCommand{key=2, flags=[OPERATION_HOTROD]}
2013-08-13 10:42:35,315 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.MarshallableTypeHints] Cache a buffer size predictor for 'org.infinispan.remoting.responses.SuccessfulResponse' assuming its serializability is unknown
2013-08-13 10:42:35,315 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.AdaptiveBufferSizePredictor] Next predicted buffer size for object type 'org.infinispan.remoting.responses.SuccessfulResponse' will be 512
2013-08-13 10:42:35,315 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.marshall.core.VersionAwareMarshaller] Wrote version 510
2013-08-13 10:42:35,315 TRACE (OOB-4,DistEmbeddedRestHotRodTest-NodeB-63949) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop marshaller
2013-08-13 10:42:35,315 TRACE (OOB-3,DistEmbeddedRestHotRodTest-NodeA-65464) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Start unmarshaller after retrieving marshaller from thread local
2013-08-13 10:42:35,315 TRACE (OOB-3,DistEmbeddedRestHotRodTest-NodeA-65464) [org.infinispan.marshall.core.VersionAwareMarshaller] Read version 510
2013-08-13 10:42:35,315 TRACE (OOB-3,DistEmbeddedRestHotRodTest-NodeA-65464) [org.infinispan.commons.marshall.jboss.AbstractJBossMarshaller] Stop unmarshaller
2013-08-13 10:42:35,315 TRACE (HotRodServerWorker-2) [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] Received response: SuccessfulResponse{responseValue=ImmortalCacheValue {value=[B at 64b7716c}}  from DistEmbeddedRestHotRodTest-NodeB-63949
2013-08-13 10:42:35,316 TRACE (HotRodServerWorker-2) [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] Responses: [sender=DistEmbeddedRestHotRodTest-NodeB-63949, retval=SuccessfulResponse{responseValue=ImmortalCacheValue {value=[B at 64b7716c}} , received=true, suspected=false]

{code}

I'll provide the test case.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

More information about the infinispan-issues mailing list