6 Replies Latest reply on Oct 24, 2006 5:37 AM by Stephane Stephane

    Migrating from JBCache 1.2.3 to 1.4.0 SP1

    Stephane Stephane Newbie

      Hi all,

      I'm migrating an application. The old one uses :
      - JBossCache 1.2.3
      - JGroups 2.2.8
      The new one uses :
      - JBossCache 1.4.0 SP1
      - JGroups 2.2.9.2

      I've not modified any configuration files.
      The problem is that the caches in the cluster don't communicate with each others now.
      I encounter no Exceptions.

      I've first think it was a JGroups problem, so i've tested those configurations :
      - JBossCache 1.4.0 SP1 + JGroups 2.2.8 : doesn't work
      - JbossCache 1.2.3 + + JGroups 2.2.9.2 : works
      - The new versions together doesn't work
      - The old versions together works

      Now, is this a JBossCache problem or a JGroups problem ?

      Do you need somes files to help me ?

      Thanks,

      Stéphane

        • 1. Re: Migrating from JBCache 1.2.3 to 1.4.0 SP1
          Manik Surtani Master

          You will need to switch JBoss Cache to DEBUG level and JGroups to INFO level logging and look at the startup log to ascertain why the nodes don't discover each other.

          Which OS is this on?

          • 2. Re: Migrating from JBCache 1.2.3 to 1.4.0 SP1
            Stephane Stephane Newbie

             

            "manik.surtani@jboss.com" wrote:
            You will need to switch JBoss Cache to DEBUG level and JGroups to INFO level logging and look at the startup log to ascertain why the nodes don't discover each other.

            Which OS is this on?


            The OS is Windows XP (development platform).

            Here is the log when it doesn't work :
            2006-10-23 18:32:05,937 [main] INFO org.jboss.cache.PropertyConfigurator - Found existing property editor for org.w3c.dom.Element: org.jboss.util.propertyeditor.ElementEditor@c6e1ec
            2006-10-23 18:32:06,515 [main] INFO org.jboss.cache.PropertyConfigurator - attribute size: 11
            2006-10-23 18:32:06,562 [main] DEBUG org.jboss.cache.PropertyConfigurator - setting attribute IsolationLevel to NONE
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - setting attribute CacheMode to REPL_ASYNC
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setUseReplQueue(boolean) with parameter "false" of type class java.lang.Boolean
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setReplQueueInterval(long) with parameter "0" of type class java.lang.Long
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setReplQueueMaxElements(int) with parameter "0" of type class java.lang.Integer
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - setting attribute ClusterName to lbsCache
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setClusterConfig(org.w3c.dom.Element) with parameter "[config: null]" of type class org.apache.xerces.dom.DeferredElementImpl
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.TreeCache - setting cluster properties from xml to: TCP(bind_addr=cerise;loopback=true;start_port=7800):TCPPING(down_thread=true;initial_hosts=cerise[7800],poire[7800];num_initial_members=3;port_range=1;timeout=3500;up_thread=true):MERGE2(max_interval=10000;min_interval=5000):FD(down_thread=true;max_tries=5;shun=true;timeout=2500;up_thread=true):VERIFY_SUSPECT(down_thread=false;timeout=1500;up_thread=false):pbcast.NAKACK(down_thread=true;gc_lag=100;retransmit_timeout=3000;up_thread=true):pbcast.STABLE(desired_avg_gossip=20000;down_thread=false;up_thread=false):pbcast.GMS(down_thread=true;join_retry_timeout=2000;join_timeout=5000;print_local_addr=true;shun=false;up_thread=true):pbcast.STATE_TRANSFER(down_thread=true;up_thread=true)
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setFetchInMemoryState(boolean) with parameter "true" of type class java.lang.Boolean
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setInitialStateRetrievalTimeout(long) with parameter "5000" of type class java.lang.Long
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setSyncReplTimeout(long) with parameter "10000" of type class java.lang.Long
            2006-10-23 18:32:06,578 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setLockAcquisitionTimeout(long) with parameter "15000" of type class java.lang.Long
            2006-10-23 18:32:06,578 [main] WARN org.jboss.cache.TreeCache - No transaction manager lookup class has been defined. Transactions cannot be used
            2006-10-23 18:32:06,593 [main] DEBUG org.jboss.cache.TreeCache - Not using an EvictionPolicy
            2006-10-23 18:32:06,671 [main] INFO org.jboss.cache.factories.InterceptorChainFactory - interceptor chain is:
            class org.jboss.cache.interceptors.CallInterceptor
            class org.jboss.cache.interceptors.PessimisticLockInterceptor
            class org.jboss.cache.interceptors.UnlockInterceptor
            class org.jboss.cache.interceptors.ReplicationInterceptor
            class org.jboss.cache.interceptors.TxInterceptor
            class org.jboss.cache.interceptors.CacheMgmtInterceptor
            2006-10-23 18:32:06,703 [main] DEBUG org.jboss.cache.TreeCache - cache mode is REPL_ASYNC

            Here is the log when it works :
            2006-10-23 18:34:21,234 [main] INFO org.jboss.cache.PropertyConfigurator - Found existing property editor for org.w3c.dom.Element: org.jboss.util.propertyeditor.ElementEditor@158f1fa
            2006-10-23 18:34:21,812 [main] INFO org.jboss.cache.PropertyConfigurator - configure(): attribute size: 11
            2006-10-23 18:34:21,812 [main] DEBUG org.jboss.cache.PropertyConfigurator - setting attribute IsolationLevel to NONE
            2006-10-23 18:34:21,812 [main] DEBUG org.jboss.cache.PropertyConfigurator - setting attribute CacheMode to REPL_ASYNC
            2006-10-23 18:34:21,812 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setUseReplQueue(boolean) with parameter "false" of type class java.lang.Boolean
            2006-10-23 18:34:21,812 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setReplQueueInterval(long) with parameter "0" of type class java.lang.Long
            2006-10-23 18:34:21,812 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setReplQueueMaxElements(int) with parameter "0" of type class java.lang.Integer
            2006-10-23 18:34:21,812 [main] DEBUG org.jboss.cache.PropertyConfigurator - setting attribute ClusterName to lbsCache
            2006-10-23 18:34:21,828 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setClusterConfig(org.w3c.dom.Element) with parameter "[config: null]" of type class org.apache.xerces.dom.DeferredElementImpl
            2006-10-23 18:34:21,828 [main] INFO org.jboss.cache.TreeCache - setting cluster properties from xml to: TCP(bind_addr=cerise;loopback=true;start_port=7800):TCPPING(down_thread=true;initial_hosts=cerise[7800],poire[7800];num_initial_members=3;port_range=1;timeout=3500;up_thread=true):MERGE2(max_interval=10000;min_interval=5000):FD(down_thread=true;max_tries=5;shun=true;timeout=2500;up_thread=true):VERIFY_SUSPECT(down_thread=false;timeout=1500;up_thread=false):pbcast.NAKACK(down_thread=true;gc_lag=100;retransmit_timeout=3000;up_thread=true):pbcast.STABLE(desired_avg_gossip=20000;down_thread=false;up_thread=false):pbcast.GMS(down_thread=true;join_retry_timeout=2000;join_timeout=5000;print_local_addr=true;shun=false;up_thread=true):pbcast.STATE_TRANSFER(down_thread=true;up_thread=true)
            2006-10-23 18:34:21,828 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setInitialStateRetrievalTimeout(long) with parameter "5000" of type class java.lang.Long
            2006-10-23 18:34:21,828 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setSyncReplTimeout(long) with parameter "10000" of type class java.lang.Long
            2006-10-23 18:34:21,828 [main] DEBUG org.jboss.cache.PropertyConfigurator - Invoking setter method: public void org.jboss.cache.TreeCache.setLockAcquisitionTimeout(long) with parameter "15000" of type class java.lang.Long
            2006-10-23 18:34:21,828 [main] WARN org.jboss.cache.TreeCache - No transaction manager lookup class has been defined. Transactions cannot be used
            2006-10-23 18:34:21,843 [main] INFO org.jboss.cache.TreeCache - interceptor chain is:
            class org.jboss.cache.interceptors.CallInterceptor
            class org.jboss.cache.interceptors.LockInterceptor
            class org.jboss.cache.interceptors.UnlockInterceptor
            class org.jboss.cache.interceptors.ReplicationInterceptor
            2006-10-23 18:34:21,843 [main] INFO org.jboss.cache.TreeCache - cache mode is REPL_ASYNC
            2006-10-23 18:34:22,281 [main] DEBUG org.jboss.cache.TreeCache - cache properties: TCP(bind_addr=cerise;loopback=true;start_port=7800):TCPPING(down_thread=true;initial_hosts=cerise[7800],poire[7800];num_initial_members=3;port_range=1;timeout=3500;up_thread=true):MERGE2(max_interval=10000;min_interval=5000):FD(down_thread=true;max_tries=5;shun=true;timeout=2500;up_thread=true):VERIFY_SUSPECT(down_thread=false;timeout=1500;up_thread=false):pbcast.NAKACK(down_thread=true;gc_lag=100;retransmit_timeout=3000;up_thread=true):pbcast.STABLE(desired_avg_gossip=20000;down_thread=false;up_thread=false):pbcast.GMS(down_thread=true;join_retry_timeout=2000;join_timeout=5000;print_local_addr=true;shun=false;up_thread=true):pbcast.STATE_TRANSFER(down_thread=true;up_thread=true)
            2006-10-23 18:34:22,375 [DownHandler (TCP)] INFO org.jgroups.blocks.ConnectionTable - server socket created on 192.168.1.61:7800
            2006-10-23 18:34:25,937 [DownHandler (STATE_TRANSFER)] INFO org.jboss.cache.TreeCache - new cache is null (maybe first member in cluster)
            2006-10-23 18:34:25,937 [main] INFO org.jboss.cache.TreeCache - state could not be retrieved (must be first member in group)
            2006-10-23 18:34:25,953 [UpHandler (STATE_TRANSFER)] INFO org.jboss.cache.TreeCache - viewAccepted(): new members: [192.168.1.61:7800]

            It seems that the difference is in the interceptor chain.


            • 3. Re: Migrating from JBCache 1.2.3 to 1.4.0 SP1
              Manik Surtani Master

              The new version has some newer interceptors, yes. The relevant ReplicationInterceptor is still there though, so it should be fine.

              Do you see any exceptions when you try and replicate something? Are you using this within JBoss AS? Did you make sure the new jboss-serialization.jar which ships with JBoss Cache 1.4.0.SP1 is in your classpath?

              • 4. Re: Migrating from JBCache 1.2.3 to 1.4.0 SP1
                Stephane Stephane Newbie

                There are no exceptions when I put objects to the cache.
                I'm using Tomcat 5.5.x. There were not the jboss-serialization.jar in the classpath, I added it but I got the same result.

                Here is a copy of the log file when I put something in the cache :
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.TxInterceptor - (null) call on method [_put(null, /FR, -1969335051, com.test.cache.User@fc301b6f, true)]
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - PessimisticLockInterceptor invoked for method _put(null, /FR, -1969335051, com.test.cache.User@fc301b6f, true)
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.PessimisticLockInterceptor - Attempting to lock node /FR for owner Thread[http-8080-Processor25,5,main]
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.CallInterceptor - Invoking method _put(null, /FR, -1969335051, com.test.cache.User@fc301b6f, true) on cache.
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.TreeCache - _put(null, "/FR", -1969335051, com.test.cache.User@fc301b6f)
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.UnlockInterceptor - Attempting to release locks on current thread. Lock table is {}
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Non-tx crud meth
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put(null, /FR, -1969335051, com.test.cache.User@fc301b6f, true), members=[], mode=REPL_ASYNC, exclude_self=true, timeout=10000
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - Broadcasting call _put(null, /FR, -1969335051, com.test.cache.User@fc301b6f, true) to recipient list null
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.TreeCache - destination list is empty, discarding call
                2006-10-24 09:13:34,984 [http-8080-Processor25] DEBUG org.jboss.cache.interceptors.ReplicationInterceptor - responses=null

                The object User is a simple object containing strings and getters / setters. It is serializable.

                The ReplicationInterceptor write that the recipient list is null. Do you have an idea ?

                • 5. Re: Migrating from JBCache 1.2.3 to 1.4.0 SP1
                  Manik Surtani Master

                  Set your JGroups logging to DEBUG and try again. When you start up the 2 servers, you should see some clues.

                  • 6. Re: Migrating from JBCache 1.2.3 to 1.4.0 SP1
                    Stephane Stephane Newbie

                    JGroups add those lines to the log :
                    2006-10-24 11:31:02,312 [main] DEBUG org.jgroups.conf.ClassConfigurator - mapping is:
                    1: class org.jgroups.stack.IpAddress
                    2: class org.jgroups.protocols.CAUSAL$CausalHeader
                    3: class org.jgroups.protocols.FD$FdHeader
                    4: class org.jgroups.protocols.FD_PID$FdHeader
                    5: class org.jgroups.protocols.FD_PROB$FdHeader
                    6: class org.jgroups.protocols.FD_SOCK$FdHeader
                    7: class org.jgroups.protocols.FragHeader
                    8: class org.jgroups.protocols.MERGE$MergeHeader
                    9: class org.jgroups.protocols.NakAckHeader
                    10: class org.jgroups.protocols.PARTITIONER$PartitionerHeader
                    11: class org.jgroups.protocols.PerfHeader
                    12: class org.jgroups.protocols.PIGGYBACK$PiggybackHeader
                    13: class org.jgroups.protocols.PingHeader
                    14: class org.jgroups.protocols.TcpHeader
                    15: class org.jgroups.protocols.TOTAL$Header
                    16: class org.jgroups.protocols.TOTAL_OLD$TotalHeader
                    17: class org.jgroups.protocols.TOTAL_TOKEN$TotalTokenHeader
                    18: class org.jgroups.protocols.TOTAL_TOKEN$RingTokenHeader
                    19: class org.jgroups.protocols.TunnelHeader
                    20: class org.jgroups.protocols.UdpHeader
                    21: class org.jgroups.protocols.UNICAST$UnicastHeader
                    22: class org.jgroups.protocols.VERIFY_SUSPECT$VerifyHeader
                    23: class org.jgroups.protocols.WANPIPE$WanPipeHeader
                    24: class org.jgroups.protocols.pbcast.GMS$GmsHeader
                    25: class org.jgroups.protocols.pbcast.NakAckHeader
                    26: class org.jgroups.protocols.pbcast.PbcastHeader
                    27: class org.jgroups.protocols.pbcast.STABLE$StableHeader
                    28: class org.jgroups.protocols.pbcast.STATE_TRANSFER$StateHeader
                    29: class org.jgroups.protocols.SMACK$SmackHeader
                    30: class org.jgroups.Message
                    31: class org.jgroups.View
                    32: class org.jgroups.ViewId
                    33: class org.jgroups.util.List
                    34: interface org.jgroups.Address
                    35: class org.jgroups.blocks.RequestCorrelator$Header
                    36: class org.jgroups.protocols.PingRsp
                    37: class [Ljava.lang.Object;
                    38: class java.util.Vector
                    39: class org.jgroups.protocols.pbcast.JoinRsp
                    40: class org.jgroups.protocols.pbcast.Digest
                    41: class java.util.Hashtable
                    53: class org.jgroups.protocols.COMPRESS$CompressHeader
                    54: class org.jgroups.protocols.FC$FcHeader
                    55: class org.jgroups.protocols.WanPipeAddress
                    56: class org.jgroups.protocols.TpHeader
                    57: class org.jgroups.protocols.ENCRYPT$EncryptHeader

                    2006-10-24 11:31:02,359 [main] DEBUG org.jgroups.protocols.AUTOCONF - frag_size=64000
                    2006-10-24 11:31:02,437 [main] DEBUG org.jgroups.protocols.pbcast.GMS - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl

                    When it work, there are periodically many new lines indicating JGroups is searching (testing) the other IPs in the cluster.
                    I'm not seing those lines.