4 Replies Latest reply on Apr 22, 2005 11:32 PM by bryan_castillo

Please help. JBoss Cache initialization never returns.

hikamesh Feb 24, 2005 12:50 PM

Hi All

I am using JBossCache in a my java application as a distributed cache. Ocassionally i am running into a issue where TreeCacheAOP intitalization/start never returns. I see the following error
(hosname replaced)
-------------------------------------------------------
GMS: address is myhostname:37009
-------------------------------------------------------
- handleJoin(myhostname:37009) failed, retrying
- handleJoin(myhostname:37009) failed, retrying
- handleJoin(myhostname:37009) failed, retrying
- handleJoin(myhostname:37009) failed, retrying
-

This continues for a long time.

Here is the configuration of the cache

<mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache">
 <depends>jboss:service=Naming</depends>
 <depends>jboss:service=TransactionManager</depends>
 <attribute name="InitialStateRetrievalTimeout">10000</attribute>
 <attribute name="SyncReplTimeout">20000</attribute>
 <attribute name="TransactionManagerLookupClass">org.jboss.cache.DummyTransactionManagerLookup</attribute>
 <attribute name="IsolationLevel">READ_UNCOMMITTED</attribute>
 <attribute name="CacheMode">REPL_SYNC</attribute>
 <attribute name="UseReplQueue">false</attribute>
 <attribute name="ReplQueueInterval">0</attribute>
 <attribute name="ReplQueueMaxElements">0</attribute>
 <attribute name="ClusterName">CFP_SIT</attribute>
 <attribute name="ClusterConfig">
 <config>
 <UDP mcast_recv_buf_size="80000" mcast_send_buf_size="150000" ip_mcast="true" mcast_port="41988"
 ucast_recv_buf_size="80000" mcast_addr="239.255.23.45" loopback="false" ucast_send_buf_size="150000" ip_ttl="64" />
 <PING timeout="2000" down_thread="false" num_initial_members="3" up_thread="false" />
 <MERGE2 max_interval="20000" min_interval="10000" />
 <VERIFY_SUSPECT timeout="1500" down_thread="false" up_thread="false" />
 <pbcast.NAKACK max_xmit_size="8192" down_thread="false" gc_lag="50" up_thread="false" retransmit_timeout="600,1200,2400,4800" />
 <UNICAST timeout="600,1200,2400" down_thread="false" min_threshold="10" window_size="100" />
 <pbcast.STABLE desired_avg_gossip="20000" down_thread="false" up_thread="false" />
 <FRAG frag_size="8192" down_thread="false" up_thread="false" />
 <pbcast.GMS print_local_addr="true" join_timeout="5000" join_retry_timeout="2000" shun="true" />
 <pbcast.STATE_TRANSFER down_thread="true" up_thread="true" />
 </config>
 </attribute>
 <attribute name="FetchStateOnStartup">true</attribute>
 <attribute name="InitialStateRetrievalTimeout">5000</attribute>
 <attribute name="SyncReplTimeout">10000</attribute>
 <attribute name="LockAcquisitionTimeout">15000</attribute>
</mbean>

Anyone knows what is the problem? Please let me know.

Thanks & Regards
Kamesh

P.S: I have seen similar postings in Jboss clustering forum and they did not have any answers too.

1. Re: Please help. JBoss Cache initialization never returns.

castillo.bryan Apr 22, 2005 9:16 PM (in response to hikamesh)

I'm seeing this error in JBoss Cache 1.2.2. My servers are named edieazdev03 and edieazdev02. The error occurs when:
1. Start edieazdev03
2. Start edieazdev02 and wait for 2 and 3 to join each other
3. Shut down edieazdev03
4. Start edeiazdev03 immediately after wait for 2 and 3 to join
each other.
5. Shut down edieazdev02
6. Immediately start up edieazdev02 - it starts spewing that error

2005-04-22 17:57:47,248 [DownHandler (GMS)] WARN DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - handleJoin(edieazdev02:32996) failed, retrying
2005-04-22 17:57:54,267 [DownHandler (GMS)] WARN DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - handleJoin(edieazdev02:32996) failed, retrying

