[jboss-user] [Clustering/JBoss] - Re: StateTransferTimeout appears to be ignored

Fri Feb 8 12:17:35 EST 2008

The following is my log4j trace of org.jboss.ha category.  Unfortunately it does not appear to contain useful information during the 3+ minute pause after the line "Fetching State".  Is there other information in this log that could give a clue or would you have other thoughts on how I should investigate?

Thank you,
Dave

2008-02-08 11:04:59,787 [main] DEBUG [ClusterPartition] Setting JGProps from xml to: UDP(discard_incompatible_packets=true;down_thread=false;enable_bundling=false;ip_ttl=2;loopback=false;max_
bundle_size=64000;max_bundle_timeout=30;mcast_addr=231.1.2.2;mcast_port=47102;mcast_recv_buf_size=25000000;mcast_send_buf_size=640000;tos=8;ucast_recv_buf_size=20000000;ucast_send_buf_size=64
0000;up_thread=false;use_incoming_packet_handler=true;use_outgoing_packet_handler=false):PING(down_thread=false;num_initial_members=3;timeout=2000;up_thread=false):MERGE2(down_thread=false;ma
x_interval=100000;min_interval=20000;up_thread=false):FD_SOCK(down_thread=false;up_thread=false):FD(down_thread=false;max_tries=5;shun=true;timeout=10000;up_thread=false):VERIFY_SUSPECT(down_
thread=false;timeout=1500;up_thread=false):pbcast.NAKACK(discard_delivered_msgs=true;down_thread=false;gc_lag=0;max_xmit_size=60000;retransmit_timeout=300,600,1200,2400,4800;up_thread=false;u
se_mcast_xmit=false):UNICAST(down_thread=false;timeout=300,600,1200,2400,3600;up_thread=false):pbcast.STABLE(desired_avg_gossip=50000;down_thread=false;max_bytes=400000;stability_delay=1000;u
p_thread=false):pbcast.GMS(down_thread=false;join_retry_timeout=2000;join_timeout=3000;print_local_addr=true;shun=true;up_thread=false;view_bundling=true):FRAG2(down_thread=false;frag_size=60
000;up_thread=false):pbcast.STATE_TRANSFER(down_thread=false;up_thread=false;use_flush=false)
2008-02-08 11:05:00,014 [main] DEBUG [ClusterPartition] Creating jboss:service=MSPTEST_emtrack
2008-02-08 11:05:00,014 [main] DEBUG [ClusterPartition] Creating JGroups JChannel
2008-02-08 11:05:00,279 [main] DEBUG [ClusterPartition] Creating HAPartition
2008-02-08 11:05:00,308 [main] DEBUG [ClusterPartition] Initing HAPartition: org.jboss.ha.framework.server.HAPartitionImpl at 18837f1
2008-02-08 11:05:00,308 [main] INFO [MSPTEST_emtrack] Initializing
2008-02-08 11:05:00,309 [main] DEBUG [MSPTEST_emtrack] setMembershipListener
2008-02-08 11:05:00,309 [main] DEBUG [MSPTEST_emtrack] setMessageListener
2008-02-08 11:05:00,309 [main] DEBUG [MSPTEST_emtrack] create replicant manager
2008-02-08 11:05:00,337 [main] DEBUG [MSPTEST_emtrack] init replicant manager
2008-02-08 11:05:00,337 [main] DEBUG [MSPTEST_emtrack] registerRPCHandler
2008-02-08 11:05:00,337 [main] DEBUG [MSPTEST_emtrack] subscribeToStateTransferEvents
2008-02-08 11:05:00,337 [main] DEBUG [MSPTEST_emtrack] registerMembershipListener
2008-02-08 11:05:00,342 [main] DEBUG [MSPTEST_emtrack] bind replicant manager
2008-02-08 11:05:00,342 [main] DEBUG [MSPTEST_emtrack] create distributed state
2008-02-08 11:05:00,354 [main] DEBUG [MSPTEST_emtrack] init distributed state service
2008-02-08 11:05:00,359 [main] DEBUG [MSPTEST_emtrack] bind distributed state service
2008-02-08 11:05:00,366 [main] DEBUG [MSPTEST_emtrack] done initing.
2008-02-08 11:05:00,366 [main] DEBUG [ClusterPartition] HAPartition initialized
2008-02-08 11:05:00,366 [main] DEBUG [ClusterPartition] Created jboss:service=MSPTEST_emtrack
2008-02-08 11:05:00,367 [main] DEBUG [HASessionStateService] Creating jboss:service=HASessionState
2008-02-08 11:05:00,385 [main] DEBUG [HASessionStateService] Created jboss:service=HASessionState
2008-02-08 11:05:00,386 [main] DEBUG [HANamingService] Creating jboss:service=HAJNDI
2008-02-08 11:05:00,386 [main] DEBUG [HANamingService] Initializing HAJNDI server on partition: MSPTEST_emtrack
2008-02-08 11:05:00,397 [main] DEBUG [HANamingService] initialize HAJNDI
2008-02-08 11:05:00,397 [main] DEBUG [HAJNDI] subscribeToStateTransferEvents
2008-02-08 11:05:00,397 [main] DEBUG [TreeHead] registerRPCHandler
2008-02-08 11:05:00,398 [main] DEBUG [HANamingService] Created jboss:service=HAJNDI
2008-02-08 11:05:00,401 [main] DEBUG [ClusterPartition] Starting jboss:service=MSPTEST_emtrack
2008-02-08 11:05:00,404 [main] DEBUG [ClusterPartition] Starting ClusterPartition: MSPTEST_emtrack
2008-02-08 11:05:02,490 [main] DEBUG [MSPTEST_emtrack] ViewAccepted: initial members set
2008-02-08 11:05:02,494 [main] DEBUG [ClusterPartition] Starting channel
2008-02-08 11:05:02,495 [main] DEBUG [MSPTEST_emtrack] get nodeName
2008-02-08 11:05:02,495 [main] DEBUG [MSPTEST_emtrack] Get current members
2008-02-08 11:05:02,496 [main] INFO [MSPTEST_emtrack] Number of cluster members: 2
2008-02-08 11:05:02,496 [main] INFO [MSPTEST_emtrack] Other members: 1
2008-02-08 11:05:02,496 [main] INFO [MSPTEST_emtrack] Fetching state (will wait for 30000 milliseconds):
2008-02-08 11:05:02,502 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [MSPTEST_emtrack] setState called
2008-02-08 11:08:11,545 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [MSPTEST_emtrack] setState for DistributedReplicantManager
2008-02-08 11:08:11,549 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [MSPTEST_emtrack] setState for HASessionStateTransfer
2008-02-08 11:08:11,549 [DRM Async Publisher#0] DEBUG [MSPTEST_emtrack] DRM: Sleeping before re-publishing for 50ms just in case
2008-02-08 11:08:11,550 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [/HASessionState/Default] Receiving state of HASessionState
2008-02-08 11:08:11,551 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [MSPTEST_emtrack] setState for HAJNDI
2008-02-08 11:08:11,551 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [TreeHead] registerRPCHandler
2008-02-08 11:08:11,551 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [MSPTEST_emtrack] setState for DistributedState
2008-02-08 11:08:11,552 [IncomingPacketHandler (channel=MSPTEST_emtrack)] DEBUG [MSPTEST_emtrack] received a state of 1466 bytes; expanded memory by 4915968 bytes (used memory before: 40976664, used memory after: 45892632)
2008-02-08 11:08:11,552 [main] INFO [MSPTEST_emtrack] state was retrieved successfully (in 189056 milliseconds)

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4127918#4127918

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4127918