3 Replies Latest reply on Mar 19, 2009 7:33 PM by nikita tovstoles

    JBC+JGroups: 2nd Tomcat hangs during startup

    nikita tovstoles Newbie

      I realize this is quite likely a JGroups config problem, but thought maybe someone can clue me in here. I have 2 tomcat nodes running JBC3 w/JGroups 2.7.0GA (in invalidation async mode) using identical config. Yet node started second never fully starts up but hangs somewhere during jbc/jgroups init time w/o any error messages. Looking at the logs below could someone please offer up a clue?

      multicast addr is 232.10.10.11. Both nodes are on the same host but correctly use different ports in local_addr.

      Note that the 1st node seems to receive a message from the 2nd node at 14:55:28:442

      JGroups config

      <!--
       Default stack using IP multicasting. It is similar to the "udp"
       stack in stacks.xml, but doesn't use streaming state transfer and flushing
       author: Bela Ban
       version: $Id: udp.xml,v 1.29 2008/09/26 15:59:33 belaban Exp $
      -->
      <!-- mcast_addr="${jgroups.udp.mcast_addr:232.10.10.10}" -->
      <config>
       <UDP
       mcast_addr="${jgroups.udp.mcast_addr:CONFIG_MULTICAST_IN_DG_PROPS}"
       mcast_port="${jgroups.udp.mcast_port:45588}"
       tos="8"
       ucast_recv_buf_size="20000000"
       ucast_send_buf_size="640000"
       mcast_recv_buf_size="25000000"
       mcast_send_buf_size="640000"
       loopback="false"
       discard_incompatible_packets="true"
       max_bundle_size="64000"
       max_bundle_timeout="30"
       ip_ttl="${jgroups.udp.ip_ttl:1}"
       enable_bundling="true"
       enable_diagnostics="true"
       thread_naming_pattern="cl"
      
       thread_pool.enabled="true"
       thread_pool.min_threads="2"
       thread_pool.max_threads="8"
       thread_pool.keep_alive_time="5000"
       thread_pool.queue_enabled="true"
       thread_pool.queue_max_size="10000"
       thread_pool.rejection_policy="discard"
      
       oob_thread_pool.enabled="true"
       oob_thread_pool.min_threads="1"
       oob_thread_pool.max_threads="8"
       oob_thread_pool.keep_alive_time="5000"
       oob_thread_pool.queue_enabled="false"
       oob_thread_pool.queue_max_size="100"
       oob_thread_pool.rejection_policy="Run"/>
      
       <PING timeout="2000"
       num_initial_members="3"/>
       <MERGE2 max_interval="30000"
       min_interval="10000"/>
       <FD_SOCK/>
       <FD_ALL/>
       <VERIFY_SUSPECT timeout="1500" />
       <BARRIER />
       <pbcast.NAKACK use_stats_for_retransmission="false"
       exponential_backoff="150"
       use_mcast_xmit="true" gc_lag="0"
       retransmit_timeout="50,300,600,1200"
       discard_delivered_msgs="true"/>
       <UNICAST timeout="300,600,1200"/>
       <pbcast.STABLE stability_delay="1000" desired_avg_gossip="50000"
       max_bytes="1000000"/>
       <VIEW_SYNC avg_send_interval="60000" />
       <pbcast.GMS print_local_addr="true" join_timeout="3000"
       shun="false"
       view_bundling="true"/>
       <FC max_credits="500000"
       min_threshold="0.20"/>
       <FRAG2 frag_size="60000" />
       <!--pbcast.STREAMING_STATE_TRANSFER /-->
       <pbcast.STATE_TRANSFER />
       <!-- pbcast.FLUSH /-->
      </config>
      


      Output from Node 1 (that works fine):
      [3/19/09 14:54:30:222] INFO org.jboss.cache.jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
      [3/19/09 14:54:30:255] INFO org.jgroups.JChannel - JGroups version: 2.7.0.GA
      [3/19/09 14:54:30:310] 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
      6: class org.jgroups.protocols.FD_SOCK$FdHeader
      7: class org.jgroups.protocols.FragHeader
      13: class org.jgroups.protocols.PingHeader
      21: class org.jgroups.protocols.UNICAST$UnicastHeader
      22: class org.jgroups.protocols.VERIFY_SUSPECT$VerifyHeader
      24: class org.jgroups.protocols.pbcast.GMS$GmsHeader
      25: class org.jgroups.protocols.pbcast.NakAckHeader
      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
      34: interface org.jgroups.Address
      35: class org.jgroups.blocks.RequestCorrelator$Header
      36: class org.jgroups.protocols.PingRsp
      38: class java.util.Vector
      39: class org.jgroups.protocols.pbcast.JoinRsp
      40: class org.jgroups.util.Digest
      41: class java.util.Hashtable
      53: class org.jgroups.protocols.COMPRESS$CompressHeader
      54: class org.jgroups.protocols.FC$FcHeader
      56: class org.jgroups.protocols.TpHeader
      57: class org.jgroups.protocols.ENCRYPT$EncryptHeader
      58: class org.jgroups.protocols.SEQUENCER$SequencerHeader
      59: class org.jgroups.protocols.FD_SIMPLE$FdHeader
      60: class org.jgroups.protocols.VIEW_SYNC$ViewSyncHeader
      61: class org.jgroups.protocols.FD_ALL$Header
      62: class org.jgroups.protocols.SFC$Header
      63: class org.jgroups.mux.MuxHeader
      64: class org.jgroups.protocols.pbcast.FLUSH$FlushHeader
      65: class org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER$StateHeader
      66: class org.jgroups.blocks.PullPushAdapter$PullHeader
      67: class org.jgroups.protocols.AuthHeader

      [3/19/09 14:54:30:535] DEBUG org.jgroups.protocols.pbcast.GMS - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl
      [3/19/09 14:54:30:557] DEBUG org.jgroups.protocols.FRAG2 - received CONFIG event: {bind_addr=nikita-wx10/172.17.50.103}
      [3/19/09 14:54:30:558] DEBUG org.jgroups.protocols.UDP - received CONFIG event: {bind_addr=nikita-wx10/172.17.50.103}
      [3/19/09 14:54:30:585] DEBUG org.jgroups.protocols.UDP - received CONFIG event: {frag_size=59800}
      [3/19/09 14:54:30:603] TRACE org.jgroups.protocols.pbcast.STABLE - stable task started
      [3/19/09 14:54:30:603] DEBUG org.jgroups.protocols.UDP - creating sockets and starting threads
      [3/19/09 14:54:30:603] DEBUG org.jgroups.protocols.UDP - sockets will use interface 172.17.50.103
      [3/19/09 14:54:30:606] DEBUG org.jgroups.protocols.UDP - socket information:
      local_addr=172.17.50.103:54561, mcast_addr=232.10.10.11:45588, bind_addr=nikita-wx10/172.17.50.103, ttl=1
      sock: bound to 172.17.50.103:54561, receive buffer size=20000000, send buffer size=640000
      mcast_sock: bound to 172.17.50.103:45588, send buffer size=640000, receive buffer size=25000000
      [3/19/09 14:54:30:654] TRACE org.jgroups.protocols.UDP - joined /224.0.75.75:7500 on lo
      [3/19/09 14:54:30:655] TRACE org.jgroups.protocols.UDP - joined /224.0.75.75:7500 on eth4
      [3/19/09 14:54:30:656] TRACE org.jgroups.blocks.MessageDispatcher$ProtocolAdapter - setting local_addr (null) to 172.17.50.103:54561
      [3/19/09 14:54:30:663] DEBUG org.jgroups.protocols.UDP - created unicast receiver thread
      [3/19/09 14:54:30:663] DEBUG org.jgroups.protocols.UDP - created multicast receiver thread
      [3/19/09 14:54:30:665] TRACE org.jgroups.protocols.FD_SOCK - waiting for client connections on nikita-wx10/172.17.50.103:62842
      [3/19/09 14:54:30:673] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:30:675] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:54:30:680] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:31:676] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:31:676] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:54:31:676] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:32:671] TRACE org.jgroups.protocols.PING - discovery took 2007 ms: responses: 0 total (0 servers (0 coord), 0 clients)
      [3/19/09 14:54:32:671] DEBUG org.jgroups.protocols.pbcast.GMS - initial_mbrs are []
      [3/19/09 14:54:32:671] DEBUG org.jgroups.protocols.pbcast.GMS - no initial members discovered: creating group as first member
      [3/19/09 14:54:32:685] DEBUG org.jgroups.protocols.pbcast.GMS - [local_addr=172.17.50.103:54561] view is [172.17.50.103:54561|0] [172.17.50.103:54561]
      [3/19/09 14:54:32:689] DEBUG org.jgroups.protocols.FD_SOCK - VIEW_CHANGE received: [172.17.50.103:54561]
      [3/19/09 14:54:32:691] TRACE org.jgroups.protocols.pbcast.STABLE - resetting digest from NAKACK: [172.17.50.103:54561#0]
      [3/19/09 14:54:32:691] TRACE org.jgroups.protocols.FC - new membership: [172.17.50.103:54561]
      [3/19/09 14:54:32:691] TRACE org.jgroups.protocols.FC - creditors are []
      [3/19/09 14:54:32:692] INFO org.jboss.cache.RPCManagerImpl - Received new cluster view: [172.17.50.103:54561|0] [172.17.50.103:54561]
      [3/19/09 14:54:32:698] DEBUG org.jgroups.protocols.pbcast.GMS - 172.17.50.103:54561 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl
      [3/19/09 14:54:32:698] DEBUG org.jgroups.protocols.pbcast.GMS - created group (first member). My view is [172.17.50.103:54561|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl
      [3/19/09 14:54:32:698] INFO org.jboss.cache.RPCManagerImpl - Cache local address is 172.17.50.103:54561
      [3/19/09 14:54:32:698] INFO org.jboss.cache.RPCManagerImpl - state was retrieved successfully (in 2098 milliseconds)
      [3/19/09 14:54:32:698] INFO org.jboss.cache.factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.3.GA
      [3/19/09 14:54:32:755] INFO org.jboss.cache.jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
      [3/19/09 14:54:32:756] TRACE org.jgroups.JChannel - already connected to dgCollectionCacheCluster
      [3/19/09 14:54:32:756] INFO org.jboss.cache.RPCManagerImpl - Cache local address is 172.17.50.103:54561
      [3/19/09 14:54:32:756] INFO org.jboss.cache.RPCManagerImpl - state was retrieved successfully (in 0 milliseconds)
      [3/19/09 14:54:32:756] INFO org.jboss.cache.factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.3.GA
      [3/19/09 14:54:32:810] INFO org.jboss.cache.jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
      [3/19/09 14:54:32:811] TRACE org.jgroups.JChannel - already connected to dgTimestampsCacheCluster
      [3/19/09 14:54:32:811] INFO org.jboss.cache.RPCManagerImpl - Cache local address is 172.17.50.103:54561
      [3/19/09 14:54:32:811] INFO org.jboss.cache.RPCManagerImpl - state was retrieved successfully (in 0 milliseconds)
      [3/19/09 14:54:32:811] INFO org.jboss.cache.factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.3.GA
      [3/19/09 14:54:32:847] INFO org.jboss.cache.jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
      [3/19/09 14:54:32:847] INFO org.jboss.cache.factories.ComponentRegistry - JBoss Cache version: JBossCache 'Naga' 3.0.3.GA
      [3/19/09 14:54:35:208] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:35:208] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:54:35:208] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:35:758] WARN org.hibernate.bytecode.cglib.BytecodeProviderImpl - The CGLIB BytecodeProvider impl is considered deprecated and not recommended for use
      [3/19/09 14:54:36:209] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:36:209] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:54:36:209] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:37:195] TRACE org.jgroups.protocols.PING - discovery took 2003 ms: responses: 0 total (0 servers (0 coord), 0 clients)
      [3/19/09 14:54:37:195] DEBUG org.jgroups.protocols.MERGE2 - 172.17.50.103:54561 is looking for merge candidates, found initial_mbrs=[[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]]
      [3/19/09 14:54:37:195] TRACE org.jgroups.protocols.MERGE2 - MERGE2.FindSubgroups thread terminated (local_addr=172.17.50.103:54561)
      [3/19/09 14:54:40:605] TRACE org.jgroups.protocols.pbcast.STABLE - setting latest_local_digest from NAKACK: [172.17.50.103:54561#0]
      [3/19/09 14:54:40:605] TRACE org.jgroups.protocols.pbcast.STABLE - sending stable msg [172.17.50.103:54561#0]
      [3/19/09 14:54:40:610] TRACE org.jgroups.protocols.pbcast.NAKACK - sending 172.17.50.103:54561#1
      [3/19/09 14:54:40:611] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are STABLE: [STABLE_GOSSIP]: digest is 172.17.50.103:54561: [0 : 0 (0)], NAKACK: [MSG, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:40:611] TRACE org.jgroups.protocols.UDP - received (mcast) 122 bytes from 172.17.50.103:45588
      [3/19/09 14:54:40:613] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is 172.17.50.103:54561: [0 : 0 (0)], NAKACK: [MSG, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:40:613] TRACE org.jgroups.protocols.pbcast.NAKACK - [172.17.50.103:54561: received 172.17.50.103:54561#1
      [3/19/09 14:54:40:613] TRACE org.jgroups.protocols.pbcast.STABLE - [172.17.50.103:54561] handling digest from 172.17.50.103:54561 (0 votes):
      mine: [172.17.50.103:54561#0]
      other: [172.17.50.103:54561#0]
      result: [172.17.50.103:54561#0]

      [3/19/09 14:54:40:613] TRACE org.jgroups.protocols.pbcast.STABLE - sending stability msg (in 17 ms) [172.17.50.103:54561#0] (copy=32850875)
      [3/19/09 14:54:40:658] TRACE org.jgroups.protocols.pbcast.STABLE - sending stability msg [172.17.50.103:54561#0] (copy=32850875)
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.pbcast.NAKACK - sending 172.17.50.103:54561#2
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are STABLE: [STABILITY]: digest is 172.17.50.103:54561: [0 : 0 (0)], NAKACK: [MSG, seqno=2], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.UDP - received (mcast) 122 bytes from 172.17.50.103:45588
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABILITY]: digest is 172.17.50.103:54561: [0 : 0 (0)], NAKACK: [MSG, seqno=2], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.pbcast.NAKACK - [172.17.50.103:54561: received 172.17.50.103:54561#2
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.pbcast.STABLE - received stability msg from 172.17.50.103:54561: [172.17.50.103:54561#0]
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.pbcast.STABLE - resetting digest from NAKACK: [172.17.50.103:54561#1]
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.pbcast.NAKACK - received stable digest 172.17.50.103:54561: [0 : 0 (0)]
      [3/19/09 14:54:40:659] TRACE org.jgroups.protocols.pbcast.NAKACK - deleting msgs <= 0 from 172.17.50.103:54561
      [3/19/09 14:54:59:601] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:54:59:601] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:54:59:601] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:00:602] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:00:602] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:00:602] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:01:603] TRACE org.jgroups.protocols.PING - discovery took 2002 ms: responses: 0 total (0 servers (0 coord), 0 clients)
      [3/19/09 14:55:01:603] DEBUG org.jgroups.protocols.MERGE2 - 172.17.50.103:54561 is looking for merge candidates, found initial_mbrs=[[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]]
      [3/19/09 14:55:01:603] TRACE org.jgroups.protocols.MERGE2 - MERGE2.FindSubgroups thread terminated (local_addr=172.17.50.103:54561)
      [3/19/09 14:55:24:010] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:24:017] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:24:017] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:25:011] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:25:011] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:25:011] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:26:010] TRACE org.jgroups.protocols.PING - discovery took 2002 ms: responses: 0 total (0 servers (0 coord), 0 clients)
      [3/19/09 14:55:26:010] DEBUG org.jgroups.protocols.MERGE2 - 172.17.50.103:54561 is looking for merge candidates, found initial_mbrs=[[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]]
      [3/19/09 14:55:26:010] TRACE org.jgroups.protocols.MERGE2 - MERGE2.FindSubgroups thread terminated (local_addr=172.17.50.103:54561)
      [3/19/09 14:55:28:442] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:442] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:442] TRACE org.jgroups.protocols.PING - received GET_MBRS_REQ from 172.17.50.103:56879, sending response [PING: type=GET_MBRS_RSP, arg=[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]]
      [3/19/09 14:55:28:443] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_RSP, arg=[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:458] TRACE org.jgroups.protocols.UDP - received (ucast) 94 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:458] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (3 headers), size=0 bytes, flags=OOB], headers are GMS: GmsHeader[JOIN_REQ_WITH_STATE_TRANSFER], UNICAST: [UNICAST: DATA, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:459] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- DATA(172.17.50.103:56879: #1
      [3/19/09 14:55:28:459] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561: created new connection for dst 172.17.50.103:56879
      [3/19/09 14:55:28:482] TRACE org.jgroups.stack.AckReceiverWindow - removed OOB message with seqno=1
      [3/19/09 14:55:28:482] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> ACK(172.17.50.103:56879: #1)
      [3/19/09 14:55:28:482] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are UNICAST: [UNICAST: ACK, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:533] TRACE org.jgroups.protocols.pbcast.GMS - processing [JOIN_WITH_STATE_TRANSFER(172.17.50.103:56879)]
      [3/19/09 14:55:28:533] DEBUG org.jgroups.protocols.pbcast.GMS - new=[172.17.50.103:56879], suspected=[], leaving=[], new view: [172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:533] DEBUG org.jgroups.protocols.pbcast.STABLE - suspending message garbage collection
      [3/19/09 14:55:28:535] DEBUG org.jgroups.protocols.pbcast.STABLE - resume task started, max_suspend_time=33000
      [3/19/09 14:55:28:535] TRACE org.jgroups.protocols.pbcast.GMS - mcasting view {[172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879]} (2 mbrs)

      [3/19/09 14:55:28:535] TRACE org.jgroups.protocols.pbcast.NAKACK - sending 172.17.50.103:54561#3
      [3/19/09 14:55:28:535] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are GMS: GmsHeader[VIEW]: view=[172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879], NAKACK: [MSG, seqno=3], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:569] TRACE org.jgroups.protocols.UDP - sending 1 msgs (126 bytes (0.2% of max_bundle_size), collected in 34ms) to 1 destination(s)
      [3/19/09 14:55:28:570] TRACE org.jgroups.protocols.UDP - received (mcast) 143 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:570] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (3 headers), size=0 bytes], headers are GMS: GmsHeader[VIEW]: view=[172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879], NAKACK: [MSG, seqno=3], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:570] TRACE org.jgroups.protocols.pbcast.NAKACK - [172.17.50.103:54561: received 172.17.50.103:54561#3
      [3/19/09 14:55:28:570] DEBUG org.jgroups.protocols.pbcast.GMS - view=[172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:570] DEBUG org.jgroups.protocols.pbcast.GMS - [local_addr=172.17.50.103:54561] view is [172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:572] TRACE org.jgroups.protocols.VIEW_SYNC - view send task started
      [3/19/09 14:55:28:572] DEBUG org.jgroups.protocols.FD_SOCK - VIEW_CHANGE received: [172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:579] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_SOCK: I_HAVE_SOCK, mbr=172.17.50.103:54561, sock_addr=172.17.50.103:62842, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:580] TRACE org.jgroups.protocols.UDP - received (mcast) 87 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:580] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=172.17.50.103:54561, sock_addr=172.17.50.103:62842, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:581] TRACE org.jgroups.protocols.FD_SOCK - i-have-sock: 172.17.50.103:54561 --> 172.17.50.103:62842 (cache is {172.17.50.103:54561=172.17.50.103:62842})
      [3/19/09 14:55:28:582] TRACE org.jgroups.protocols.FD_SOCK - pinger_thread started
      [3/19/09 14:55:28:583] DEBUG org.jgroups.protocols.FD_SOCK - ping_dest is 172.17.50.103:56879, pingable_mbrs=[172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:583] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are FD_SOCK: WHO_HAS_SOCK, mbr=172.17.50.103:56879, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:585] TRACE org.jgroups.protocols.UDP - received (ucast) 87 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:585] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=172.17.50.103:56879, sock_addr=172.17.50.103:62882, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:586] TRACE org.jgroups.protocols.FD_SOCK - i-have-sock: 172.17.50.103:56879 --> 172.17.50.103:62882 (cache is {172.17.50.103:56879=172.17.50.103:62882, 172.17.50.103:54561=172.17.50.103:62842})
      [3/19/09 14:55:28:590] TRACE org.jgroups.protocols.FD_SOCK - ping_dest=172.17.50.103:56879, ping_sock=Socket[addr=/172.17.50.103,port=62882,localport=62883], cache={172.17.50.103:56879=172.17.50.103:62882, 172.17.50.103:54561=172.17.50.103:62842}
      [3/19/09 14:55:28:592] TRACE org.jgroups.protocols.pbcast.STABLE - resetting digest from NAKACK: [172.17.50.103:54561#3, 172.17.50.103:56879#0]
      [3/19/09 14:55:28:592] TRACE org.jgroups.protocols.FC - new membership: [172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:592] TRACE org.jgroups.protocols.FC - creditors are []
      [3/19/09 14:55:28:592] INFO org.jboss.cache.RPCManagerImpl - Received new cluster view: [172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879]
      [3/19/09 14:55:28:592] TRACE org.jgroups.protocols.pbcast.GMS - sending VIEW_ACK to 172.17.50.103:54561
      [3/19/09 14:55:28:592] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561: created new connection for dst 172.17.50.103:54561
      [3/19/09 14:55:28:594] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> DATA(172.17.50.103:54561: #1
      [3/19/09 14:55:28:595] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:54561, src=172.17.50.103:54561, headers are GMS: GmsHeader[VIEW_ACK]: view=null, UNICAST: [UNICAST: DATA, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:596] TRACE org.jgroups.protocols.UDP - received (ucast) 85 bytes from 172.17.50.103:54561
      [3/19/09 14:55:28:596] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:54561 (3 headers), size=0 bytes, flags=OOB], headers are GMS: GmsHeader[VIEW_ACK]: view=null, UNICAST: [UNICAST: DATA, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:596] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- DATA(172.17.50.103:54561: #1
      [3/19/09 14:55:28:596] TRACE org.jgroups.stack.AckReceiverWindow - removed OOB message with seqno=1
      [3/19/09 14:55:28:596] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> ACK(172.17.50.103:54561: #1)
      [3/19/09 14:55:28:596] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:54561, src=172.17.50.103:54561, headers are UNICAST: [UNICAST: ACK, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:597] TRACE org.jgroups.protocols.UDP - received (ucast) 68 bytes from 172.17.50.103:54561
      [3/19/09 14:55:28:597] TRACE org.jgroups.protocols.pbcast.GMS - received all ACKs (0) for [172.17.50.103:54561|1]
      [3/19/09 14:55:28:598] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> DATA(172.17.50.103:56879: #1
      [3/19/09 14:55:28:598] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are GMS: GmsHeader[JOIN_RSP]: join_rsp=view: [172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879], digest: 172.17.50.103:56879: [0 : 0], 172.17.50.103:54561: [0 : 2 (2)], UNICAST: [UNICAST: DATA, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:598] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:54561 (2 headers), size=0 bytes], headers are UNICAST: [UNICAST: ACK, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:598] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- ACK(172.17.50.103:54561: #1)
      [3/19/09 14:55:28:603] TRACE org.jgroups.protocols.UDP - received (ucast) 68 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:603] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (2 headers), size=0 bytes], headers are UNICAST: [UNICAST: ACK, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:603] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- ACK(172.17.50.103:56879: #1)
      [3/19/09 14:55:28:612] TRACE org.jgroups.protocols.UDP - received (mcast) 87 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:612] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=172.17.50.103:56879, sock_addr=172.17.50.103:62882, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:612] TRACE org.jgroups.protocols.FD_SOCK - i-have-sock: 172.17.50.103:56879 --> 172.17.50.103:62882 (cache is {172.17.50.103:56879=172.17.50.103:62882, 172.17.50.103:54561=172.17.50.103:62842})
      [3/19/09 14:55:28:613] TRACE org.jgroups.protocols.UDP - received (ucast) 70 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:613] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: GET_CACHE, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:613] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are FD_SOCK: GET_CACHE_RSP, cache={172.17.50.103:54561=172.17.50.103:62842, 172.17.50.103:56879=172.17.50.103:62882}, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:616] TRACE org.jgroups.protocols.UDP - received (ucast) 85 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:617] TRACE org.jgroups.protocols.FD_SOCK - accepted connection from /172.17.50.103:62884
      [3/19/09 14:55:28:617] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (3 headers), size=0 bytes, flags=OOB], headers are GMS: GmsHeader[VIEW_ACK]: view=null, UNICAST: [UNICAST: DATA, seqno=2], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:617] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- DATA(172.17.50.103:56879: #2
      [3/19/09 14:55:28:617] TRACE org.jgroups.stack.AckReceiverWindow - removed OOB message with seqno=2
      [3/19/09 14:55:28:617] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> ACK(172.17.50.103:56879: #2)
      [3/19/09 14:55:28:617] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are UNICAST: [UNICAST: ACK, seqno=2], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:619] TRACE org.jgroups.protocols.FD_SOCK - waiting for client connections on nikita-wx10/172.17.50.103:62842
      [3/19/09 14:55:28:619] TRACE org.jgroups.protocols.pbcast.GMS - received all ACKs (0) for [172.17.50.103:54561|1]
      [3/19/09 14:55:28:619] TRACE org.jgroups.protocols.pbcast.STABLE - resetting digest from NAKACK: [172.17.50.103:54561#3, 172.17.50.103:56879#0]
      [3/19/09 14:55:28:619] DEBUG org.jgroups.protocols.pbcast.STABLE - resuming message garbage collection
      [3/19/09 14:55:28:621] TRACE org.jgroups.protocols.UDP - received (ucast) 109 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:622] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (3 headers), size=0 bytes], headers are STATE_TRANSFER: type=STATE_REQ, sender=172.17.50.103:56879 id=1237499728620, UNICAST: [UNICAST: DATA, seqno=3], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:622] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- DATA(172.17.50.103:56879: #3
      [3/19/09 14:55:28:622] TRACE org.jgroups.stack.AckReceiverWindow - removed seqno=3
      [3/19/09 14:55:28:622] TRACE org.jgroups.protocols.BARRIER - barrier was closed
      [3/19/09 14:55:28:623] DEBUG org.jgroups.protocols.pbcast.STATE_TRANSFER - digest is 172.17.50.103:56879: [0 : 0 (0)], 172.17.50.103:54561: [0 : 3 (3)], getting application state
      [3/19/09 14:55:28:629] TRACE org.jgroups.protocols.BARRIER - barrier was opened
      [3/19/09 14:55:28:629] TRACE org.jgroups.protocols.pbcast.STATE_TRANSFER - sending state for ID=null to 172.17.50.103:56879 (16384 bytes)
      [3/19/09 14:55:28:629] TRACE org.jgroups.protocols.FC - sender 172.17.50.103:56879 minus 16384 credits, 483616 remaining
      [3/19/09 14:55:28:630] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> DATA(172.17.50.103:56879: #2
      [3/19/09 14:55:28:630] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are STATE_TRANSFER: type=STATE_RSP, sender=172.17.50.103:54561 id=0, digest=172.17.50.103:56879: [0 : 0 (0)], 172.17.50.103:54561: [0 : 3 (3)], UNICAST: [UNICAST: DATA, seqno=2], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:630] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 --> ACK(172.17.50.103:56879: #3)
      [3/19/09 14:55:28:630] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:56879, src=172.17.50.103:54561, headers are UNICAST: [UNICAST: ACK, seqno=3], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:644] TRACE org.jgroups.protocols.UDP - received (ucast) 68 bytes from 172.17.50.103:56879
      [3/19/09 14:55:28:644] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (2 headers), size=0 bytes], headers are UNICAST: [UNICAST: ACK, seqno=2], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:644] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:54561 <-- ACK(172.17.50.103:56879: #2)
      [3/19/09 14:55:31:586] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:31:586] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:31:586] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:31:587] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:31:593] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 3014 ms old

      [3/19/09 14:55:31:616] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:31:616] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:34:588] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:34:588] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:34:588] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:34:588] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:34:594] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2978 ms old

      [3/19/09 14:55:34:617] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:34:617] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:37:590] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:37:590] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:37:590] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:37:590] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:37:595] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2978 ms old

      [3/19/09 14:55:37:619] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:37:619] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:38:397] TRACE org.jgroups.protocols.UDP - received (mcast) 156 bytes from 172.17.50.103:45588
      [3/19/09 14:55:38:397] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is 172.17.50.103:56879: [0 : 0 (0)], 172.17.50.103:54561: [0 : 3 (3)], NAKACK: [MSG, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:38:397] TRACE org.jgroups.protocols.pbcast.NAKACK - [172.17.50.103:54561: received 172.17.50.103:56879#1
      [3/19/09 14:55:38:398] TRACE org.jgroups.protocols.pbcast.STABLE - [172.17.50.103:54561] handling digest from 172.17.50.103:56879 (0 votes):
      mine: [172.17.50.103:54561#3, 172.17.50.103:56879#0]
      other: [172.17.50.103:54561#3, 172.17.50.103:56879#0]
      result: [172.17.50.103:54561#3, 172.17.50.103:56879#0]

      [3/19/09 14:55:40:592] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:40:592] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:40:592] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:40:592] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:40:596] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2977 ms old

      [3/19/09 14:55:40:620] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:40:621] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:43:595] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:43:595] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:43:595] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:43:595] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:43:597] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2976 ms old

      [3/19/09 14:55:43:621] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:43:621] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:45:388] TRACE org.jgroups.protocols.pbcast.STABLE - setting latest_local_digest from NAKACK: [172.17.50.103:54561#3, 172.17.50.103:56879#1]
      [3/19/09 14:55:45:388] TRACE org.jgroups.protocols.pbcast.STABLE - sending stable msg [172.17.50.103:54561#3, 172.17.50.103:56879#1]
      [3/19/09 14:55:45:388] TRACE org.jgroups.protocols.pbcast.NAKACK - sending 172.17.50.103:54561#4
      [3/19/09 14:55:45:388] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are STABLE: [STABLE_GOSSIP]: digest is 172.17.50.103:56879: [0 : 1 (1)], 172.17.50.103:54561: [0 : 3 (3)], NAKACK: [MSG, seqno=4], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:45:389] TRACE org.jgroups.protocols.UDP - received (mcast) 156 bytes from 172.17.50.103:45588
      [3/19/09 14:55:45:389] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is 172.17.50.103:56879: [0 : 1 (1)], 172.17.50.103:54561: [0 : 3 (3)], NAKACK: [MSG, seqno=4], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:45:389] TRACE org.jgroups.protocols.pbcast.NAKACK - [172.17.50.103:54561: received 172.17.50.103:54561#4
      [3/19/09 14:55:45:389] TRACE org.jgroups.protocols.pbcast.STABLE - [172.17.50.103:54561] handling digest from 172.17.50.103:54561 (1 votes):
      mine: [172.17.50.103:54561#3, 172.17.50.103:56879#0]
      other: [172.17.50.103:54561#3, 172.17.50.103:56879#1]
      result: [172.17.50.103:54561#3, 172.17.50.103:56879#0]

      [3/19/09 14:55:45:389] TRACE org.jgroups.protocols.pbcast.STABLE - sending stability msg (in 299 ms) [172.17.50.103:54561#3, 172.17.50.103:56879#0] (copy=16132954)
      [3/19/09 14:55:45:689] TRACE org.jgroups.protocols.pbcast.STABLE - sending stability msg [172.17.50.103:54561#3, 172.17.50.103:56879#0] (copy=16132954)
      [3/19/09 14:55:45:689] TRACE org.jgroups.protocols.pbcast.NAKACK - sending 172.17.50.103:54561#5
      [3/19/09 14:55:45:689] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are STABLE: [STABILITY]: digest is 172.17.50.103:56879: [0 : 0 (1)], 172.17.50.103:54561: [0 : 3 (3)], NAKACK: [MSG, seqno=5], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:45:689] TRACE org.jgroups.protocols.UDP - received (mcast) 156 bytes from 172.17.50.103:45588
      [3/19/09 14:55:45:689] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABILITY]: digest is 172.17.50.103:56879: [0 : 0 (1)], 172.17.50.103:54561: [0 : 3 (3)], NAKACK: [MSG, seqno=5], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:45:690] TRACE org.jgroups.protocols.pbcast.NAKACK - [172.17.50.103:54561: received 172.17.50.103:54561#5
      [3/19/09 14:55:45:690] TRACE org.jgroups.protocols.pbcast.STABLE - received stability msg from 172.17.50.103:54561: [172.17.50.103:54561#3, 172.17.50.103:56879#0]
      [3/19/09 14:55:45:690] TRACE org.jgroups.protocols.pbcast.STABLE - resetting digest from NAKACK: [172.17.50.103:54561#4, 172.17.50.103:56879#1]
      [3/19/09 14:55:45:690] TRACE org.jgroups.protocols.pbcast.NAKACK - received stable digest 172.17.50.103:56879: [0 : 0 (1)], 172.17.50.103:54561: [0 : 3 (3)]
      [3/19/09 14:55:45:690] TRACE org.jgroups.protocols.pbcast.NAKACK - deleting msgs <= 0 from 172.17.50.103:56879
      [3/19/09 14:55:45:690] TRACE org.jgroups.protocols.pbcast.NAKACK - deleting msgs <= 3 from 172.17.50.103:54561
      [3/19/09 14:55:46:597] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:46:597] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:46:597] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:46:597] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:46:599] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2978 ms old

      [3/19/09 14:55:46:623] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:46:623] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:48:415] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:48:415] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:48:415] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:48:416] TRACE org.jgroups.protocols.UDP - received (ucast) 80 bytes from 172.17.50.103:56879
      [3/19/09 14:55:48:416] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=[own_addr=172.17.50.103:56879, coord_addr=172.17.50.103:54561, is_server=true, is_coord=false]], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:48:416] TRACE org.jgroups.protocols.PING - received GET_MBRS_RSP, rsp=[own_addr=172.17.50.103:56879, coord_addr=172.17.50.103:54561, is_server=true, is_coord=false]
      [3/19/09 14:55:49:416] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:49:416] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:49:416] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:49:417] TRACE org.jgroups.protocols.UDP - received (ucast) 80 bytes from 172.17.50.103:56879
      [3/19/09 14:55:49:417] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:54561, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=[own_addr=172.17.50.103:56879, coord_addr=172.17.50.103:54561, is_server=true, is_coord=false]], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:49:417] TRACE org.jgroups.protocols.PING - received GET_MBRS_RSP, rsp=[own_addr=172.17.50.103:56879, coord_addr=172.17.50.103:54561, is_server=true, is_coord=false]
      [3/19/09 14:55:49:598] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:49:598] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:49:598] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:49:598] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:49:600] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2977 ms old

      [3/19/09 14:55:49:624] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:49:624] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:50:417] TRACE org.jgroups.protocols.PING - discovery took 2002 ms: responses: 1 total (1 servers (0 coord), 0 clients)
      [3/19/09 14:55:50:417] DEBUG org.jgroups.protocols.MERGE2 - 172.17.50.103:54561 is looking for merge candidates, found initial_mbrs=[[own_addr=172.17.50.103:56879, coord_addr=172.17.50.103:54561, is_server=true, is_coord=false], [own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]]
      [3/19/09 14:55:50:417] TRACE org.jgroups.protocols.MERGE2 - MERGE2.FindSubgroups thread terminated (local_addr=172.17.50.103:54561)
      [3/19/09 14:55:52:600] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:54561, headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:52:600] TRACE org.jgroups.protocols.FD_ALL - 172.17.50.103:54561 sent heartbeat to cluster
      [3/19/09 14:55:52:600] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:52:600] TRACE org.jgroups.protocols.FD_ALL - checking for expired senders, table is:
      172.17.50.103:56879: 2976 ms old

      [3/19/09 14:55:52:600] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:52:625] TRACE org.jgroups.protocols.UDP - received (mcast) 60 bytes from 172.17.50.103:45588
      [3/19/09 14:55:52:626] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are FD_ALL: heartbeat, UDP: [channel_name=dgEntityCacheCluster]


      Output from Node 2 (that hangs)
      [3/19/09 14:55:28:074] INFO org.jboss.cache.jmx.PlatformMBeanServerRegistration - JBossCache MBeans were successfully registered to the platform mbean server.
      [3/19/09 14:55:28:099] INFO org.jgroups.JChannel - JGroups version: 2.7.0.GA
      [3/19/09 14:55:28:147] 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
      6: class org.jgroups.protocols.FD_SOCK$FdHeader
      7: class org.jgroups.protocols.FragHeader
      13: class org.jgroups.protocols.PingHeader
      21: class org.jgroups.protocols.UNICAST$UnicastHeader
      22: class org.jgroups.protocols.VERIFY_SUSPECT$VerifyHeader
      24: class org.jgroups.protocols.pbcast.GMS$GmsHeader
      25: class org.jgroups.protocols.pbcast.NakAckHeader
      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
      34: interface org.jgroups.Address
      35: class org.jgroups.blocks.RequestCorrelator$Header
      36: class org.jgroups.protocols.PingRsp
      38: class java.util.Vector
      39: class org.jgroups.protocols.pbcast.JoinRsp
      40: class org.jgroups.util.Digest
      41: class java.util.Hashtable
      53: class org.jgroups.protocols.COMPRESS$CompressHeader
      54: class org.jgroups.protocols.FC$FcHeader
      56: class org.jgroups.protocols.TpHeader
      57: class org.jgroups.protocols.ENCRYPT$EncryptHeader
      58: class org.jgroups.protocols.SEQUENCER$SequencerHeader
      59: class org.jgroups.protocols.FD_SIMPLE$FdHeader
      60: class org.jgroups.protocols.VIEW_SYNC$ViewSyncHeader
      61: class org.jgroups.protocols.FD_ALL$Header
      62: class org.jgroups.protocols.SFC$Header
      63: class org.jgroups.mux.MuxHeader
      64: class org.jgroups.protocols.pbcast.FLUSH$FlushHeader
      65: class org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER$StateHeader
      66: class org.jgroups.blocks.PullPushAdapter$PullHeader
      67: class org.jgroups.protocols.AuthHeader

      [3/19/09 14:55:28:336] DEBUG org.jgroups.protocols.pbcast.GMS - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl
      [3/19/09 14:55:28:353] DEBUG org.jgroups.protocols.FRAG2 - received CONFIG event: {bind_addr=nikita-wx10/172.17.50.103}
      [3/19/09 14:55:28:353] DEBUG org.jgroups.protocols.UDP - received CONFIG event: {bind_addr=nikita-wx10/172.17.50.103}
      [3/19/09 14:55:28:379] DEBUG org.jgroups.protocols.UDP - received CONFIG event: {frag_size=59800}
      [3/19/09 14:55:28:393] TRACE org.jgroups.protocols.pbcast.STABLE - stable task started
      [3/19/09 14:55:28:393] DEBUG org.jgroups.protocols.UDP - creating sockets and starting threads
      [3/19/09 14:55:28:393] DEBUG org.jgroups.protocols.UDP - sockets will use interface 172.17.50.103
      [3/19/09 14:55:28:395] DEBUG org.jgroups.protocols.UDP - socket information:
      local_addr=172.17.50.103:56879, mcast_addr=232.10.10.11:45588, bind_addr=nikita-wx10/172.17.50.103, ttl=1
      sock: bound to 172.17.50.103:56879, receive buffer size=20000000, send buffer size=640000
      mcast_sock: bound to 172.17.50.103:45588, send buffer size=640000, receive buffer size=25000000
      [3/19/09 14:55:28:431] TRACE org.jgroups.protocols.UDP - joined /224.0.75.75:7500 on lo
      [3/19/09 14:55:28:431] TRACE org.jgroups.protocols.UDP - joined /224.0.75.75:7500 on eth4
      [3/19/09 14:55:28:432] TRACE org.jgroups.blocks.MessageDispatcher$ProtocolAdapter - setting local_addr (null) to 172.17.50.103:56879
      [3/19/09 14:55:28:435] DEBUG org.jgroups.protocols.UDP - created unicast receiver thread
      [3/19/09 14:55:28:435] DEBUG org.jgroups.protocols.UDP - created multicast receiver thread
      [3/19/09 14:55:28:436] TRACE org.jgroups.protocols.FD_SOCK - waiting for client connections on nikita-wx10/172.17.50.103:62882
      [3/19/09 14:55:28:440] TRACE org.jgroups.protocols.UDP - sending msg to null, src=172.17.50.103:56879, headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:442] TRACE org.jgroups.protocols.UDP - received (mcast) 81 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:443] TRACE org.jgroups.protocols.UDP - received (ucast) 80 bytes from 172.17.50.103:54561
      [3/19/09 14:55:28:447] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:56879 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=dgEntityCacheCluster], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:449] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:56879, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:449] TRACE org.jgroups.protocols.PING - received GET_MBRS_RSP, rsp=[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]
      [3/19/09 14:55:28:450] TRACE org.jgroups.protocols.PING - discovery took 14 ms: responses: 1 total (1 servers (1 coord), 0 clients)
      [3/19/09 14:55:28:450] DEBUG org.jgroups.protocols.pbcast.GMS - initial_mbrs are [[own_addr=172.17.50.103:54561, coord_addr=172.17.50.103:54561, is_server=true, is_coord=true]]
      [3/19/09 14:55:28:450] DEBUG org.jgroups.protocols.pbcast.GMS - election results: {172.17.50.103:54561=1}
      [3/19/09 14:55:28:450] DEBUG org.jgroups.protocols.pbcast.GMS - sending handleJoin(172.17.50.103:56879) to 172.17.50.103:54561
      [3/19/09 14:55:28:451] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:56879: created new connection for dst 172.17.50.103:54561
      [3/19/09 14:55:28:456] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:56879 --> DATA(172.17.50.103:54561: #1
      [3/19/09 14:55:28:457] TRACE org.jgroups.protocols.UDP - sending msg to 172.17.50.103:54561, src=172.17.50.103:56879, headers are GMS: GmsHeader[JOIN_REQ_WITH_STATE_TRANSFER], UNICAST: [UNICAST: DATA, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:482] TRACE org.jgroups.protocols.UDP - received (ucast) 68 bytes from 172.17.50.103:54561
      [3/19/09 14:55:28:483] TRACE org.jgroups.protocols.UDP - message is [dst: 172.17.50.103:56879, src: 172.17.50.103:54561 (2 headers), size=0 bytes], headers are UNICAST: [UNICAST: ACK, seqno=1], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:485] TRACE org.jgroups.protocols.UNICAST - 172.17.50.103:56879 <-- ACK(172.17.50.103:54561: #1)
      [3/19/09 14:55:28:570] TRACE org.jgroups.protocols.UDP - received (mcast) 143 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:575] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (3 headers), size=0 bytes], headers are GMS: GmsHeader[VIEW]: view=[172.17.50.103:54561|1] [172.17.50.103:54561, 172.17.50.103:56879], NAKACK: [MSG, seqno=3], UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:576] TRACE org.jgroups.protocols.pbcast.NAKACK - message was discarded (not yet server)
      [3/19/09 14:55:28:580] TRACE org.jgroups.protocols.UDP - received (mcast) 87 bytes from 172.17.50.103:45588
      [3/19/09 14:55:28:581] TRACE org.jgroups.protocols.UDP - message is [dst: <null>, src: 172.17.50.103:54561 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=172.17.50.103:54561, sock_addr=172.17.50.103:62842, UDP: [channel_name=dgEntityCacheCluster]
      [3/19/09 14:55:28:581] TRACE org.jgroups.protocols.FD_SOCK - i-have-sock: 172.17.50.103:54561 --> 172.17.50.103:62842 (cache is {172.17.50.103:54561=172.17.50.10


        • 2. Re: JBC+JGroups: 2nd Tomcat hangs during startup
          nikita tovstoles Newbie

          Will do. FWIW: the main thread is waiting here:
          org.jboss.cache.remoting.jgroups.ChannelMessageListener.waitForState(ChannelMessageListener.java:99)

          If I interrupt it, isStateSet is still false, so it enters wait() again. Here's the thread dump:


          "main" prio=6 tid=0x013bc000 nid=0x1218 in Object.wait() [0x0011c000..0x0011fe24]
          java.lang.Thread.State: WAITING (on object monitor)
          at java.lang.Object.wait(Native Method)
          - waiting on <0x41222c58> (a java.lang.Object)
          at java.lang.Object.wait(Object.java:485)
          at org.jboss.cache.remoting.jgroups.ChannelMessageListener.waitForState(ChannelMessageListener.java:99)
          - locked <0x41222c58> (a java.lang.Object)
          at org.jboss.cache.RPCManagerImpl.start(RPCManagerImpl.java:248)
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
          at java.lang.reflect.Method.invoke(Method.java:597)
          at org.jboss.cache.util.reflect.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:144)
          at org.jboss.cache.factories.ComponentRegistry$PrioritizedMethod.invoke(ComponentRegistry.java:883)
          at org.jboss.cache.factories.ComponentRegistry.internalStart(ComponentRegistry.java:680)
          at org.jboss.cache.factories.ComponentRegistry.start(ComponentRegistry.java:561)
          at org.jboss.cache.invocation.CacheInvocationDelegate.start(CacheInvocationDelegate.java:301)
          at org.jboss.cache.DefaultCacheFactory.createCache(DefaultCacheFactory.java:119)
          at com.doppelganger.framework.cache.DGCacheInstanceManagerBean.afterPropertiesSet(DGCacheInstanceManagerBean.java:96)



          • 3. Re: JBC+JGroups: 2nd Tomcat hangs during startup
            nikita tovstoles Newbie

            Looks like Brian answered this question here:
            http://www.jboss.org/index.html?module=bb&op=viewtopic&t=152642

            If using multiple cache instances, each instance needs a dedicated JChannel