Its as though it is trying to connect to itself. Once it produces this error, I can kill edieazdev02 and start it and it will still error. It gets into some state where I have to pull down all of the hosts and restart all of them. It seems like 3 still thinks 2 is a member of the group when its not and when 2 tries to come back online its told that it should connect to 2. (Just my guess though)

Does anybody know what is wrong, or give me some hints on how I can debug this?

Thanks.

Here is my config

<?xml version="1.0" encoding="UTF-8"?>

jboss:service=Naming
jboss:service=TransactionManager

org.jboss.cache.DummyTransactionManagerLookup
NONE


REPL_ASYNC
true
10000
20000
ExternalPricing-Cluster

<UDP
bind_addr = "172.16.1.63"
mcast_addr = "239.1.2.3"
mcast_port = "48866"
ip_ttl = "64"
ip_mcast = "true"
mcast_send_buf_size = "150000"
mcast_recv_buf_size = "80000"
ucast_send_buf_size = "150000"
ucast_recv_buf_size = "80000"
loopback = "false"
/>
<PING timeout="2000" num_initial_members="1"
up_thread="false" down_thread="false"/>
<MERGE2 min_interval="10000" max_interval="20000"/>

<FD_SOCK/>
<VERIFY_SUSPECT timeout="1500"
up_thread="false" down_thread="false"/>
<pbcast.NAKACK gc_lag="50" retransmit_timeout="600,1200,2400,4800"
max_xmit_size="8192" up_thread="false" down_thread="false"/>
<UNICAST timeout="600,1200,2400" window_size="100" min_threshold="10"
down_thread="false"/>
<pbcast.STABLE desired_avg_gossip="20000"
up_thread="false" down_thread="false"/>
<FRAG frag_size="8192"
down_thread="false" up_thread="false"/>
<pbcast.GMS join_timeout="5000" join_retry_timeout="2000"
shun="true" print_local_addr="true"/>
<pbcast.STATE_TRANSFER up_thread="true" down_thread="true"/>

true
30000
10000
15000
15000


org.jboss.cache.eviction.FIFOPolicy

30

700000
3600

400000
3600

10000

600
Actions

2. Re: Please help. JBoss Cache initialization never returns.

castillo.bryan Apr 22, 2005 9:21 PM (in response to hikamesh)

Here is a reposting of the configuration.

<?xml version="1.0" encoding="UTF-8"?>
<server>
 <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/>
 <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache">

 <depends>jboss:service=Naming</depends>
 <depends>jboss:service=TransactionManager</depends>

 <attribute name="TransactionManagerLookupClass">org.jboss.cache.DummyTransactionManagerLookup</attribute>
 <attribute name="IsolationLevel">NONE</attribute>

 <!-- Valid modes are LOCAL, REPL_ASYNC and REPL_SYNC -->
 <attribute name="CacheMode">REPL_ASYNC</attribute>
 <attribute name="UseReplQueue">true</attribute>
 <attribute name="ReplQueueInterval">10000</attribute>
 <attribute name="ReplQueueMaxElements">20000</attribute>
 <attribute name="ClusterName">ExternalPricing-Cluster</attribute>

 <attribute name="ClusterConfig">
 <config>
 <UDP
 bind_addr = "172.16.1.63"
 mcast_addr = "239.1.2.3"
 mcast_port = "48866"
 ip_ttl = "64"
 ip_mcast = "true"
 mcast_send_buf_size = "150000"
 mcast_recv_buf_size = "80000"
 ucast_send_buf_size = "150000"
 ucast_recv_buf_size = "80000"
 loopback = "false"
 />
 <PING timeout="2000" num_initial_members="1"
 up_thread="false" down_thread="false"/>
 <MERGE2 min_interval="10000" max_interval="20000"/>
 <!--<FD shun="true" up_thread="true" down_thread="true" />-->
 <FD_SOCK/>
 <VERIFY_SUSPECT timeout="1500"
 up_thread="false" down_thread="false"/>
 <pbcast.NAKACK gc_lag="50" retransmit_timeout="600,1200,2400,4800"
 max_xmit_size="8192" up_thread="false" down_thread="false"/>
 <UNICAST timeout="600,1200,2400" window_size="100" min_threshold="10"
 down_thread="false"/>
 <pbcast.STABLE desired_avg_gossip="20000"
 up_thread="false" down_thread="false"/>
 <FRAG frag_size="8192"
 down_thread="false" up_thread="false"/>
 <pbcast.GMS join_timeout="5000" join_retry_timeout="2000"
 shun="true" print_local_addr="true"/>
 <pbcast.STATE_TRANSFER up_thread="true" down_thread="true"/>
 </config>
 </attribute>
 <attribute name="FetchStateOnStartup">true</attribute>
 <attribute name="InitialStateRetrievalTimeout">30000</attribute>
 <attribute name="SyncReplTimeout">10000</attribute>
 <attribute name="LockAcquisitionTimeout">15000</attribute>
 <attribute name="LockAcquisitionTimeout">15000</attribute>

 <!-- Name of the eviction policy class. -->
 <attribute name="EvictionPolicyClass">org.jboss.cache.eviction.FIFOPolicy</attribute>
 <attribute name="EvictionPolicyConfig">
 <config>
 <attribute name="wakeUpIntervalSeconds">30</attribute>
 <region name="/_default_">
 <attribute name="maxNodes">700000</attribute>
 <attribute name="timeToLiveSeconds">3600</attribute>
 </region>
 <region name="/SharedCost">
 <attribute name="maxNodes">400000</attribute>
 <attribute name="timeToLiveSeconds">3600</attribute>
 </region>
 <region name="/PriceCache">
 <attribute name="maxNodes">10000</attribute>
 <!-- 10 minutes -->
 <attribute name="timeToLiveSeconds">600</attribute>
 </region>
 </config>
 </attribute>
 </mbean>
