[jbosscache-issues] [JBoss JIRA] Updated: (JBCACHE-1525) Cache.removeNode does not remove node when buddies are configured and called on instance which does not contains the node.

Manik Surtani (JIRA) jira-events at lists.jboss.org
Thu Aug 6 07:38:30 EDT 2009


     [ https://jira.jboss.org/jira/browse/JBCACHE-1525?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Manik Surtani updated JBCACHE-1525:
-----------------------------------

    Fix Version/s: 3.3.0.GA


> 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
>             Fix For: 3.3.0.GA
>
>
> 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