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

Reading entry via HotRod fails in compatibility mode for non-local entry if stored via Embedded cache

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • 6.0.0.Beta1, 6.0.0.Final
    • 5.3.0.Final, 6.0.0.Alpha2
    • None
    • None

    Description

      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@41c001f5>

      The following test case fails in DIST mode and numOwners=1

      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());
         }
      

      The relevant part of trace log is here:

      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@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@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@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@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@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@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@64b7716c}} , received=true, suspected=false]
      
      

      I'll provide the test case.

      Attachments

        Activity

          People

            mgencur Martin Gencur
            mgencur Martin Gencur
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: