0 Replies Latest reply on Oct 12, 2005 12:25 PM by Jed Lloyd

    TreeCache Replication On Server Startup

    Jed Lloyd Newbie

      Hello,

      I'm having a problem with replication on server startup. I have written a wrapper class, using JBoss TreeCacheAOP, for a CacheManager class which is loaded via the struts DispatcherServlet on application startup. I now have the application deployed in a clustered Weblogic environment with two nodes running on the same box. The TreeCache is configured to run in REPL_ASYNC mode, with FetchStateOnStartup set to false and the InitialStateRetrievalTimeout set to 1 hour.

      What I have noticed is that after the CacheManager loads all the cache data to in memory Hashmaps and then begins adding these maps to the TreeCacheAOP through the wrapper class, it looks like the TreeCache begins making attempts to replicate the changes to each nodes cache. I have looked into the JGroups configuration specs and am not sure if I have missed something, however cannot seem to figure out why the replication attempts are started so soon after application startup.

      Here is a copy of the JBossCacheConfig.xml file followed by the application server startup logs:

      <?xml version="1.0" encoding="UTF-8"?>
      
      <!-- ===================================================================== -->
      <!-- -->
      <!-- TreeCacheAop Service Configuration -->
      <!-- -->
      <!-- ===================================================================== -->
      
      <server>
      
       <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/>
      
      
       <!-- ==================================================================== -->
       <!-- Defines TreeCache configuration -->
       <!-- ==================================================================== -->
      
       <mbean code="org.jboss.cache.aop.TreeCacheAop" name="jboss.cache:service=TreeCacheAop">
      
       <depends>jboss:service=Naming</depends>
       <depends>jboss:service=TransactionManager</depends>
      
       <!--
       Configure the TransactionManager
       -->
       <!-- <attribute name="TransactionManagerLookupClass">org.jboss.cache.JBossTransactionManagerLookup</attribute> -->
      
      
       <!--
       Node locking level : SERIALIZABLE
       REPEATABLE_READ (default)
       READ_COMMITTED
       READ_UNCOMMITTED
       NONE
       -->
       <attribute name="IsolationLevel">REPEATABLE_READ</attribute>
      
       <!--
       Valid modes are LOCAL
       REPL_ASYNC
       REPL_SYNC
       -->
       <attribute name="CacheMode">REPL_ASYNC</attribute>
      
      
       <!-- Just used for async repl: use a repliation queue -->
       <attribute name="UseReplQueue">false</attribute>
      
       <!-- Replication interval for replication queue (in ms) -->
       <attribute name="ReplQueueInterval">0</attribute>
      
       <!-- Max number of elements which trigger replication -->
       <attribute name="ReplQueueMaxElements">0</attribute>
      
       <!-- Name of cluster. Needs to be the same for all clusters, in order
       to find each other
       -->
       <attribute name="ClusterName">Remedy-TreeCache-Cluster</attribute>
      
       <!-- JGroups protocol stack properties. Can also be a URL,
       e.g. file:/home/bela/default.xml
       <attribute name="ClusterProperties"></attribute>
       -->
      
       <attribute name="ClusterConfig">
       <config>
       <!-- UDP: if you have a multihomed machine,
       set the bind_addr attribute to the appropriate NIC IP address, e.g bind_addr="192.168.0.2"
       -->
       <!-- UDP: On Windows machines, because of the media sense feature
       being broken with multicast (even after disabling media sense)
       set the loopback attribute to true -->
       <UDP mcast_addr="228.1.2.3" mcast_port="48866" ip_ttl="32" ip_mcast="true" loopback="false"
       mcast_send_buf_size="200000" mcast_recv_buf_size="1000000"
       ucast_send_buf_size="200000" ucast_recv_buf_size="1000000"/>
       <PING timeout="2000" num_initial_members="2"/>
       <FD_SOCK/>
       <VERIFY_SUSPECT timeout="1500"/>
       <pbcast.NAKACK gc_lag="50" retransmit_timeout="600,1200,2400,4800" max_xmit_size="8192"/>
       <UNICAST timeout="600,1200,2400" window_size="100" min_threshold="10"/>
       <pbcast.STABLE desired_avg_gossip="20000" max_bytes="500000"/>
       <FRAG frag_size="8192"/>
       <pbcast.GMS join_timeout="5000" join_retry_timeout="2000" shun="false" print_local_addr="true"/>
       </config>
       </attribute>
      
      
       <!--
       Whether or not to fetch state on joining a cluster
       -->
       <attribute name="FetchStateOnStartup">false</attribute>
      
       <!--
       The max amount of time (in milliseconds) we wait until the
       initial state (ie. the contents of the cache) are retrieved from
       existing members in a clustered environment
       -->
       <attribute name="InitialStateRetrievalTimeout">3600000</attribute>
      
       <!--
       Number of milliseconds to wait until all responses for a
       synchronous call have been received.
       -->
       <attribute name="SyncReplTimeout">10000</attribute>
      
       <!-- Max number of milliseconds to wait for a lock acquisition -->
       <attribute name="LockAcquisitionTimeout">15000</attribute>
      
      
       <!-- Name of the eviction policy class. Not supported now. -->
       <attribute name="EvictionPolicyClass"></attribute>
       </mbean>
      
       </server>



      Application Node 1:

      INFO [2005-10-11 15:31:11,981] [main] remedy - Loading RefLocation to cache data...
      INFO [2005-10-11 15:31:11,984] [main] remedy - 4 total Location entries loaded from database.
      INFO [2005-10-11 15:31:11,985] [main] remedy - Loading Alerts cache data...
      INFO [2005-10-11 15:31:12,009] [main] remedy - 8 total Alert entries have been loaded from database.
      INFO [2005-10-11 15:31:12,010] [main] remedy - Loading ActionItem cache data...
      INFO [2005-10-11 15:31:12,065] [main] remedy - 21 total ActionItem entries have been loaded from database.
      INFO [2005-10-11 15:31:12,066] [main] remedy - Loading Action Logs cache data...
      INFO [2005-10-11 15:31:12,073] [main] remedy - 0 total ActionLog entries have been loaded from database.
      INFO [2005-10-11 15:31:12,074] [main] remedy - Loading SecPrincial data into cache...
      INFO [2005-10-11 15:31:12,231] [main] remedy - 2142 total SecPrincipal entries have been loaded from database.
      DEBUG [2005-10-11 15:31:12,256] [main] org.jboss.cache.Node - createChild: fqn=/Client, child_name=Client
      DEBUG [2005-10-11 15:31:12,257] [main] org.jboss.cache.interceptors.LockInterceptor - created child Client
      DEBUG [2005-10-11 15:31:12,257] [main] org.jboss.cache.Node - acquiring WL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,258] [main] org.jboss.cache.Node - acquired WL: fqn=/Client, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,258] [main] org.jboss.cache.TreeCache - _put(null, "/Client", dummy, dummy)
      DEBUG [2005-10-11 15:31:12,259] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,260] [main] org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put([Ljava.lang.Object;@3e25d3), members=[10.3.75.38:34728, 10.3.75.38:34731], mode=REPL_ASYNC, exclude_self=true, timeout=10000
      DEBUG [2005-10-11 15:31:12,260] [main] org.jboss.cache.TreeCache - callRemoteMethods(): valid members are [10.3.75.38:34728]
      DEBUG [2005-10-11 15:31:12,261] [main] org.jgroups.blocks.RpcDispatcher - dests=[10.3.75.38:34728], method_call=_replicate(_put(null, /Client, dummy, dummy, true)), mode=6, timeout=10000
      DEBUG [2005-10-11 15:31:12,269] [main] org.jgroups.blocks.RpcDispatcher - real_dests=[10.3.75.38:34728]
      DEBUG [2005-10-11 15:31:12,310] [main] org.jgroups.blocks.GroupRequest - sending request (id=1129059072309)
      DEBUG [2005-10-11 15:31:12,311] [DownHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - sending msg #23
      DEBUG [2005-10-11 15:31:12,312] [main] org.jgroups.blocks.GroupRequest - received all responses: [GroupRequest:
      req_id=1129059072309
      caller=10.3.75.38:34731
      10.3.75.38:34728: sender=10.3.75.38:34728, retval=null, received=false, suspected=false

      request_msg: [dst: , src: 10.3.75.38:34731 (3 headers), size = 523 bytes]
      rsp_mode: GET_NONE
      done: false
      timeout: 10000
      expected_mbrs: 0
      ]

      DEBUG [2005-10-11 15:31:12,312] [DownHandler (UDP)] org.jgroups.protocols.UDP - sending msg to null (src=10.3.75.38:34731), headers are {NAKACK=[MSG, seqno=23], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072309, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,313] [UDP mcast receiver] org.jgroups.protocols.UDP - received (mcast)674 bytes from 10.3.75.38:34732
      DEBUG [2005-10-11 15:31:12,314] [UDP mcast receiver] org.jgroups.protocols.UDP - message is [dst: 228.1.2.3:48866, src: 10.3.75.38:34731 (3 headers), size = 523 bytes], headers are {NAKACK=[MSG, seqno=23], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072309, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,314] [UpHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - 10.3.75.38:34731] received 10.3.75.38:34731#23
      DEBUG [2005-10-11 15:31:12,316] [UpHandler (GMS)] org.jgroups.blocks.RequestCorrelator - discarded request from 10.3.75.38:34731 as we are not part of destination list (local_addr=10.3.75.38:34731, hdr=[Header: name=MessageDispatcher, type=REQ, id=1129059072309, rsp_expected=false], dest_mbrs=[10.3.75.38:34728])
      DEBUG [2005-10-11 15:31:12,318] [main] org.jgroups.blocks.RpcDispatcher - responses: [sender=10.3.75.38:34728, retval=null, received=false, suspected=false]

      DEBUG [2005-10-11 15:31:12,318] [main] org.jboss.cache.TreeCache - (10.3.75.38:34731): responses for method _replicate:
      [sender=10.3.75.38:34728, retval=null, received=false, suspected=false]

      DEBUG [2005-10-11 15:31:12,321] [main] org.jboss.cache.Node - acquiring RL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,321] [main] org.jboss.cache.Node - acquired RL: fqn=/Client, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,322] [main] org.jboss.cache.TreeCache - _get("/Client", __AOPINSTANCE_POJO__, "false")
      DEBUG [2005-10-11 15:31:12,322] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,322] [main] org.jboss.cache.Node - acquiring RL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,322] [main] org.jboss.cache.Node - acquired RL: fqn=/Client, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,323] [main] org.jboss.cache.TreeCache - _get("/Client", __jboss:internal:class__, "true")
      DEBUG [2005-10-11 15:31:12,323] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,323] [main] org.jboss.cache.aop.TreeCacheAopDelegate - putObject(): fqn: /Client
      DEBUG [2005-10-11 15:31:12,323] [main] org.jboss.cache.aop.TreeCacheAopDelegate - putObject(): aspectized obj is a Map type of size: 94
      DEBUG [2005-10-11 15:31:12,323] [main] org.jboss.cache.Node - acquiring RL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,323] [main] org.jboss.cache.Node - acquired RL: fqn=/Client, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,324] [main] org.jboss.cache.TreeCache - _get("/Client", __jboss:internal:class__, "true")
      DEBUG [2005-10-11 15:31:12,324] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,324] [main] org.jboss.cache.aop.TreeCacheAopDelegate - removeObject(): clasz is null. fqn: /Client
      DEBUG [2005-10-11 15:31:12,324] [main] org.jboss.cache.Node - acquiring WL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,324] [main] org.jboss.cache.Node - acquired WL: fqn=/Client, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,324] [main] org.jboss.cache.TreeCache - _put(null, "/Client", __jboss:internal:class__, class java.util.HashMap)
      DEBUG [2005-10-11 15:31:12,325] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,325] [main] org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put([Ljava.lang.Object;@1e3f34c), members=[10.3.75.38:34728, 10.3.75.38:34731], mode=REPL_ASYNC, exclude_self=true, timeout=10000
      DEBUG [2005-10-11 15:31:12,325] [main] org.jboss.cache.TreeCache - callRemoteMethods(): valid members are [10.3.75.38:34728]
      DEBUG [2005-10-11 15:31:12,325] [main] org.jgroups.blocks.RpcDispatcher - dests=[10.3.75.38:34728], method_call=_replicate(_put(null, /Client, __jboss:internal:class__, class java.util.HashMap, true)), mode=6, timeout=10000
      DEBUG [2005-10-11 15:31:12,326] [main] org.jgroups.blocks.RpcDispatcher - real_dests=[10.3.75.38:34728]
      DEBUG [2005-10-11 15:31:12,326] [main] org.jgroups.blocks.GroupRequest - sending request (id=1129059072326)
      DEBUG [2005-10-11 15:31:12,326] [main] org.jgroups.blocks.GroupRequest - received all responses: [GroupRequest:
      req_id=1129059072326
      caller=10.3.75.38:34731
      10.3.75.38:34728: sender=10.3.75.38:34728, retval=null, received=false, suspected=false

      request_msg: [dst: , src: (1 headers), size = 596 bytes]
      rsp_mode: GET_NONE
      done: false
      timeout: 10000
      expected_mbrs: 0
      ]
      DEBUG [2005-10-11 15:31:12,326] [main] org.jgroups.blocks.RpcDispatcher - responses: [sender=10.3.75.38:34728, retval=null, received=false, suspected=false]

      DEBUG [2005-10-11 15:31:12,327] [DownHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - sending msg #24
      DEBUG [2005-10-11 15:31:12,327] [main] org.jboss.cache.TreeCache - (10.3.75.38:34731): responses for method _replicate:
      [sender=10.3.75.38:34728, retval=null, received=false, suspected=false]

      DEBUG [2005-10-11 15:31:12,327] [DownHandler (UDP)] org.jgroups.protocols.UDP - sending msg to null (src=10.3.75.38:34731), headers are {NAKACK=[MSG, seqno=24], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072326, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,328] [UDP mcast receiver] org.jgroups.protocols.UDP - received (mcast)747 bytes from 10.3.75.38:34732
      DEBUG [2005-10-11 15:31:12,330] [UDP mcast receiver] org.jgroups.protocols.UDP - message is [dst: 228.1.2.3:48866, src: 10.3.75.38:34731 (3 headers), size = 596 bytes], headers are {NAKACK=[MSG, seqno=24], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072326, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,330] [UpHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - 10.3.75.38:34731] received 10.3.75.38:34731#24
      DEBUG [2005-10-11 15:31:12,331] [UpHandler (GMS)] org.jgroups.blocks.RequestCorrelator - discarded request from 10.3.75.38:34731 as we are not part of destination list (local_addr=10.3.75.38:34731, hdr=[Header: name=MessageDispatcher, type=REQ, id=1129059072326, rsp_expected=false], dest_mbrs=[10.3.75.38:34728])
      DEBUG [2005-10-11 15:31:12,651] [UDP mcast receiver] org.jgroups.protocols.UDP - received (mcast)674 bytes from 10.3.75.38:34729
      DEBUG [2005-10-11 15:31:12,651] [UDP mcast receiver] org.jgroups.protocols.UDP - message is [dst: 228.1.2.3:48866, src: 10.3.75.38:34728 (3 headers), size = 523 bytes], headers are {NAKACK=[MSG, seqno=24], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072648, rsp_expected=false], dest_mbrs=[10.3.75.38:34731], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,652] [UpHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - 10.3.75.38:34731] received 10.3.75.38:34728#24
      DEBUG [2005-10-11 15:31:12,653] [UpHandler (GMS)] org.jgroups.blocks.RequestCorrelator - calling (org.jgroups.blocks.RpcDispatcher) with request 1129059072648
      DEBUG [2005-10-11 15:31:12,672] [UpHandler (GMS)] org.jgroups.blocks.RpcDispatcher - [sender=10.3.75.38:34728], method_call: _replicate(_put(null, /Client, dummy, dummy, true))
      DEBUG [2005-10-11 15:31:12,672] [UpHandler (GMS)] org.jboss.cache.interceptors.ReplicationInterceptor - replicate(): received _put(null, /Client, dummy, dummy, true)
      DEBUG [2005-10-11 15:31:12,673] [UpHandler (GMS)] org.jboss.cache.Node - acquiring WL: fqn=/Client, caller=Thread[UpHandler (GMS),5,main], lock=
      DEBUG [2005-10-11 15:31:12,673] [UpHandler (GMS)] org.jboss.cache.Node - acquired WL: fqn=/Client, caller=Thread[UpHandler (GMS),5,main], lock=write owner=Thread[UpHandler (GMS),5,main]
      DEBUG [2005-10-11 15:31:12,673] [UpHandler (GMS)] org.jboss.cache.TreeCache - _put(null, "/Client", dummy, dummy)
      DEBUG [2005-10-11 15:31:12,673] [UpHandler (GMS)] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: write owner=Thread[UpHandler (GMS),5,main]
      DEBUG [2005-10-11 15:31:12,684] [main] org.jboss.cache.Node - acquiring RL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,685] [main] org.jboss.cache.Node - acquired RL: fqn=/Client, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,685] [main] org.jboss.cache.interceptors.LockInterceptor - failed finding child 1536 of node /Client
      DEBUG [2005-10-11 15:31:12,685] [main] org.jboss.cache.TreeCache - _get("/Client/1536", __AOPINSTANCE_POJO__, "false")
      DEBUG [2005-10-11 15:31:12,685] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,685] [main] org.jboss.cache.Node - acquiring RL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,685] [main] org.jboss.cache.Node - acquired RL: fqn=/Client, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,686] [main] org.jboss.cache.interceptors.LockInterceptor - failed finding child 1536 of node /Client
      DEBUG [2005-10-11 15:31:12,686] [main] org.jboss.cache.TreeCache - _get("/Client/1536", __jboss:internal:class__, "true")
      DEBUG [2005-10-11 15:31:12,686] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,686] [main] org.jboss.cache.aop.TreeCacheAopDelegate - putObject(): fqn: /Client/1536
      DEBUG [2005-10-11 15:31:12,688] [main] org.jboss.cache.aop.TreeCacheAopDelegate - handleMultipleReference(): No multiple refernce found for fqn: /Client/1536
      DEBUG [2005-10-11 15:31:12,692] [main] org.jboss.cache.Node - acquiring RL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.Node - acquired RL: fqn=/Client, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.Node - createChild: fqn=/Client/1536, child_name=1536
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.interceptors.LockInterceptor - created child 1536
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.Node - acquiring WL: fqn=/Client/1536, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.Node - acquired WL: fqn=/Client/1536, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.TreeCache - _put(null, "/Client/1536", __AOPINSTANCE_COUNT__, 1)
      DEBUG [2005-10-11 15:31:12,693] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client/1536: write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,694] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: read owners=[Thread[main,5,main]]
      DEBUG [2005-10-11 15:31:12,694] [main] org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put([Ljava.lang.Object;@12b1e53), members=[10.3.75.38:34728, 10.3.75.38:34731], mode=REPL_ASYNC, exclude_self=true, timeout=10000
      DEBUG [2005-10-11 15:31:12,694] [main] org.jboss.cache.TreeCache - callRemoteMethods(): valid members are [10.3.75.38:34728]
      DEBUG [2005-10-11 15:31:12,694] [main] org.jgroups.blocks.RpcDispatcher - dests=[10.3.75.38:34728], method_call=_replicate(_put(null, /Client/1536, __AOPINSTANCE_COUNT__, 1, true)), mode=6, timeout=10000
      DEBUG [2005-10-11 15:31:12,695] [main] org.jgroups.blocks.RpcDispatcher - real_dests=[10.3.75.38:34728]
      DEBUG [2005-10-11 15:31:12,695] [main] org.jgroups.blocks.GroupRequest - sending request (id=1129059072695)
      DEBUG [2005-10-11 15:31:12,696] [main] org.jgroups.blocks.GroupRequest - received all responses: [GroupRequest:
      req_id=1129059072695
      caller=10.3.75.38:34731
      10.3.75.38:34728: sender=10.3.75.38:34728, retval=null, received=false, suspected=false

      request_msg: [dst: , src: (1 headers), size = 618 bytes]
      rsp_mode: GET_NONE
      done: false
      timeout: 10000
      expected_mbrs: 0
      ]
      DEBUG [2005-10-11 15:31:12,696] [DownHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - sending msg #25
      DEBUG [2005-10-11 15:31:12,696] [main] org.jgroups.blocks.RpcDispatcher - responses: [sender=10.3.75.38:34728, retval=null, received=false, suspected=false]

      DEBUG [2005-10-11 15:31:12,696] [main] org.jboss.cache.TreeCache - (10.3.75.38:34731): responses for method _replicate:
      [sender=10.3.75.38:34728, retval=null, received=false, suspected=false]

      DEBUG [2005-10-11 15:31:12,696] [DownHandler (UDP)] org.jgroups.protocols.UDP - sending msg to null (src=10.3.75.38:34731), headers are {NAKACK=[MSG, seqno=25], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072695, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}

      Application Node 2:

      INFO [2005-10-11 15:31:12,284] [main] remedy - Loading CNM abbr data...
      INFO [2005-10-11 15:31:12,289] [main] remedy - 27 total CNM abbr entries loaded from database.
      INFO [2005-10-11 15:31:12,290] [main] remedy - Loading Remedy Entitlement Function cache data...
      INFO [2005-10-11 15:31:12,304] [main] remedy - 17 total Remedy Entitlement Function entries loaded from database.
      INFO [2005-10-11 15:31:12,305] [main] remedy - Loading Remedy Entitlement Group cache data...
      DEBUG [2005-10-11 15:31:12,313] [UDP mcast receiver] org.jgroups.protocols.UDP - received (mcast)674 bytes from 10.3.75.38:34732
      DEBUG [2005-10-11 15:31:12,314] [UDP mcast receiver] org.jgroups.protocols.UDP - message is [dst: 228.1.2.3:48866, src: 10.3.75.38:34731 (3 headers), size = 523 bytes], headers are {NAKACK=[MSG, seqno=23], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072309, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,315] [UpHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - 10.3.75.38:34728] received 10.3.75.38:34731#23
      DEBUG [2005-10-11 15:31:12,316] [UpHandler (GMS)] org.jgroups.blocks.RequestCorrelator - calling (org.jgroups.blocks.RpcDispatcher) with request 1129059072309
      DEBUG [2005-10-11 15:31:12,328] [UDP mcast receiver] org.jgroups.protocols.UDP - received (mcast)747 bytes from 10.3.75.38:34732
      DEBUG [2005-10-11 15:31:12,329] [UDP mcast receiver] org.jgroups.protocols.UDP - message is [dst: 228.1.2.3:48866, src: 10.3.75.38:34731 (3 headers), size = 596 bytes], headers are {NAKACK=[MSG, seqno=24], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072326, rsp_expected=false], dest_mbrs=[10.3.75.38:34728], UDP=[channel_name=Remedy-TreeCache-Cluster]}
      DEBUG [2005-10-11 15:31:12,330] [UpHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - 10.3.75.38:34728] received 10.3.75.38:34731#24
      DEBUG [2005-10-11 15:31:12,349] [UpHandler (GMS)] org.jgroups.blocks.RpcDispatcher - [sender=10.3.75.38:34731], method_call: _replicate(_put(null, /Client, dummy, dummy, true))
      DEBUG [2005-10-11 15:31:12,349] [UpHandler (GMS)] org.jboss.cache.interceptors.ReplicationInterceptor - replicate(): received _put(null, /Client, dummy, dummy, true)
      INFO [2005-10-11 15:31:12,349] [main] remedy - 1 total Remedy Entitlement Group entries loaded from database.
      INFO [2005-10-11 15:31:12,356] [main] remedy - Loading Remedy Entitlement GrpToFunct cache data...
      DEBUG [2005-10-11 15:31:12,359] [UpHandler (GMS)] org.jboss.cache.Node - createChild: fqn=/Client, child_name=Client
      DEBUG [2005-10-11 15:31:12,359] [UpHandler (GMS)] org.jboss.cache.interceptors.LockInterceptor - created child Client
      DEBUG [2005-10-11 15:31:12,360] [UpHandler (GMS)] org.jboss.cache.Node - acquiring WL: fqn=/Client, caller=Thread[UpHandler (GMS),5,main], lock=
      DEBUG [2005-10-11 15:31:12,360] [UpHandler (GMS)] org.jboss.cache.Node - acquired WL: fqn=/Client, caller=Thread[UpHandler (GMS),5,main], lock=write owner=Thread[UpHandler (GMS),5,main]
      DEBUG [2005-10-11 15:31:12,361] [UpHandler (GMS)] org.jboss.cache.TreeCache - _put(null, "/Client", dummy, dummy)
      DEBUG [2005-10-11 15:31:12,361] [UpHandler (GMS)] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: write owner=Thread[UpHandler (GMS),5,main]
      DEBUG [2005-10-11 15:31:12,361] [UpHandler (GMS)] org.jgroups.blocks.RequestCorrelator - calling (org.jgroups.blocks.RpcDispatcher) with request 1129059072326
      DEBUG [2005-10-11 15:31:12,363] [UpHandler (GMS)] org.jgroups.blocks.RpcDispatcher - [sender=10.3.75.38:34731], method_call: _replicate(_put(null, /Client, __jboss:internal:class__, class java.util.HashMap, true))
      DEBUG [2005-10-11 15:31:12,364] [UpHandler (GMS)] org.jboss.cache.interceptors.ReplicationInterceptor - replicate(): received _put(null, /Client, __jboss:internal:class__, class java.util.HashMap, true)
      DEBUG [2005-10-11 15:31:12,364] [UpHandler (GMS)] org.jboss.cache.Node - acquiring WL: fqn=/Client, caller=Thread[UpHandler (GMS),5,main], lock=
      DEBUG [2005-10-11 15:31:12,364] [UpHandler (GMS)] org.jboss.cache.Node - acquired WL: fqn=/Client, caller=Thread[UpHandler (GMS),5,main], lock=write owner=Thread[UpHandler (GMS),5,main]
      DEBUG [2005-10-11 15:31:12,364] [UpHandler (GMS)] org.jboss.cache.TreeCache - _put(null, "/Client", __jboss:internal:class__, class java.util.HashMap)
      DEBUG [2005-10-11 15:31:12,364] [UpHandler (GMS)] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: write owner=Thread[UpHandler (GMS),5,main]
      INFO [2005-10-11 15:31:12,384] [main] remedy - 17 total Remedy Entitlement GrpToFunct entries loaded from database.
      INFO [2005-10-11 15:31:12,384] [main] remedy - Loading RefLocation to cache data...
      INFO [2005-10-11 15:31:12,388] [main] remedy - 4 total Location entries loaded from database.
      INFO [2005-10-11 15:31:12,389] [main] remedy - Loading Alerts cache data...
      INFO [2005-10-11 15:31:12,424] [main] remedy - 8 total Alert entries have been loaded from database.
      INFO [2005-10-11 15:31:12,425] [main] remedy - Loading ActionItem cache data...
      INFO [2005-10-11 15:31:12,477] [main] remedy - 21 total ActionItem entries have been loaded from database.
      INFO [2005-10-11 15:31:12,478] [main] remedy - Loading Action Logs cache data...
      INFO [2005-10-11 15:31:12,483] [main] remedy - 0 total ActionLog entries have been loaded from database.
      INFO [2005-10-11 15:31:12,483] [main] remedy - Loading SecPrincial data into cache...
      INFO [2005-10-11 15:31:12,632] [main] remedy - 2142 total SecPrincipal entries have been loaded from database.
      DEBUG [2005-10-11 15:31:12,637] [main] org.jboss.cache.Node - acquiring WL: fqn=/Client, caller=Thread[main,5,main], lock=
      DEBUG [2005-10-11 15:31:12,637] [main] org.jboss.cache.Node - acquired WL: fqn=/Client, caller=Thread[main,5,main], lock=write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,637] [main] org.jboss.cache.TreeCache - _put(null, "/Client", dummy, dummy)
      DEBUG [2005-10-11 15:31:12,637] [main] org.jboss.cache.interceptors.UnlockInterceptor - releasing lock for /Client: write owner=Thread[main,5,main]
      DEBUG [2005-10-11 15:31:12,638] [main] org.jboss.cache.interceptors.ReplicationInterceptor - invoking method _put([Ljava.lang.Object;@1efe574), members=[10.3.75.38:34728, 10.3.75.38:34731], mode=REPL_ASYNC, exclude_self=true, timeout=10000
      DEBUG [2005-10-11 15:31:12,638] [main] org.jboss.cache.TreeCache - callRemoteMethods(): valid members are [10.3.75.38:34731]
      DEBUG [2005-10-11 15:31:12,639] [main] org.jgroups.blocks.RpcDispatcher - dests=[10.3.75.38:34731], method_call=_replicate(_put(null, /Client, dummy, dummy, true)), mode=6, timeout=10000
      DEBUG [2005-10-11 15:31:12,640] [main] org.jgroups.blocks.RpcDispatcher - real_dests=[10.3.75.38:34731]
      DEBUG [2005-10-11 15:31:12,648] [main] org.jgroups.blocks.GroupRequest - sending request (id=1129059072648)
      DEBUG [2005-10-11 15:31:12,649] [DownHandler (NAKACK)] org.jgroups.protocols.pbcast.NAKACK - sending msg #24
      DEBUG [2005-10-11 15:31:12,649] [main] org.jgroups.blocks.GroupRequest - received all responses: [GroupRequest:
      req_id=1129059072648
      caller=10.3.75.38:34728
      10.3.75.38:34731: sender=10.3.75.38:34731, retval=null, received=false, suspected=false

      request_msg: [dst: , src: (1 headers), size = 523 bytes]
      rsp_mode: GET_NONE
      done: false
      timeout: 10000
      expected_mbrs: 0
      ]
      DEBUG [2005-10-11 15:31:12,650] [DownHandler (UDP)] org.jgroups.protocols.UDP - sending msg to null (src=10.3.75.38:34728), headers are {NAKACK=[MSG, seqno=24], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1129059072648, rsp_expected=false], dest_mbrs=[10.3.75.38:34731], UDP=[channel_name=Remedy-TreeCache-Cluster]}