[JBoss JIRA] (ISPN-3405) Entries are passivated with wrong ID in DB
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-3405?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño updated ISPN-3405:
-----------------------------------
Fix Version/s: 6.0.0.Final
> Entries are passivated with wrong ID in DB
> ------------------------------------------
>
> Key: ISPN-3405
> URL: https://issues.jboss.org/browse/ISPN-3405
> Project: Infinispan
> Issue Type: Bug
> Components: Eviction
> Affects Versions: 6.0.0.Alpha1
> Reporter: Vitalii Chepeliuk
> Assignee: Galder Zamarreño
> Fix For: 6.0.0.Final
>
>
> Entry passivation into DB, concretly this class LockSupportCacheStore and method store. Look at lines with "<<<" string for more info
> {code:title=Bar.java|borderStyle=solid}
> @Override
> public final void store(InternalCacheEntry ed) throws CacheLoaderException {
> if (trace) {
> log.tracef("store(%s)", ed);
> }
> if (ed == null) {
> return;
> }
> if (ed.canExpire() && ed.isExpired(timeService.wallClockTime())) {
> if (containsKey(ed.getKey())) {
> if (trace) {
> log.tracef("Entry %s is expired! Removing!", ed);
> }
> remove(ed.getKey());
> } else {
> if (trace) {
> log.tracef("Entry %s is expired! Not doing anything.", ed);
> }
> }
> return;
> }
> L keyHashCode = getLockFromKey(ed.getKey()); <<< here key is generated like ed.getKey().hashCode() & 0xfffffc00;
> lockForWriting(keyHashCode);
> try {
> storeLockSafe(ed, keyHashCode); <<< here it should be stored into Bucket and then stored in DB
> } finally {
> unlock(keyHashCode);
> }
> if (trace) {
> log.tracef("exit store(%s)", ed);
> }
> }
> {code}
> When I use RemoteCacheManager and RemoteCache I am putting entries into cache
> {code:title=Bar.java|borderStyle=solid}
> cache.put("key1", "v1");
> cache.put("key2", "v2");
> cache.put("key3", "v3");
> {code}
> Then 2 entries are passivated and stored in DB
> ||ID||DATA||TIMESTAMP||
> |183713792|0301fe032a01034c422b21033e286d7942657374506572736f6e616c4b657957686963684861734e657665724265656e426574746572420521033e02763203620003630000000000000002|-1|
> |23486464|0301fe032a01034c420721033e046b657931420521033e02763103620003630000000000000001|-1|
> IDs are generated from method above and
> {code:title=Bar.java|borderStyle=solid}
> byte[] keyBytes = marshaller.objectToByteBuffer("key1"); <<< key is marshalled
> long keyID = ByteArrayEquivalence.INSTANCE.hashCode(keyBytes) & 0xfffffc00 //computation taken from BucketBasedCacheStore <<< this does not work for me
> ode}
> And next step I'd like to retrieve data from DB
> SELECT ID, DATA FROM JDBC_BINARY_DEFAULT WHERE ID=keyID
> But in method
> {code:title=Bar.java|borderStyle=solid}
> @Override
> public Integer getLockFromKey(Object key) {
> return key.hashCode() & 0xfffffc00; <<< here should be used Arrays.hashCode((byte[])key) & 0xfffffc00), if key is represented as byte array, or used ByteArrayEquivalence instead of simple byte array(byte[]) as argument
> }
> {code}
--
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
10 years, 10 months
[JBoss JIRA] (ISPN-3406) Reading entry via HotRod fails in compatibility mode for non-local entry if stored via Embedded cache
by Martin Gencur (JIRA)
[ https://issues.jboss.org/browse/ISPN-3406?page=com.atlassian.jira.plugin.... ]
Martin Gencur reassigned ISPN-3406:
-----------------------------------
Assignee: Galder Zamarreño (was: Mircea Markus)
> 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: Galder Zamarreño
>
> 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
> {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@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]
> {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
10 years, 10 months
[JBoss JIRA] (ISPN-3406) Reading entry via HotRod fails in compatibility mode for non-local entry if stored via Embedded cache
by Martin Gencur (JIRA)
[ https://issues.jboss.org/browse/ISPN-3406?page=com.atlassian.jira.plugin.... ]
Martin Gencur commented on ISPN-3406:
-------------------------------------
The test case can be found at https://github.com/mgencur/infinispan/commit/689a0b0bb1a064a0234820d824b2...
According to logging that I added to TypeConverterInterceptor, it seems that an EmbeddedTypeConverter is used to store entries into the embedded cache but HotRodTypeConverter is used when reading the entry via HotRod on another node. But this only happens if the entry is not located in the HotRod's endpoint local node.
> 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@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@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]
> {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
10 years, 10 months
[JBoss JIRA] (ISPN-3406) Reading entry via HotRod fails in compatibility mode for non-local entry if stored via Embedded cache
by Martin Gencur (JIRA)
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@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@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]
{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
10 years, 10 months
[JBoss JIRA] (ISPN-3403) NullPointerException when invoking JMX operation with debug logging enabled
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-3403?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño resolved ISPN-3403.
------------------------------------
Fix Version/s: 6.0.0.Alpha3
Resolution: Done
> NullPointerException when invoking JMX operation with debug logging enabled
> ---------------------------------------------------------------------------
>
> Key: ISPN-3403
> URL: https://issues.jboss.org/browse/ISPN-3403
> Project: Infinispan
> Issue Type: Bug
> Affects Versions: 6.0.0.Alpha2
> Reporter: Fabian Stäber
> Assignee: Mircea Markus
> Fix For: 6.0.0.Alpha3
>
>
> When the CLI client runs the "cache ___defaultcache" command to select a cache, the first things that happens is that the "createSessionId" call is invoked via JMX on the server.
> When the command is run for the first time, there is no previously selected cache. Therefore, the "active cache" parameter for the "createSessionId" command is null.
> On the server side, in ResourceDMBean.invoke(), there is a debug log message that would log the class of the arguments received using args[i].getClass(). As args[i] is null for the "active cache" parameter, the call fails with a NullPointerException.
> As a result, it is not possible to select a cache with the CLI client when debug logging is enabled in ResourceDMBean.
> ---
> I have created a very small pull request for this on GitHub.
--
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
10 years, 10 months
[JBoss JIRA] (ISPN-3345) CachePutInterceptorTest does not always close cache managers
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-3345?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño commented on ISPN-3345:
----------------------------------------
Pete and I discovered that there's an extra cache manager being created since ISPN-3208 was fixed. We're trying to solve it, together with ISPN-3349.
> CachePutInterceptorTest does not always close cache managers
> ------------------------------------------------------------
>
> Key: ISPN-3345
> URL: https://issues.jboss.org/browse/ISPN-3345
> Project: Infinispan
> Issue Type: Bug
> Components: CDI integration
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Labels: testsuite_stability
> Fix For: 6.0.0.Alpha3
>
>
> Sometimes CDI's CachePutInterceptorTest fails to close all cache managers:
> {code}
> [16:39:06][org.infinispan:infinispan-cdi] [testng-CachePutInterceptorTest] Test putWithCacheKeyGenerator(org.infinispan.cdi.test.interceptor.CachePutInterceptorTest) succeeded.
> [16:39:06][org.infinispan:infinispan-cdi] Test suite progress: tests succeeded: 29, failed: 0, skipped: 0.
> [16:39:07][org.infinispan:infinispan-cdi] [testng-CachePutInterceptorTest] Test testCachePut(org.infinispan.cdi.test.interceptor.CachePutInterceptorTest) succeeded.
> [16:39:07][org.infinispan:infinispan-cdi] Test suite progress: tests succeeded: 30, failed: 0, skipped: 0.
> [16:39:07][org.infinispan:infinispan-cdi] [testng-CachePutInterceptorTest] Test testCachePutBeforeInvocation(org.infinispan.cdi.test.interceptor.CachePutInterceptorTest) succeeded.
> [16:39:07][org.infinispan:infinispan-cdi] Test suite progress: tests succeeded: 31, failed: 0, skipped: 0.
> [16:39:07][org.infinispan:infinispan-cdi] [testng-CachePutInterceptorTest] Test testCachePutCacheKeyParam(org.infinispan.cdi.test.interceptor.CachePutInterceptorTest) succeeded.
> [16:39:07][org.infinispan:infinispan-cdi] Test suite progress: tests succeeded: 32, failed: 0, skipped: 0.
> [16:39:07][org.infinispan:infinispan-cdi] [testng-CachePutInterceptorTest] Test testCachePutWithCacheName(org.infinispan.cdi.test.interceptor.CachePutInterceptorTest) succeeded.
> [16:39:07][org.infinispan:infinispan-cdi] Test suite progress: tests succeeded: 33, failed: 0, skipped: 0.
> [16:40:07][org.infinispan:infinispan-cdi]
> [16:40:07][org.infinispan:infinispan-cdi] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
> [16:40:07][org.infinispan:infinispan-cdi] !!!!!! (testng-CachePutInterceptorTest) Exiting because CachePutInterceptorTest has NOT shut down all the cache managers it has started !!!!!!!
> [16:40:07][org.infinispan:infinispan-cdi] !!!!!! (testng-CachePutInterceptorTest) The still-running cacheManager was created here: org.infinispan.cdi.AdvancedCacheProducer.getAdvancedCache(AdvancedCacheProducer.java:67) !!!!!!!
> [16:40:07][org.infinispan:infinispan-cdi] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
> [16:40:07][org.infinispan:infinispan-cdi] {code}
--
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
10 years, 10 months
[JBoss JIRA] (ISPN-3366) Data loss when entry forwarding to primary owner and primary owner shutdown
by Takayoshi Kimura (JIRA)
[ https://issues.jboss.org/browse/ISPN-3366?page=com.atlassian.jira.plugin.... ]
Takayoshi Kimura commented on ISPN-3366:
----------------------------------------
Verified the fix with 5.2.x branch.
For putIfAbsent commands, is it something we can fix within ISPN-3357?
> Data loss when entry forwarding to primary owner and primary owner shutdown
> ---------------------------------------------------------------------------
>
> Key: ISPN-3366
> URL: https://issues.jboss.org/browse/ISPN-3366
> Project: Infinispan
> Issue Type: Bug
> Components: Distributed Cache
> Affects Versions: 5.2.4.Final, 6.0.0.Alpha1
> Reporter: Takayoshi Kimura
> Assignee: Dan Berindei
> Priority: Critical
> Fix For: 5.2.8.Final, 6.0.0.Alpha3, 6.0.0.Final
>
> Attachments: ISPN-3366-full-logs-3rd.zip, ISPN-3366-full-logs-4th.zip, ISPN-3366-logs.zip
>
>
> Looks like a problem in entry forwarding.
> Here is test scenario:
> * DIST numOwners=2, start with 4 nodes cluster then normal shutdown 1 node during load
> * HotRod putIfAbsent accesses from 40 threads (1 process, 1 remote cache instance), 40000 entries total
> After the test run, the numberOfEntries on each node are:
> * node1: 26608
> * node2: 26622
> * node3: 26746
> * node4: 0
> Total is 79976 and HotRod client received 11 errors, so 79976 + (11 * 2) = 79998. It means 1 entry is completely missing.
> Let's take a look at the missing entry, hash(thread16key59) = 574ff563.
> Current CH: owners(574ff563) are [node4, node1]
> The events sequence is:
> * hotrod -> node1
> * node1 forwarding it to primary owner node4
> * node4 doesn't process the forwarded entry, shutdown
> Result owners(7c29bccb) is [] empty. This entry is completely lost without any errors.
--
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
10 years, 10 months
[JBoss JIRA] (ISPN-3389) Forwarded transactions can remain stale after state transfer
by Mircea Markus (JIRA)
[ https://issues.jboss.org/browse/ISPN-3389?page=com.atlassian.jira.plugin.... ]
Mircea Markus updated ISPN-3389:
--------------------------------
Fix Version/s: 6.0.0.CR1
6.0.0.Final
> Forwarded transactions can remain stale after state transfer
> ------------------------------------------------------------
>
> Key: ISPN-3389
> URL: https://issues.jboss.org/browse/ISPN-3389
> Project: Infinispan
> Issue Type: Bug
> Components: State transfer
> Affects Versions: 5.2.7.Final
> Reporter: Erik Salter
> Assignee: Dan Berindei
> Fix For: 6.0.0.CR1, 6.0.0.Final
>
>
> There is a scenario where a tx started on one node, moved during state transfer, and committed on the originating node won't be removed from the new owner's tx table.
> The chain of events is as follows:
> 1. New topology comes in as part of a view change.
> 2. Local transaction started with the new topology ID. This transaction was started due to a LockControlCommand and has no modifications. Also important, it only has local locks.
> 3. Tx forwarded to new owner before the local lock is acquired and registered with the transaction.
> 4. Since the tx has only local locks and no modifications, it is only removed locally. No TxCompletion or Rollback are broadcast to the new owners.
> This key becomes unusable not due to stale locks, but because the waitForTransaction() code will see that the old tx can "potentially" lock the key.
> This easily happens with pessimistic caches, though I have seen it happen with optimistic caches (there is a delta between the transaction being created and the lock registration).
--
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
10 years, 10 months
[JBoss JIRA] (ISPN-3389) Forwarded transactions can remain stale after state transfer
by Mircea Markus (JIRA)
[ https://issues.jboss.org/browse/ISPN-3389?page=com.atlassian.jira.plugin.... ]
Mircea Markus updated ISPN-3389:
--------------------------------
Labels: 5.2.x (was: )
> Forwarded transactions can remain stale after state transfer
> ------------------------------------------------------------
>
> Key: ISPN-3389
> URL: https://issues.jboss.org/browse/ISPN-3389
> Project: Infinispan
> Issue Type: Bug
> Components: State transfer
> Affects Versions: 5.2.7.Final
> Reporter: Erik Salter
> Assignee: Dan Berindei
> Labels: 5.2.x
> Fix For: 6.0.0.CR1, 6.0.0.Final
>
>
> There is a scenario where a tx started on one node, moved during state transfer, and committed on the originating node won't be removed from the new owner's tx table.
> The chain of events is as follows:
> 1. New topology comes in as part of a view change.
> 2. Local transaction started with the new topology ID. This transaction was started due to a LockControlCommand and has no modifications. Also important, it only has local locks.
> 3. Tx forwarded to new owner before the local lock is acquired and registered with the transaction.
> 4. Since the tx has only local locks and no modifications, it is only removed locally. No TxCompletion or Rollback are broadcast to the new owners.
> This key becomes unusable not due to stale locks, but because the waitForTransaction() code will see that the old tx can "potentially" lock the key.
> This easily happens with pessimistic caches, though I have seen it happen with optimistic caches (there is a delta between the transaction being created and the lock registration).
--
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
10 years, 10 months
[JBoss JIRA] (ISPN-3389) Forwarded transactions can remain stale after state transfer
by Mircea Markus (JIRA)
[ https://issues.jboss.org/browse/ISPN-3389?page=com.atlassian.jira.plugin.... ]
Mircea Markus updated ISPN-3389:
--------------------------------
Priority: Critical (was: Major)
> Forwarded transactions can remain stale after state transfer
> ------------------------------------------------------------
>
> Key: ISPN-3389
> URL: https://issues.jboss.org/browse/ISPN-3389
> Project: Infinispan
> Issue Type: Bug
> Components: State transfer
> Affects Versions: 5.2.7.Final
> Reporter: Erik Salter
> Assignee: Dan Berindei
> Priority: Critical
> Labels: 5.2.x
> Fix For: 6.0.0.CR1, 6.0.0.Final
>
>
> There is a scenario where a tx started on one node, moved during state transfer, and committed on the originating node won't be removed from the new owner's tx table.
> The chain of events is as follows:
> 1. New topology comes in as part of a view change.
> 2. Local transaction started with the new topology ID. This transaction was started due to a LockControlCommand and has no modifications. Also important, it only has local locks.
> 3. Tx forwarded to new owner before the local lock is acquired and registered with the transaction.
> 4. Since the tx has only local locks and no modifications, it is only removed locally. No TxCompletion or Rollback are broadcast to the new owners.
> This key becomes unusable not due to stale locks, but because the waitForTransaction() code will see that the old tx can "potentially" lock the key.
> This easily happens with pessimistic caches, though I have seen it happen with optimistic caches (there is a delta between the transaction being created and the lock registration).
--
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
10 years, 10 months