[jbosscache-issues] [JBoss JIRA] Created: (JBCACHE-1525) Cache.removeNode does not remove node when buddies are configured and called on instance which does not contains the node.
Jaroslaw Lewandowski (JIRA)
jira-events at lists.jboss.org
Thu Jul 30 11:24:29 EDT 2009
Cache.removeNode does not remove node when buddies are configured and called on instance which does not contains the node.
--------------------------------------------------------------------------------------------------------------------------
Key: JBCACHE-1525
URL: https://jira.jboss.org/jira/browse/JBCACHE-1525
Project: JBoss Cache
Issue Type: Bug
Security Level: Public (Everyone can see)
Components: Buddy Replication
Affects Versions: 3.0.0.GA
Reporter: Jaroslaw Lewandowski
Assignee: Manik Surtani
When tried to remove node from cache instance which had one budy and the budy on the other side possesed all the data it looks like the node still exists in the cluster.
The following test does shows the problem.
{code:java}
@Test
public void stealEachOtherData() throws Exception {
Cache<Object,Object> cacheOne = PojoCacheFactory.createCache("configuration/test-jgroups-budies.xml").getCache();
Cache<Object, Object> cacheTwo = PojoCacheFactory.createCache("configuration/test-jgroups-budies.xml").getCache();
Fqn fqn = Fqn.fromString("/test/blah");
String key = "key";
for (int i = 0; i < 100; i++) {
String value = "Value"+i;
cacheOne.put(fqn, key, value);
Node<Object,Object> node;
long timeOut = 3000L;
node = assertNotNullWithTimeOut(cacheTwo, fqn, timeOut);
assertEquals(value, node.get(key));
node = assertNotNullWithTimeOut(cacheOne, fqn, timeOut);
assertEquals(value, node.get(key));
_log.debug("BEFORE REMOVE");
cacheTwo.removeNode(fqn);
assertNull(cacheOne.getNode(fqn));
assertNull(cacheTwo.getNode(fqn));
}
}
private Node<Object, Object> assertNotNullWithTimeOut(Cache<Object, Object> cacheTwo, Fqn fqn, long timeOut) throws InterruptedException {
Node<Object, Object> node = null;
long start = System.currentTimeMillis();
do {
node = cacheTwo.getNode(fqn);
Thread.sleep(50l);
} while (node == null && (System.currentTimeMillis() - start < timeOut));
assertNotNull(node);
return node;
}
{code}
here is the configuration
{code:xml}
<?xml version="1.0" encoding="UTF-8" ?>
<jbosscache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns="urn:jboss:jbosscache-core:config:3.0">
<locking
isolationLevel="REPEATABLE_READ"
lockParentForChildInsertRemove="false"
lockAcquisitionTimeout="20000"
nodeLockingScheme="mvcc"
writeSkewCheck="false"
concurrencyLevel="500"/>
<clustering mode="replication" clusterName="TestDigitalVault">
<stateRetrieval timeout="15000" fetchInMemoryState="false"/>
<sync replTimeout="15000"/>
<buddy enabled="true" communicationTimeout="3000">
<dataGravitation auto="true" removeOnFind="true" searchBackupTrees="true"/>
<locator class="org.jboss.cache.buddyreplication.NextMemberBuddyLocator">
<properties>
numBuddies = 1
ignoreColocatedBuddies = false
</properties>
</locator>
</buddy>
<jgroupsConfig>
<TCP bind_port="2000"
port_range="5"
enable_bundling="false"/>
<TCPPING initial_hosts="localhost[2000]"
port_range="5"
timeout="3000"
num_initial_members="1"
/>
<FD_SOCK/>
<FD timeout="10000"
max_tries="5"
shun="true"/>
<VERIFY_SUSPECT timeout="15000"/>
<pbcast.NAKACK max_xmit_size="60000"
use_mcast_xmit="false"
gc_lag="0"
retransmit_timeout="300,600,1200,2400,4800"
discard_delivered_msgs="true"/>
<UNICAST timeout="300,600,1200,2400,3600"/>
<pbcast.STABLE stability_delay="1000"
desired_avg_gossip="50000"
max_bytes="400000"/>
<pbcast.GMS print_local_addr="true"
join_timeout="5000"
join_retry_timeout="2000"
shun="false"
view_bundling="true"
view_ack_collection_timeout="5000"/>
<pbcast.STREAMING_STATE_TRANSFER/>
<pbcast.FLUSH timeout="0"/>
</jgroupsConfig>
</clustering>
</jbosscache>
{code}
Here are some logs:
{code}
2009-07-30 16:15:25,914 [main] TRACE cache.interceptors.InvocationContextInterceptor - Invoked with command RemoveNodeCommand{fqn=/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true}]
2009-07-30 16:15:25,916 [main] TRACE cache.interceptors.InvocationContextInterceptor - Setting up transactional context.
2009-07-30 16:15:25,916 [main] TRACE cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null
2009-07-30 16:15:25,916 [main] TRACE cache.lock.MVCCLockManager - Attempting to lock /test/blah
2009-07-30 16:15:25,917 [main] TRACE commands.write.RemoveNodeCommand - perform(null, /test/blah)
2009-07-30 16:15:25,917 [main] TRACE commands.write.RemoveNodeCommand - node /test/blah not found
2009-07-30 16:15:25,917 [main] TRACE cache.interceptors.MVCCLockingInterceptor - Releasing lock on [/test/blah] for owner Thread[main,5,main]
2009-07-30 16:15:25,918 [main] TRACE cache.lock.MVCCLockManager - Attempting to unlock /test/blah
2009-07-30 16:15:25,918 [main] TRACE cache.interceptors.ReplicationInterceptor - invoking method RemoveNodeCommand, members=[127.0.0.1:2000, 127.0.0.1:2001], mode=REPL_SYNC, exclude_self=true, timeout=15000
2009-07-30 16:15:25,918 [main] TRACE cache.interceptors.ReplicationInterceptor - Broadcasting call RemoveNodeCommand{fqn=/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null} to recipient list null
2009-07-30 16:15:25,919 [main] TRACE cache.buddyreplication.BuddyManager - Transformed RemoveNodeCommand{fqn=/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null} to RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}
2009-07-30 16:15:25,920 [main] TRACE cache.interceptors.ReplicationInterceptor - Setting call recipients to [127.0.0.1:2000] since the original list of recipients passed in is null.
2009-07-30 16:15:25,921 [main] TRACE jboss.cache.RPCManagerImpl - callRemoteMethods(): valid members are [127.0.0.1:2000] methods: ReplicateCommand{cmds=RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}} Using OOB? false
2009-07-30 16:15:25,921 [main] TRACE cache.marshall.CommandAwareRpcDispatcher - dests=[127.0.0.1:2000], command=ReplicateCommand{cmds=RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}}, mode=2, timeout=15000
2009-07-30 16:15:25,922 [main] TRACE cache.marshall.CacheMarshaller300 - Marshalling object ReplicateCommand{cmds=RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}}
2009-07-30 16:15:25,923 [main] TRACE cache.marshall.CommandAwareRpcDispatcher - real_dests=[127.0.0.1:2000]
2009-07-30 16:15:25,924 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.marshall.CacheMarshaller300 - Unmarshalled object ReplicateCommand{cmds=RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}}
2009-07-30 16:15:25,925 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.marshall.CommandAwareRpcDispatcher - Executing command: ReplicateCommand{cmds=RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}} [sender=127.0.0.1:2001]
2009-07-30 16:15:25,926 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.marshall.CommandAwareRpcDispatcher - This is a non-visitable command - so performing directly and not via the invoker.
2009-07-30 16:15:25,926 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.factories.ComponentRegistry - Testing if invocations are allowed.
2009-07-30 16:15:25,927 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE commands.remote.ReplicateCommand - Invoking command RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null}, with originLocal flag set to false.
2009-07-30 16:15:25,927 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.interceptors.InvocationContextInterceptor - Invoked with command RemoveNodeCommand{fqn=/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah, dataVersion=null, globalTransaction=null, skipSendingNodeEvents=false, parentFqn=null, targetNode=null} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=false}]
2009-07-30 16:15:25,929 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.interceptors.InvocationContextInterceptor - Setting up transactional context.
2009-07-30 16:15:25,929 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null
2009-07-30 16:15:25,929 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.lock.MVCCLockManager - Attempting to lock /_BUDDY_BACKUP_/127.0.0.1_2001/test/blah
2009-07-30 16:15:25,930 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE commands.write.RemoveNodeCommand - perform(null, /_BUDDY_BACKUP_/127.0.0.1_2001/test/blah)
2009-07-30 16:15:25,930 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE commands.write.RemoveNodeCommand - node /_BUDDY_BACKUP_/127.0.0.1_2001/test/blah not found
2009-07-30 16:15:25,930 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.interceptors.MVCCLockingInterceptor - Releasing lock on [/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah] for owner Thread[Incoming-1,TestDigitalVault,127.0.0.1:2000,5,Thread Pools]
2009-07-30 16:15:25,931 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.lock.MVCCLockManager - Attempting to unlock /_BUDDY_BACKUP_/127.0.0.1_2001/test/blah
2009-07-30 16:15:25,931 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options
2009-07-30 16:15:25,931 [Incoming-1,TestDigitalVault,127.0.0.1:2000] TRACE cache.marshall.CacheMarshaller300 - Marshalling object null
2009-07-30 16:15:25,932 [OOB-2,TestDigitalVault,127.0.0.1:2001] TRACE cache.marshall.CacheMarshaller300 - Unmarshalled object null
2009-07-30 16:15:25,933 [main] TRACE cache.marshall.CommandAwareRpcDispatcher - responses: [sender=127.0.0.1:2000, retval=null, received=true, suspected=false]
2009-07-30 16:15:25,933 [main] TRACE jboss.cache.RPCManagerImpl - (127.0.0.1:2001): responses for method ReplicateCommand:
null
2009-07-30 16:15:25,934 [main] TRACE cache.interceptors.ReplicationInterceptor - responses=[]
2009-07-30 16:15:25,934 [main] TRACE cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options
2009-07-30 16:15:25,934 [main] TRACE cache.interceptors.InvocationContextInterceptor - Invoked with command GetNodeCommand{fqn=/test/blah} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=false, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=false, forceSynchronous=false}, originLocal=true}]
2009-07-30 16:15:25,935 [main] TRACE cache.interceptors.InvocationContextInterceptor - Setting up transactional context.
2009-07-30 16:15:25,936 [main] TRACE cache.interceptors.InvocationContextInterceptor - Setting tx as null and gtx as null
2009-07-30 16:15:25,937 [main] TRACE cache.mvcc.MVCCNodeHelper - Node /test/blah is not in context, fetching from container.
2009-07-30 16:15:25,937 [main] TRACE cache.interceptors.DataGravitatorInterceptor - Checking local existence of requested fqn /test/blah
2009-07-30 16:15:25,937 [main] TRACE cache.interceptors.DataGravitatorInterceptor - No need to gravitate; have this already.
2009-07-30 16:15:25,937 [main] TRACE cache.interceptors.CallInterceptor - Executing command: GetNodeCommand{fqn=/test/blah}.
2009-07-30 16:15:25,939 [main] TRACE commands.read.GetNodeCommand - Found node, returning UnversionedNode[ /test/blah data=[key]]
2009-07-30 16:15:25,939 [main] TRACE cache.interceptors.MVCCLockingInterceptor - Nothing to do since there are no modifications in scope.
2009-07-30 16:15:25,940 [main] TRACE cache.interceptors.InvocationContextInterceptor - Resetting invocation-scope options
{code}
As you can see first it's tried to delete "/test/blah" in the current instance and then "/_BUDDY_BACKUP_/127.0.0.1_2001/test/blah" in the other intsance .. both operations fail.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the jbosscache-issues
mailing list