[ https://issues.jboss.org/browse/ISPN-4424?page=com.atlassian.jira.plugin.... ] Galder Zamarreño edited comment on ISPN-4424 at 6/23/14 4:03 AM: ----------------------------------------------------------------- {code} 17109 TRACE [org.infinispan.client.hotrod.impl.protocol.Codec20] (pool-7-thread-2:) Wrote header for message 6561. Operation code: 0x11. Flags: 0x0 17111 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-5-2:) Decoded header HotRodHeader{op=GetWithVersionRequest, version=20, messageId=6561, cacheName=, flag=0, clientIntelligence=3, topologyId=2} 17113 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-5-2:) Write response GetWithVersionResponse{version=20, messageId=6561, operation=GetWithVersionResponse, status=Success, data=[B0x034b000001cf,h=3e25a7d7], dataVersion=281479271678483} {code} ^ A client thread requests an entry's versioned data. This returns 463 (...000001cf) and version 281479271678483. With the version and previous value in place, client calls replaceWithVersion(key, 464, 281479271678483), with the intention to update the entry to 464 value if the version is still 281479271678483. Server side, we see the server requesting the cached entry and finding 463 as value and 281479271678483 version: {code}17126 TRACE [org.infinispan.interceptors.CallInterceptor] (HotRodServerWorker-3-1:___defaultcache) Executing command: GetKeyValueCommand {key=[B0x033e07484f47454b..[10], flags=[SKIP_LISTENER_NOTIFICATION]} 17126 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (HotRodServerWorker-3-1:___defaultcache) Found entry MetadataImmortalCacheEntry{key=[B0x033e07484f47454b..[10], value=[B0x034b000001cf, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678483}}}{code} In parallel, an entry update happens: {code}17126 TRACE [org.infinispan.container.DefaultDataContainer] (remote-thread-NodeA-p3-t1:___defaultcache) Creating new ICE for writing. Existing=MetadataImmortalCacheEntry{key=[B0x033e07484f47454b..[10], value=[B0x034b000001cf, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678483}}}, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678485}}, new value=[B@7b55e60d 17126 TRACE [org.infinispan.container.DefaultDataContainer] (remote-thread-NodeA-p3-t1:___defaultcache) Store MetadataImmortalCacheEntry{key=[B0x033e07484f47454b..[10], value=[B0x034b000001d0, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678485}}} in container{code} Entry is now updated to value 464 (...000001d0) and version 281479271678485. However, the server ends up calling replace with the old value being 464 but it somehow passed the if condition where the version should be 281479271678483 (new version to be applied shown in the logs): {code}17126 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (HotRodServerWorker-3-1:___defaultcache) Invoked with command ReplaceCommand{key=[B0x033e07484f47454b..[10], oldValue=[B0x034b000001d0, newValue=[B0x034b000001d0, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678486}}, flags=null, successful=true, valueMatcher=MATCH_EXPECTED} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@2feeb01e]{code} One way to solve this issue would be to add synchronisation but that would hurt performance badly. The real problem though is the fact that when the server calls getCacheEntry(), this returns a mutable cache entry. This entry cannot be directly mutated by the client but can indeed mutated by the server, and in fact it does so when it calls InternalCacheEntryFactory.update() method. One way to solve this might be getCacheEntry to return a true immutable cache entry, whose call reordering cannot lead to race conditions such as this. was (Author: galder.zamarreno): {code} 17109 TRACE [org.infinispan.client.hotrod.impl.protocol.Codec20] (pool-7-thread-2:) Wrote header for message 6561. Operation code: 0x11. Flags: 0x0 17111 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-5-2:) Decoded header HotRodHeader{op=GetWithVersionRequest, version=20, messageId=6561, cacheName=, flag=0, clientIntelligence=3, topologyId=2} 17113 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-5-2:) Write response GetWithVersionResponse{version=20, messageId=6561, operation=GetWithVersionResponse, status=Success, data=[B0x034b000001cf,h=3e25a7d7], dataVersion=281479271678483} {code} ^ A client thread requests an entry's versioned data. This returns 463 (...000001cf) and version 281479271678483. With the version and previous value in place, client calls replaceWithVersion(key, 464, 281479271678483), with the intention to update the entry to 464 value if the version is still 281479271678483. Server side, we see the server requesting the cached entry and finding 463 as value and 281479271678483 version: {code}17126 TRACE [org.infinispan.interceptors.CallInterceptor] (HotRodServerWorker-3-1:___defaultcache) Executing command: GetKeyValueCommand {key=[B0x033e07484f47454b..[10], flags=[SKIP_LISTENER_NOTIFICATION]} 2014-06-20 16:16:56,815 17126 TRACE [org.infinispan.commands.read.GetKeyValueCommand] (HotRodServerWorker-3-1:___defaultcache) Found entry MetadataImmortalCacheEntry{key=[B0x033e07484f47454b..[10], value=[B0x034b000001cf, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678483}}}{code} In parallel, an entry update happens: {code}17126 TRACE [org.infinispan.container.DefaultDataContainer] (remote-thread-NodeA-p3-t1:___defaultcache) Creating new ICE for writing. Existing=MetadataImmortalCacheEntry{key=[B0x033e07484f47454b..[10], value=[B0x034b000001cf, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678483}}}, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678485}}, new value=[B@7b55e60d 17126 TRACE [org.infinispan.container.DefaultDataContainer] (remote-thread-NodeA-p3-t1:___defaultcache) Store MetadataImmortalCacheEntry{key=[B0x033e07484f47454b..[10], value=[B0x034b000001d0, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678485}}} in container{code} Entry is now updated to value 464 (...000001d0) and version 281479271678485. However, the server ends up calling replace with the old value being 464 but it somehow passed the if condition where the version should be 281479271678483 (new version to be applied shown in the logs): {code}17126 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (HotRodServerWorker-3-1:___defaultcache) Invoked with command ReplaceCommand{key=[B0x033e07484f47454b..[10], oldValue=[B0x034b000001d0, newValue=[B0x034b000001d0, metadata=EmbeddedMetadata{version=NumericVersion{version=281479271678486}}, flags=null, successful=true, valueMatcher=MATCH_EXPECTED} and InvocationContext [org.infinispan.context.SingleKeyNonTxInvocationContext@2feeb01e]{code} One way to solve this issue would be to add synchronisation but that would hurt performance badly. The real problem though is the fact that when the server calls getCacheEntry(), this returns a mutable cache entry. This entry cannot be directly mutated by the client but can indeed mutated by the server, and in fact it does so when it calls InternalCacheEntryFactory.update() method. One way to solve this might be getCacheEntry to return a true immutable cache entry, whose call reordering cannot lead to race conditions such as this. -- This message was sent by Atlassian JIRA (v6.2.6#6264)