</server>

3. Re: Please help. JBoss Cache initialization never returns.

bryan_castillo Apr 22, 2005 10:33 PM (in response to hikamesh)

Here is the debug output when this error occurs.

If you look at this edieazdev02:30005 is suppose to be the coordinator even though it was shut down. Basically, I brought the coordinator down and back up quickly. When it came back up another node in the cluster, gave it the address and port for a coordinator that was shut down.

class org.jboss.cache.interceptors.CallInterceptor
class org.jboss.cache.interceptors.LockInterceptor
class org.jboss.cache.interceptors.UnlockInterceptor
class org.jboss.cache.interceptors.ReplicationInterceptor
2005-04-22 18:39:28,397 [main] INFO main org.jboss.cache.TreeCache - cache mode is REPL_ASYNC
2005-04-22 18:39:28,583 [main] DEBUG main org.jgroups.conf.ClassConfigurator - mapping is:
1: class org.jgroups.stack.IpAddress
2: class org.jgroups.protocols.CAUSAL$CausalHeader
3: class org.jgroups.protocols.FD$FdHeader
4: class org.jgroups.protocols.FD_PID$FdHeader
5: class org.jgroups.protocols.FD_PROB$FdHeader
6: class org.jgroups.protocols.FD_SOCK$FdHeader
7: class org.jgroups.protocols.FRAG$FragHeader
8: class org.jgroups.protocols.MERGE$MergeHeader
9: class org.jgroups.protocols.NakAckHeader
10: class org.jgroups.protocols.PARTITIONER$PartitionerHeader
11: class org.jgroups.protocols.PerfHeader
12: class org.jgroups.protocols.PIGGYBACK$PiggybackHeader
13: class org.jgroups.protocols.PingHeader
14: class org.jgroups.protocols.TcpHeader
15: class org.jgroups.protocols.TOTAL$Header
16: class org.jgroups.protocols.TOTAL_OLD$TotalHeader
17: class org.jgroups.protocols.TOTAL_TOKEN$TotalTokenHeader
18: class org.jgroups.protocols.TOTAL_TOKEN$RingTokenHeader
19: class org.jgroups.protocols.TunnelHeader
20: class org.jgroups.protocols.UdpHeader
21: class org.jgroups.protocols.UNICAST$UnicastHeader
22: class org.jgroups.protocols.VERIFY_SUSPECT$VerifyHeader
23: class org.jgroups.protocols.WANPIPE$WanPipeHeader
24: class org.jgroups.protocols.pbcast.GMS$GmsHeader
25: class org.jgroups.protocols.pbcast.NakAckHeader
26: class org.jgroups.protocols.pbcast.PbcastHeader
27: class org.jgroups.protocols.pbcast.STABLE$StableHeader
28: class org.jgroups.protocols.pbcast.STATE_TRANSFER$StateHeader
29: class org.jgroups.protocols.SMACK$SmackHeader
50: class org.jgroups.service.lease.LeaseRequestHeader
51: class org.jgroups.service.lease.LeaseResponseHeader
52: class org.jgroups.service.lease.DenyResponseHeader
53: class org.jgroups.protocols.COMPRESS$CompressHeader

2005-04-22 18:39:28,618 [main] DEBUG main org.jgroups.protocols.AUTOCONF - frag_size=64000
2005-04-22 18:39:28,688 [main] DEBUG main org.jgroups.protocols.pbcast.GMS - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl
2005-04-22 18:39:28,749 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - creating sockets and starting threads
2005-04-22 18:39:28,750 [DownHandler (UDP)] INFO DownHandler (UDP) org.jgroups.protocols.UDP - unicast sockets will use interface 172.16.1.62
2005-04-22 18:39:28,772 [DownHandler (UDP)] INFO DownHandler (UDP) org.jgroups.protocols.UDP - socket information:
local_addr=edieazdev02:33005, mcast_addr=239.1.2.3:48866, bind_addr=/172.16.1.62, ttl=64
sock: bound to 172.16.1.62:33005, receive buffer size=65536, send buffer size=65536
mcast_recv_sock: bound to 172.16.1.62:48866, send buffer size=65536, receive buffer size=65536
mcast_send_sock: bound to 172.16.1.62:33006, send buffer size=65536, receive buffer size=65536
2005-04-22 18:39:28,772 [DownHandler (UDP)] INFO DownHandler (UDP) org.jgroups.protocols.UDP - socket information:
local_addr=edieazdev02:33005, mcast_addr=239.1.2.3:48866, bind_addr=/172.16.1.62, ttl=64
sock: bound to 172.16.1.62:33005, receive buffer size=65536, send buffer size=65536
mcast_recv_sock: bound to 172.16.1.62:48866, send buffer size=65536, receive buffer size=65536
mcast_send_sock: bound to 172.16.1.62:33006, send buffer size=65536, receive buffer size=65536
2005-04-22 18:39:28,776 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - created unicast receiver thread
2005-04-22 18:39:28,785 [ServerSocketHandler thread] DEBUG ServerSocketHandler thread org.jgroups.protocols.FD_SOCK - waiting for client connections on port 49152
2005-04-22 18:39:28,786 [FD_SOCK Ping thread] DEBUG FD_SOCK Ping thread org.jgroups.protocols.FD_SOCK - pinger_thread started
2005-04-22 18:39:28,786 [FD_SOCK Ping thread] DEBUG FD_SOCK Ping thread org.jgroups.protocols.FD_SOCK - determinePingDest()=null, pingable_mbrs=[]
2005-04-22 18:39:28,786 [FD_SOCK Ping thread] DEBUG FD_SOCK Ping thread org.jgroups.protocols.FD_SOCK - pinger thread terminated
2005-04-22 18:39:28,787 [DownHandler (FD_SOCK)] DEBUG DownHandler (FD_SOCK) org.jgroups.protocols.PING - FIND_INITIAL_MBRS
2005-04-22 18:39:28,791 [DownHandler (FD_SOCK)] DEBUG DownHandler (FD_SOCK) org.jgroups.protocols.PING - waiting for initial members: time_to_wait=2000, got 0 rsps
2005-04-22 18:39:28,792 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to 239.1.2.3:48866 (src=edieazdev02:33005), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:28,798 [UDP mcast receiver] DEBUG UDP mcast receiver org.jgroups.protocols.UDP - received (mcast) 111 bytes from /172.16.1.62:33006 (size=111 bytes)
2005-04-22 18:39:28,802 [UDP.UcastReceiverThread] DEBUG UDP.UcastReceiverThread org.jgroups.protocols.UDP - received (ucast) 289 bytes from /172.16.1.63:33128
2005-04-22 18:39:28,809 [UDP mcast receiver] DEBUG UDP mcast receiver org.jgroups.protocols.UDP - message is [dst: 239.1.2.3:48866, src: edieazdev02:33005 (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:28,813 [UDP.UcastReceiverThread] DEBUG UDP.UcastReceiverThread org.jgroups.protocols.UDP - message is [dst: edieazdev02:33005, src: edieazdev03:33128 (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_RSP, arg=[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]], UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:28,813 [UDP.UcastReceiverThread] DEBUG UDP.UcastReceiverThread org.jgroups.protocols.PING - received FIND_INITAL_MBRS_RSP, rsp=[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]
2005-04-22 18:39:28,814 [DownHandler (FD_SOCK)] DEBUG DownHandler (FD_SOCK) org.jgroups.protocols.PING - initial mbrs are [[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]]
2005-04-22 18:39:28,814 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - initial_mbrs are [[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]]
2005-04-22 18:39:28,815 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - sending handleJoin(edieazdev02:33005) to edieazdev02:33002
2005-04-22 18:39:28,819 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.pbcast.STABLE - stable task started; num_gossip_runs=3, max_gossip_runs=3
2005-04-22 18:39:28,826 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.stack.AckSenderWindow - window_size=100, min_threshold=10
2005-04-22 18:39:28,827 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> DATA(edieazdev02:33002: #7, first=true)
2005-04-22 18:39:28,832 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:28,832 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:29,439 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #7)
2005-04-22 18:39:29,440 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:29,440 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:29,440 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:30,649 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #7)
2005-04-22 18:39:30,649 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:30,650 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:30,650 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:32,418 [UDP mcast receiver] DEBUG UDP mcast receiver org.jgroups.protocols.UDP - received (mcast) 707 bytes from /172.16.1.63:33129 (size=707 bytes)
2005-04-22 18:39:32,425 [UDP mcast receiver] DEBUG UDP mcast receiver org.jgroups.protocols.UDP - message is [dst: 239.1.2.3:48866, src: edieazdev03:33128 (3 headers), size = 265 bytes], headers are {NAKACK=[NAKACK: MSG, seqno=1, range=null], UDP=[UDP:group_addr=ExternalPricing-Cluster], MessageDispatcher=[Header: name=MessageDispatcher, type=REQ, id=1114220372414, rsp_expected=false], dest_mbrs=[edieazdev02:33002]}
2005-04-22 18:39:32,425 [UpHandler (FD_SOCK)] DEBUG UpHandler (FD_SOCK) org.jgroups.protocols.pbcast.NAKACK - message was discarded (not yet server)
2005-04-22 18:39:33,059 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #7)
2005-04-22 18:39:33,059 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:33,060 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:33,060 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:33,840 [DownHandler (GMS)] WARN DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - handleJoin(edieazdev02:33005) failed, retrying
2005-04-22 18:39:35,469 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #7)
2005-04-22 18:39:35,470 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:35,470 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:35,470 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:35,892 [DownHandler (FD_SOCK)] DEBUG DownHandler (FD_SOCK) org.jgroups.protocols.PING - FIND_INITIAL_MBRS
2005-04-22 18:39:36,029 [DownHandler (FD_SOCK)] DEBUG DownHandler (FD_SOCK) org.jgroups.protocols.PING - waiting for initial members: time_to_wait=2000, got 0 rsps
2005-04-22 18:39:36,029 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to 239.1.2.3:48866 (src=edieazdev02:33005), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:36,035 [UDP mcast receiver] DEBUG UDP mcast receiver org.jgroups.protocols.UDP - received (mcast) 111 bytes from /172.16.1.62:33006 (size=111 bytes)
2005-04-22 18:39:36,076 [UDP.UcastReceiverThread] DEBUG UDP.UcastReceiverThread org.jgroups.protocols.UDP - received (ucast) 289 bytes from /172.16.1.63:33128
2005-04-22 18:39:36,076 [UDP mcast receiver] DEBUG UDP mcast receiver org.jgroups.protocols.UDP - message is [dst: 239.1.2.3:48866, src: edieazdev02:33005 (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:36,305 [UDP.UcastReceiverThread] DEBUG UDP.UcastReceiverThread org.jgroups.protocols.UDP - message is [dst: edieazdev02:33005, src: edieazdev03:33128 (2 headers), size = 0 bytes], headers are {PING=[PING: type=GET_MBRS_RSP, arg=[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]], UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:36,306 [UDP.UcastReceiverThread] DEBUG UDP.UcastReceiverThread org.jgroups.protocols.PING - received FIND_INITAL_MBRS_RSP, rsp=[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]
2005-04-22 18:39:36,306 [DownHandler (FD_SOCK)] DEBUG DownHandler (FD_SOCK) org.jgroups.protocols.PING - initial mbrs are [[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]]
2005-04-22 18:39:36,307 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - initial_mbrs are [[own_addr=edieazdev03:33128, coord_addr=edieazdev02:33002]]
2005-04-22 18:39:36,307 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - sending handleJoin(edieazdev02:33005) to edieazdev02:33002
2005-04-22 18:39:36,308 [DownHandler (GMS)] DEBUG DownHandler (GMS) org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> DATA(edieazdev02:33002: #8, first=false)
2005-04-22 18:39:36,309 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:36,309 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:36,909 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #8)
2005-04-22 18:39:36,910 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:36,910 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:36,910 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:37,879 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #7)
2005-04-22 18:39:37,880 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:37,880 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:37,880 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:38,119 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #8)
2005-04-22 18:39:38,120 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:38,120 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:38,120 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:40,289 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #7)
2005-04-22 18:39:40,290 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:40,290 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:40,290 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=7], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:40,529 [TimeScheduler.Thread] DEBUG TimeScheduler.Thread org.jgroups.protocols.UNICAST - [edieazdev02:33005] --> XMIT(edieazdev02:33002: #8)
2005-04-22 18:39:40,529 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.Message - header for "UDP" is already present: old header=[UDP:group_addr=ExternalPricing-Cluster], new header=[UDP:group_addr=ExternalPricing-Cluster]
2005-04-22 18:39:40,530 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:40,530 [DownHandler (UDP)] DEBUG DownHandler (UDP) org.jgroups.protocols.UDP - sending message to edieazdev02:33002 (src=edieazdev02:33005), headers are {UNICAST=[UNICAST: DATA, seqno=8], GMS=GmsHeader[JOIN_REQ]: mbr=edieazdev02:33005
, UDP=[UDP:group_addr=ExternalPricing-Cluster]}
2005-04-22 18:39:41,309 [DownHandler (GMS)] WARN DownHandler (GMS) org.jgroups.protocols.pbcast.ClientGmsImpl - handleJoin(edieazdev02:33005) failed, retrying

4. Re: Please help. JBoss Cache initialization never returns.

bryan_castillo Apr 22, 2005 11:32 PM (in response to hikamesh)

I took the jgroups protocol stack from the Jboss "all" server configuration

C:\jboss-4.0.1sp1\server\all\deploy\cluster-service.xml

And I'm not seeing the error anymore.

(There are a lot more threads in my JVM now though)

I'm hoping that the number of threads do not increase as I increase the number of nodes. I'm testing with 2 nodes right now, but will be moving up to 7 nodes in production.

 <UDP
 bind_addr = "172.16.1.63"
 mcast_addr = "239.1.2.3"
 mcast_port = "48866"
 ip_ttl = "64"
 ip_mcast = "true"
 mcast_send_buf_size = "150000"
 mcast_recv_buf_size = "80000"
 ucast_send_buf_size = "150000"
 ucast_recv_buf_size = "80000"
 loopback = "false"
 />

 <!-- This is the config JBoss 4.0 app server uses for its clustering -->
 <PING timeout="2000" num_initial_members="3"
 up_thread="true" down_thread="true" />
 <MERGE2 min_interval="10000" max_interval="20000" />
 <FD shun="true" up_thread="true" down_thread="true"
 timeout="2500" max_tries="5" />
 <VERIFY_SUSPECT timeout="3000" num_msgs="3"
 up_thread="true" down_thread="true" />
 <pbcast.NAKACK gc_lag="50" retransmit_timeout="300,600,1200,2400,4800"
 max_xmit_size="8192"
 up_thread="true" down_thread="true" />
 <UNICAST timeout="300,600,1200,2400,4800" window_size="100" min_threshold="10"
 down_thread="true" />
 <pbcast.STABLE desired_avg_gossip="20000"
 up_thread="true" down_thread="true" />
 <FRAG frag_size="8192"
 down_thread="true" up_thread="true" />
 <pbcast.GMS join_timeout="5000" join_retry_timeout="2000"
 shun="true" print_local_addr="true" />

Go to original post