[jboss-jira] [JBoss JIRA] (JGRP-1686) JBOSS CLUSTER issues in vCloud Director

sachin jopat created JGRP-1686: ---------------------------------- Summary: JBOSS CLUSTER issues in vCloud Director Key: JGRP-1686 URL: https://issues.jboss.org/browse/JGRP-1686 Project: JGroups Issue Type: Bug Environment: VMWare vCloud Director Reporter: sachin jopat Assignee: Bela Ban Background:- We recently migrated from VM LabManager to VM vCloud director for virtualization and have been using JBOSS6.1.0 from sometime. So this may not be an issue in JBOSS, but looking for a workaround here. Problem Statement:- While starting Cluster server, it fails to communicate with other servers using UDP multicast for cluster communication, but when we change the transport mechanism from UDP to TCP for cluster communication, the same settings work. Strange, but however we tested UDP multicast is not blocked on VCloud. Below is the change in the Jboss application run.bat file, which worked. But using tcp is not a preferred option especially when we plan to have 8-10 clusters:- Original ‘set COMMAND_ARGS=%COMMAND_ARGS% -u %REM_MCAST_ADDR%’ Changed ‘set COMMAND_ARGS=%COMMAND_ARGS% -Djboss.default.jgroups.stack=tcp’ Changes to run JBoss clusters are confined to the JGroups configuration and all configurations for UDP and TCP are in the below XML file:- JBOSS/server/CONFIG/deploy/cluster/jgroupschannelfactory.sar/META-INF/jgroups-channelfactorystacks.xml Sample configuration:- <protocol_stacks> <stack name="udp"> <config> <UDP bind_port="${jboss.jgroups.udp.bind_port:55200}" /> <PING timeout="2000" num_initial_members="3"/> <MERGE2 max_interval="100000" min_interval="20000"/> <FD_SOCK/> <FD timeout="6000" max_tries="5"/> <pbcast.NAKACK retransmit_timeout="300,600,1200" /> <UNICAST timeout="300,600,1200,2400,3600"/> <pbcast.STABLE desired_avg_gossip="50000" max_bytes="400k"/> <pbcast.GMS join_timeout="3000" /> <FRAG2 frag_size="60k"/> </config> </stack> <stack name="tcp"> <config> <TCP start_port="${jboss.jgroups.tcp.tcp_port:7600}"/> <TCPPING timeout="3000" initial_hosts="Host-A[7600],Host-B[7600]”/> ... </config> </stack> </protocol_stacks> Please find below the logs. So it stops at the below step on the agent cluster node which we try to start soon after Farm agent server successfully started:- Cluster agent boot log:- 09:49:39,196 INFO [HANamingService] Started HAJNDI bootstrap; jnpPort=1300, backlog=50, bindAddress=OM2/192.168.1.201 09:49:39,211 INFO [DetachedHANamingService$AutomaticDiscovery] Listening on /192.168.1.201:1102, group=224.1.1.3, HA-JNDI address=192.168.1.201:1300 09:49:39,227 INFO [TransactionManagerFactory] Using a batchMode transaction manager 09:49:39,242 INFO [ComponentsJmxRegistration] Could not register object with name: org.infinispan:type=Cache,name="distributed-tree(repl_sync)",manager="ha-partition",component=Cache 09:49:39,242 INFO [CacheJmxRegistration] MBeans were successfully registered to the platform mbean server. 09:49:39,258 INFO [RpcManagerImpl] Trying to fetch state from OM1:1299 09:49:39,492 INFO [RpcManagerImpl] Successfully retrieved and applied state from OM1:1299 09:49:39,492 INFO [ComponentRegistry] Infinispan version: Infinispan 'Ursus' 4.2.0.FINAL 09:49:39,492 INFO [DefaultCacheContainerFactory] Started "distributed-tree" cache from "ha-partition" container Farm agent server log:- 2013-08-30 09:48:16,374 INFO [Http11Protocol] (Thread-2) Starting Coyote HTTP/1.1 on http-OM1%2F192.168.1.200-8280 2013-08-30 09:48:16,390 INFO [AjpProtocol] (Thread-2) Starting Coyote AJP/1.3 on ajp-OM1%2F192.168.1.200-8209 2013-08-30 09:48:16,390 INFO [AbstractServer] (Thread-2) JBossAS [6.1.0.Final "Neo"] Started in 1m:6s:488ms 2013-08-30 09:48:58,463 TRACE [UDP] (Timer-5,<ADDR>) sending msg to null, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:58,463 TRACE [UDP] (Timer-5,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB] 2013-08-30 09:48:58,463 TRACE [UDP] (OOB-11,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:58,463 TRACE [PING] (OOB-11,null) received GET_MBRS_REQ from OM1:1299, sending response [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299] 2013-08-30 09:48:58,463 TRACE [UDP] (OOB-11,null) sending msg to OM1:1299, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:58,463 TRACE [UDP] (OOB-12,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:58,463 TRACE [UDP] (OOB-13,null) received [dst: OM1:1299, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:58,463 TRACE [PING] (OOB-13,null) received GET_MBRS_RSP from OM1:1299: own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299 2013-08-30 09:48:59,477 TRACE [UDP] (Timer-2,<ADDR>) sending msg to null, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:59,477 TRACE [UDP] (Timer-2,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB] 2013-08-30 09:48:59,477 TRACE [UDP] (OOB-14,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:59,477 TRACE [PING] (OOB-14,null) received GET_MBRS_REQ from OM1:1299, sending response [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299] 2013-08-30 09:48:59,477 TRACE [UDP] (OOB-14,null) sending msg to OM1:1299, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:59,477 TRACE [UDP] (OOB-15,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:59,477 TRACE [UDP] (OOB-16,null) received [dst: OM1:1299, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:48:59,477 TRACE [PING] (OOB-16,null) received GET_MBRS_RSP from OM1:1299: own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299 2013-08-30 09:49:00,475 TRACE [PING] (Timer-4,<ADDR>) discovery took 2012 ms: responses: 1 total (1 servers (1 coord), 0 clients) 2013-08-30 09:49:00,475 TRACE [MERGE2] (Timer-4,<ADDR>) Discovery results: [OM1:1299]: [OM1:1299|0] [OM1:1299] 2013-08-30 09:49:00,834 TRACE [STABLE] (Timer-5,<ADDR>) OM1:1299: setting latest_local_digest from NAKACK: [OM1:1299#2] 2013-08-30 09:49:00,834 TRACE [STABLE] (Timer-5,<ADDR>) OM1:1299: sending stable msg [OM1:1299#2] 2013-08-30 09:49:00,834 TRACE [NAKACK] (Timer-2,<ADDR>) sending OM1:1299#3 2013-08-30 09:49:00,834 TRACE [UDP] (Timer-2,<ADDR>) sending msg to null, src=OM1:1299, headers are STABLE: [STABLE_GOSSIP]: digest is OM1:1299: [0 : 2 (2)], NAKACK: [MSG, seqno=3], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:00,834 TRACE [UDP] (Timer-2,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB] 2013-08-30 09:49:00,834 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is OM1:1299: [0 : 2 (2)], NAKACK: [MSG, seqno=3], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:00,834 TRACE [UDP] (OOB-18,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is OM1:1299: [0 : 2 (2)], NAKACK: [MSG, seqno=3], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:00,834 TRACE [NAKACK] (OOB-17,null) OM1:1299: received OM1:1299#3 2013-08-30 09:49:00,834 TRACE [STABLE] (OOB-17,null) OM1:1299: handling digest from OM1:1299 (0 votes): mine: [OM1:1299#1] other: [OM1:1299#2] result: [OM1:1299#1] 2013-08-30 09:49:00,834 TRACE [STABLE] (OOB-17,null) OM1:1299: sending stability msg (in 780 ms) [OM1:1299#1] (copy=1081264483) 2013-08-30 09:49:01,630 TRACE [STABLE] (Timer-4,<ADDR>) OM1:1299: sending stability msg [OM1:1299#1] (copy=1081264483) 2013-08-30 09:49:01,630 TRACE [NAKACK] (Timer-4,<ADDR>) sending OM1:1299#4 2013-08-30 09:49:01,630 TRACE [UDP] (Timer-4,<ADDR>) sending msg to null, src=OM1:1299, headers are STABLE: [STABILITY]: digest is OM1:1299: [0 : 1 (2)], NAKACK: [MSG, seqno=4], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:01,630 TRACE [UDP] (Timer-4,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB] 2013-08-30 09:49:01,630 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABILITY]: digest is OM1:1299: [0 : 1 (2)], NAKACK: [MSG, seqno=4], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:01,630 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABILITY]: digest is OM1:1299: [0 : 1 (2)], NAKACK: [MSG, seqno=4], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:01,630 TRACE [NAKACK] (OOB-19,null) OM1:1299: received OM1:1299#4 2013-08-30 09:49:01,630 TRACE [STABLE] (OOB-19,null) OM1:1299: received stability msg from OM1:1299: [OM1:1299#1] 2013-08-30 09:49:01,630 TRACE [STABLE] (OOB-19,null) OM1:1299: resetting digest from NAKACK: [OM1:1299#3] 2013-08-30 09:49:01,630 TRACE [NAKACK] (OOB-19,null) received stable digest OM1:1299: [0 : 1 (2)] 2013-08-30 09:49:01,630 TRACE [NAKACK] (OOB-19,null) deleting msgs <= 1 from OM1:1299 2013-08-30 09:49:25,638 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: 0877da68-118d-d463-ca8c-57545e902c09 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=0877da68-118d-d463-ca8c-57545e902c09, view id=null, is_server=false, is_coord=false, logical_name=OM2:1299, physical_addrs=192.168.1.201:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,638 TRACE [PING] (OOB-19,null) received GET_MBRS_REQ from OM2:1299, sending response [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400] 2013-08-30 09:49:25,638 TRACE [UDP] (OOB-19,null) sending msg to OM2:1299, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|0], is_server=true, is_coord=true, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,716 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are GMS: GmsHeader[JOIN_REQ]: mbr=OM2:1299, UNICAST: DATA, seqno=1, first, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,716 TRACE [UNICAST] (OOB-19,null) OM1:1299 <-- DATA(OM2:1299: #1, first) 2013-08-30 09:49:25,732 TRACE [UNICAST] (OOB-19,null) OM1:1299: created receiver window for OM2:1299 at seqno=#1 for conn-id=0 2013-08-30 09:49:25,732 TRACE [UNICAST] (OOB-19,null) OM1:1299 --> ACK(OM2:1299: #1) 2013-08-30 09:49:25,732 TRACE [UDP] (OOB-19,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,794 DEBUG [GMS] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) new=[OM2:1299], suspected=[], leaving=[], new view: [OM1:1299|1] [OM1:1299, OM2:1299] 2013-08-30 09:49:25,794 TRACE [NAKACK] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending OM1:1299#5 2013-08-30 09:49:25,794 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending msg to null, src=OM1:1299, headers are FLUSH: FLUSH[type=START_FLUSH,viewId=0,members=[OM1:1299]], NAKACK: [MSG, seqno=5], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,794 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes] 2013-08-30 09:49:25,794 TRACE [UDP] (Incoming-1,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=START_FLUSH,viewId=0,members=[OM1:1299]], NAKACK: [MSG, seqno=5], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,810 TRACE [NAKACK] (Incoming-1,null) OM1:1299: received OM1:1299#5 2013-08-30 09:49:25,810 TRACE [UDP] (Incoming-2,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=START_FLUSH,viewId=0,members=[OM1:1299]], NAKACK: [MSG, seqno=5], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,810 DEBUG [FLUSH] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: flush coordinator is starting FLUSH with participants [OM1:1299] 2013-08-30 09:49:25,810 TRACE [UNICAST] (Incoming-1,null) OM1:1299: created connection to OM1:1299 2013-08-30 09:49:25,810 TRACE [UNICAST] (Incoming-1,null) OM1:1299 --> DATA(OM1:1299: #1, conn_id=0, first) 2013-08-30 09:49:25,810 TRACE [UDP] (Incoming-1,null) sending msg to OM1:1299, src=OM1:1299, headers are FLUSH: FLUSH[type=FLUSH_COMPLETED,viewId=0], UNICAST: DATA, seqno=1, first, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,810 DEBUG [FLUSH] (Incoming-1,null) OM1:1299: received START_FLUSH, responded with FLUSH_COMPLETED to OM1:1299 2013-08-30 09:49:25,810 TRACE [UDP] (Incoming-3,null) received [dst: OM1:1299, src: OM1:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=FLUSH_COMPLETED,viewId=0], UNICAST: DATA, seqno=1, first, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,810 TRACE [UNICAST] (Incoming-3,null) OM1:1299 <-- DATA(OM1:1299: #1, first) 2013-08-30 09:49:25,810 TRACE [UNICAST] (Incoming-3,null) OM1:1299: created receiver window for OM1:1299 at seqno=#1 for conn-id=0 2013-08-30 09:49:25,810 TRACE [UNICAST] (Incoming-3,null) OM1:1299 --> ACK(OM1:1299: #1) 2013-08-30 09:49:25,810 TRACE [UDP] (Incoming-3,null) sending msg to OM1:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,810 TRACE [UDP] (Incoming-4,null) received [dst: OM1:1299, src: OM1:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,825 TRACE [UNICAST] (Incoming-4,null) OM1:1299 <-- ACK(OM1:1299: #1) 2013-08-30 09:49:25,810 DEBUG [FLUSH] (Incoming-3,null) OM1:1299: FLUSH_COMPLETED from OM1:1299, completed true, flushMembers [OM1:1299], flushCompleted [OM1:1299] 2013-08-30 09:49:25,825 TRACE [GMS] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: successful GMS flush by coordinator 2013-08-30 09:49:25,825 DEBUG [FLUSH] (Incoming-3,null) OM1:1299: all FLUSH_COMPLETED received 2013-08-30 09:49:25,825 DEBUG [STABLE] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) suspending message garbage collection 2013-08-30 09:49:25,825 DEBUG [STABLE] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) resume task started, max_suspend_time=33000 2013-08-30 09:49:25,825 TRACE [GMS] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: mcasting view {[OM1:1299|1] [OM1:1299, OM2:1299]} (2 mbrs) 2013-08-30 09:49:25,825 TRACE [NAKACK] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending OM1:1299#6 2013-08-30 09:49:25,825 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending msg to null, src=OM1:1299, headers are GMS: GmsHeader[VIEW]: view=[OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=6], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,825 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes] 2013-08-30 09:49:25,825 TRACE [UDP] (Incoming-5,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes], headers are GMS: GmsHeader[VIEW]: view=[OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=6], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,825 TRACE [NAKACK] (Incoming-5,null) OM1:1299: received OM1:1299#6 2013-08-30 09:49:25,825 TRACE [UDP] (Incoming-6,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes], headers are GMS: GmsHeader[VIEW]: view=[OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=6], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,825 DEBUG [NAKACK] (Incoming-5,null) [setDigest()] existing digest: OM1:1299: [1 : 6 (6)] new digest: OM2:1299: [0 : 0], OM1:1299: [1 : 5 (5)] resulting digest: OM2:1299: [0 : 0 (0)], OM1:1299: [1 : 6 (6)] 2013-08-30 09:49:25,825 DEBUG [GMS] (Incoming-5,null) OM1:1299: view is [OM1:1299|1] [OM1:1299, OM2:1299] 2013-08-30 09:49:25,825 TRACE [VIEW_SYNC] (Incoming-5,null) view send task started 2013-08-30 09:49:25,825 DEBUG [FD_SOCK] (Incoming-5,null) VIEW_CHANGE received: [OM1:1299, OM2:1299] 2013-08-30 09:49:25,841 TRACE [UDP] (FD_SOCK pinger,om-agent-om-fence-HAPartition,OM1:1299) sending msg to null, src=OM1:1299, headers are FD_SOCK: I_HAVE_SOCK, mbr=OM1:1299, sock_addr=192.168.1.200:54400, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,841 TRACE [UDP] (FD_SOCK pinger,om-agent-om-fence-HAPartition,OM1:1299) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB] 2013-08-30 09:49:25,841 TRACE [STABLE] (Incoming-5,null) OM1:1299: resetting digest from NAKACK: [OM1:1299#6, OM2:1299#0] 2013-08-30 09:49:25,841 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=OM1:1299, sock_addr=192.168.1.200:54400, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,841 TRACE [UFC] (Incoming-5,null) new membership: [OM1:1299, OM2:1299] 2013-08-30 09:49:25,841 TRACE [FD_SOCK] (OOB-19,null) i-have-sock: OM1:1299 --> 192.168.1.200:54400 (cache is {OM1:1299=192.168.1.200:54400}) 2013-08-30 09:49:25,841 TRACE [MFC] (Incoming-5,null) new membership: [OM1:1299, OM2:1299] 2013-08-30 09:49:25,841 TRACE [FD_SOCK] (FD_SOCK pinger,om-agent-om-fence-HAPartition,OM1:1299) pinger_thread started 2013-08-30 09:49:25,841 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=OM1:1299, sock_addr=192.168.1.200:54400, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,841 DEBUG [FD_SOCK] (FD_SOCK pinger,om-agent-om-fence-HAPartition,OM1:1299) ping_dest is OM2:1299, pingable_mbrs=[OM1:1299, OM2:1299] 2013-08-30 09:49:25,841 INFO [om-agent-om-fence] (Incoming-5,null) New cluster view for partition om-agent-om-fence (id: 1, delta: 1, merge: false) : [OM1:1299, OM2:1299] 2013-08-30 09:49:25,841 TRACE [UDP] (FD_SOCK pinger,om-agent-om-fence-HAPartition,OM1:1299) sending msg to OM2:1299, src=OM1:1299, headers are FD_SOCK: WHO_HAS_SOCK, mbr=OM2:1299, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,841 INFO [JGroupsTransport] (Incoming-5,null) Received new cluster view: [OM1:1299|1] [OM1:1299, OM2:1299] 2013-08-30 09:49:25,841 INFO [om-agent-om-fence] (AsynchViewChangeHandler Thread) I am (OM1:1299) received membershipChanged event: 2013-08-30 09:49:25,841 INFO [om-agent-om-fence] (AsynchViewChangeHandler Thread) Dead members: 0 ([]) 2013-08-30 09:49:25,841 INFO [om-agent-om-fence] (AsynchViewChangeHandler Thread) New Members : 1 ([OM2:1299]) 2013-08-30 09:49:25,841 INFO [om-agent-om-fence] (AsynchViewChangeHandler Thread) All Members : 2 ([OM1:1299, OM2:1299]) 2013-08-30 09:49:25,857 DEBUG [FLUSH] (Incoming-5,null) OM1:1299: installing view [OM1:1299|1] [OM1:1299, OM2:1299] 2013-08-30 09:49:25,857 TRACE [UNICAST] (Incoming-5,null) OM1:1299 --> DATA(OM1:1299: #2, conn_id=0) 2013-08-30 09:49:25,857 TRACE [UDP] (Incoming-5,null) sending msg to OM1:1299, src=OM1:1299, headers are GMS: GmsHeader[VIEW_ACK]: view=null, UNICAST: DATA, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,857 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are GMS: GmsHeader[VIEW_ACK]: view=null, UNICAST: DATA, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,857 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM1:1299: #2) 2013-08-30 09:49:25,857 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM1:1299: #2) 2013-08-30 09:49:25,857 TRACE [GMS] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: received all ACKs (1) from existing members for view [OM1:1299|1] 2013-08-30 09:49:25,857 TRACE [UDP] (OOB-20,null) sending msg to OM1:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,857 TRACE [UNICAST] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: created connection to OM2:1299 2013-08-30 09:49:25,857 TRACE [UNICAST] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299 --> DATA(OM2:1299: #1, conn_id=1, first) 2013-08-30 09:49:25,857 TRACE [UDP] (Incoming-7,null) received [dst: OM1:1299, src: OM1:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:25,857 TRACE [UNICAST] (Incoming-7,null) OM1:1299 <-- ACK(OM1:1299: #2) 2013-08-30 09:49:25,857 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending msg to OM2:1299, src=OM1:1299, headers are GMS: GmsHeader[JOIN_RSP]: join_rsp=view: [OM1:1299|1] [OM1:1299, OM2:1299], digest: OM2:1299: [0 : 0], OM1:1299: [1 : 5 (5)], UNICAST: DATA, seqno=1, conn_id=1, first, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,075 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=OM2:1299, sock_addr=192.168.1.201:54400, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,075 TRACE [FD_SOCK] (OOB-20,null) i-have-sock: OM2:1299 --> 192.168.1.201:54400 (cache is {OM2:1299=192.168.1.201:54400, OM1:1299=192.168.1.200:54400}) 2013-08-30 09:49:26,075 TRACE [FD_SOCK] (FD_SOCK pinger,om-agent-om-fence-HAPartition,OM1:1299) ping_dest=OM2:1299, ping_sock=Socket[addr=/192.168.1.201,port=54400,localport=50257], cache={OM2:1299=192.168.1.201:54400, OM1:1299=192.168.1.200:54400} 2013-08-30 09:49:26,106 TRACE [UDP] (Incoming-8,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,106 TRACE [UNICAST] (Incoming-8,null) OM1:1299 <-- ACK(OM2:1299: #1) 2013-08-30 09:49:26,122 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: I_HAVE_SOCK, mbr=OM2:1299, sock_addr=192.168.1.201:54400, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,122 TRACE [FD_SOCK] (OOB-20,null) i-have-sock: OM2:1299 --> 192.168.1.201:54400 (cache is {OM2:1299=192.168.1.201:54400, OM1:1299=192.168.1.200:54400}) 2013-08-30 09:49:26,122 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD_SOCK: GET_CACHE, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,122 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are FD_SOCK: GET_CACHE_RSP, cache={OM2:1299=192.168.1.201:54400, OM1:1299=192.168.1.200:54400}, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,137 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are GMS: GmsHeader[VIEW_ACK]: view=null, UNICAST: DATA, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,137 TRACE [FD_SOCK] (FD_SOCK server socket acceptor,om-agent-om-fence-HAPartition,OM1:1299) accepted connection from /192.168.1.201:63697 2013-08-30 09:49:26,137 TRACE [FD_SOCK] (FD_SOCK server socket acceptor,om-agent-om-fence-HAPartition,OM1:1299) waiting for client connections on OM1/192.168.1.200:54400 2013-08-30 09:49:26,137 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM2:1299: #2) 2013-08-30 09:49:26,137 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM2:1299: #2) 2013-08-30 09:49:26,137 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,153 TRACE [GMS] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: received all ACKs (1) from joiners for view [OM1:1299|1] 2013-08-30 09:49:26,153 TRACE [STABLE] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: resetting digest from NAKACK: [OM1:1299#6, OM2:1299#0] 2013-08-30 09:49:26,153 DEBUG [STABLE] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) resuming message garbage collection 2013-08-30 09:49:26,153 DEBUG [GMS] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: sending RESUME event 2013-08-30 09:49:26,153 DEBUG [FLUSH] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) OM1:1299: received RESUME, sending STOP_FLUSH to all 2013-08-30 09:49:26,153 TRACE [NAKACK] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending OM1:1299#7 2013-08-30 09:49:26,153 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) sending msg to null, src=OM1:1299, headers are FLUSH: FLUSH[type=STOP_FLUSH,viewId=1], NAKACK: [MSG, seqno=7], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,153 TRACE [UDP] (ViewHandler,om-agent-om-fence-HAPartition,OM1:1299) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes] 2013-08-30 09:49:26,153 TRACE [UDP] (Incoming-9,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=STOP_FLUSH,viewId=1], NAKACK: [MSG, seqno=7], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,153 TRACE [NAKACK] (Incoming-9,null) OM1:1299: received OM1:1299#7 2013-08-30 09:49:26,153 TRACE [UDP] (Incoming-10,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=STOP_FLUSH,viewId=1], NAKACK: [MSG, seqno=7], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,153 DEBUG [FLUSH] (Incoming-9,null) OM1:1299: received STOP_FLUSH, unblocking FLUSH.down() and sending UNBLOCK up 2013-08-30 09:49:26,293 TRACE [UDP] (Incoming-11,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=0 bytes], headers are STREAMING_STATE_TRANSFER: type=STATE_REQ, sender=OM2:1299 id=0, UNICAST: DATA, seqno=3, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,293 TRACE [UNICAST] (Incoming-11,null) OM1:1299 <-- DATA(OM2:1299: #3) 2013-08-30 09:49:26,293 TRACE [UNICAST] (Incoming-11,null) OM1:1299 --> ACK(OM2:1299: #3) 2013-08-30 09:49:26,293 TRACE [UDP] (Incoming-11,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=3, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,309 DEBUG [STREAMING_STATE_TRANSFER] (Incoming-11,null) Responding to state requester OM2:1299 with address 192.168.1.200:50258 and digest null 2013-08-30 09:49:26,309 TRACE [UNICAST] (Incoming-11,null) OM1:1299 --> DATA(OM2:1299: #2, conn_id=1) 2013-08-30 09:49:26,309 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER server socket acceptor,om-agent-om-fence-HAPartition,OM1:1299) StateProviderThreadSpawner listening at 192.168.1.200:50258... 2013-08-30 09:49:26,309 TRACE [UDP] (Incoming-11,null) sending msg to OM2:1299, src=OM1:1299, headers are STREAMING_STATE_TRANSFER: type=STATE_RSP, sender=OM1:1299 id=0, UNICAST: DATA, seqno=2, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,309 TRACE [UDP] (Incoming-12,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=2, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,309 TRACE [UNICAST] (Incoming-12,null) OM1:1299 <-- ACK(OM2:1299: #2) 2013-08-30 09:49:26,309 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER server socket acceptor,om-agent-om-fence-HAPartition,OM1:1299) StateProviderThreadSpawner listening at 192.168.1.200:50258... 2013-08-30 09:49:26,309 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Accepted request for state transfer from /192.168.1.201:63698 handing of to PooledExecutor thread 2013-08-30 09:49:26,325 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Running on Thread[STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299,5,JGroups]. Accepted request for state transfer from /192.168.1.201:63698, original buffer size was 8192 and was reset to 8192, passing outputstream up... 2013-08-30 09:49:26,512 DEBUG [StateTransferManagerImpl] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Generating state. Can provide? true 2013-08-30 09:49:26,590 DEBUG [StateTransferManagerImpl] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Writing 1 StoredEntries to stream 2013-08-30 09:49:26,715 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=9 bytes, flags=OOB|DONT_BUNDLE|NO_FC], headers are RequestCorrelator: id=201, type=REQ, id=2, rsp_expected=true, UNICAST: DATA, seqno=4, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,715 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM2:1299: #4) 2013-08-30 09:49:26,715 TRACE [RequestCorrelator] (OOB-20,null) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 2 2013-08-30 09:49:26,746 TRACE [RequestCorrelator] (OOB-20,null) sending rsp for 2 to OM2:1299 2013-08-30 09:49:26,746 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> DATA(OM2:1299: #3, conn_id=1) 2013-08-30 09:49:26,746 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are RequestCorrelator: id=201, type=RSP, id=2, rsp_expected=false, UNICAST: DATA, seqno=3, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,746 DEBUG [StateTransferManagerImpl] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) State generated, closing object stream 2013-08-30 09:49:26,746 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM2:1299: #4) 2013-08-30 09:49:26,746 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=4, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,746 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) State writer is closing the socket 2013-08-30 09:49:26,761 TRACE [UDP] (Incoming-13,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=3, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,761 TRACE [UNICAST] (Incoming-13,null) OM1:1299 <-- ACK(OM2:1299: #3) 2013-08-30 09:49:26,761 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=9 bytes, flags=OOB|DONT_BUNDLE|NO_FC], headers are RequestCorrelator: id=201, type=REQ, id=3, rsp_expected=true, UNICAST: DATA, seqno=5, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,761 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM2:1299: #5) 2013-08-30 09:49:26,761 TRACE [RequestCorrelator] (OOB-20,null) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 3 2013-08-30 09:49:26,761 TRACE [RequestCorrelator] (OOB-20,null) sending rsp for 3 to OM2:1299 2013-08-30 09:49:26,761 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> DATA(OM2:1299: #4, conn_id=1) 2013-08-30 09:49:26,761 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are RequestCorrelator: id=201, type=RSP, id=3, rsp_expected=false, UNICAST: DATA, seqno=4, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,761 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM2:1299: #5) 2013-08-30 09:49:26,761 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=5, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,777 TRACE [UDP] (Incoming-14,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=4, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,777 TRACE [UNICAST] (Incoming-14,null) OM1:1299 <-- ACK(OM2:1299: #4) 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-15,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=START_FLUSH,viewId=1,members=[OM1:1299, OM2:1299]], NAKACK: [MSG, seqno=1], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 TRACE [NAKACK] (Incoming-15,null) OM1:1299: received OM2:1299#1 2013-08-30 09:49:26,824 TRACE [UNICAST] (Incoming-15,null) OM1:1299 --> DATA(OM2:1299: #5, conn_id=1) 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-15,null) sending msg to OM2:1299, src=OM1:1299, headers are FLUSH: FLUSH[type=FLUSH_COMPLETED,viewId=1], UNICAST: DATA, seqno=5, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 DEBUG [FLUSH] (Incoming-15,null) OM1:1299: received START_FLUSH, responded with FLUSH_COMPLETED to OM2:1299 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-16,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=5, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 TRACE [UNICAST] (Incoming-16,null) OM1:1299 <-- ACK(OM2:1299: #5) 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-17,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=0 bytes], headers are STREAMING_STATE_TRANSFER: type=STATE_REQ, sender=OM2:1299 id=0, UNICAST: DATA, seqno=6, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 TRACE [UNICAST] (Incoming-17,null) OM1:1299 <-- DATA(OM2:1299: #6) 2013-08-30 09:49:26,824 TRACE [UNICAST] (Incoming-17,null) OM1:1299 --> ACK(OM2:1299: #6) 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-17,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=6, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 DEBUG [STREAMING_STATE_TRANSFER] (Incoming-17,null) Responding to state requester OM2:1299 with address 192.168.1.200:50258 and digest null 2013-08-30 09:49:26,824 TRACE [UNICAST] (Incoming-17,null) OM1:1299 --> DATA(OM2:1299: #6, conn_id=1) 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-17,null) sending msg to OM2:1299, src=OM1:1299, headers are STREAMING_STATE_TRANSFER: type=STATE_RSP, sender=OM1:1299 id=0, UNICAST: DATA, seqno=6, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 TRACE [UDP] (Incoming-18,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=6, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:26,824 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER server socket acceptor,om-agent-om-fence-HAPartition,OM1:1299) StateProviderThreadSpawner listening at 192.168.1.200:50258... 2013-08-30 09:49:26,824 TRACE [UNICAST] (Incoming-18,null) OM1:1299 <-- ACK(OM2:1299: #6) 2013-08-30 09:49:26,824 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Accepted request for state transfer from /192.168.1.201:63699 handing of to PooledExecutor thread 2013-08-30 09:49:26,824 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Running on Thread[STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299,5,JGroups]. Accepted request for state transfer from /192.168.1.201:63699, original buffer size was 8192 and was reset to 8192, passing outputstream up... 2013-08-30 09:49:27,058 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) State writer is closing the socket 2013-08-30 09:49:27,151 TRACE [UDP] (Incoming-19,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes], headers are FLUSH: FLUSH[type=STOP_FLUSH,viewId=1], NAKACK: [MSG, seqno=2], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,151 TRACE [NAKACK] (Incoming-19,null) OM1:1299: received OM2:1299#2 2013-08-30 09:49:27,151 DEBUG [FLUSH] (Incoming-19,null) OM1:1299: received STOP_FLUSH, unblocking FLUSH.down() and sending UNBLOCK up 2013-08-30 09:49:27,276 TRACE [UDP] (Incoming-20,null) received [dst: <null>, src: OM2:1299 (4 headers), size=874 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=4, rsp_expected=false, exclusion_list=[OM2:1299], NAKACK: [MSG, seqno=3], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,276 TRACE [NAKACK] (Incoming-20,null) OM1:1299: received OM2:1299#3 2013-08-30 09:49:27,276 TRACE [MFC] (Incoming-20,null) OM2:1299 used 874 credits, 1999126 remaining 2013-08-30 09:49:27,276 TRACE [RequestCorrelator] (Incoming-20,null) calling (org.jboss.ha.core.framework.server.CoreGroupCommunicationService$RpcHandler) with request 4 2013-08-30 09:49:27,276 TRACE [UDP] (Incoming-20,null) received [dst: <null>, src: OM2:1299 (4 headers), size=382 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=5, rsp_expected=true, exclusion_list=[OM2:1299], NAKACK: [MSG, seqno=4], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,276 TRACE [NAKACK] (Incoming-20,null) OM1:1299: received OM2:1299#4 2013-08-30 09:49:27,276 TRACE [MFC] (Incoming-20,null) OM2:1299 used 382 credits, 1998744 remaining 2013-08-30 09:49:27,276 TRACE [RequestCorrelator] (Incoming-20,null) calling (org.jboss.ha.core.framework.server.CoreGroupCommunicationService$RpcHandler) with request 5 2013-08-30 09:49:27,276 TRACE [RequestCorrelator] (Incoming-20,null) sending rsp for 5 to OM2:1299 2013-08-30 09:49:27,276 TRACE [UNICAST] (Incoming-20,null) OM1:1299 --> DATA(OM2:1299: #7, conn_id=1) 2013-08-30 09:49:27,276 TRACE [UDP] (Incoming-20,null) sending msg to OM2:1299, src=OM1:1299, headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=RSP, id=5, rsp_expected=false, UNICAST: DATA, seqno=7, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,292 TRACE [UDP] (Incoming-1,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=7, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,292 TRACE [UNICAST] (Incoming-1,null) OM1:1299 <-- ACK(OM2:1299: #7) 2013-08-30 09:49:27,292 TRACE [UDP] (Incoming-4,null) received [dst: <null>, src: OM2:1299 (4 headers), size=873 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=6, rsp_expected=false, exclusion_list=[OM2:1299], NAKACK: [MSG, seqno=5], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,292 TRACE [NAKACK] (Incoming-4,null) OM1:1299: received OM2:1299#5 2013-08-30 09:49:27,292 TRACE [MFC] (Incoming-4,null) OM2:1299 used 873 credits, 1997871 remaining 2013-08-30 09:49:27,292 TRACE [RequestCorrelator] (Incoming-4,null) calling (org.jboss.ha.core.framework.server.CoreGroupCommunicationService$RpcHandler) with request 6 2013-08-30 09:49:27,323 TRACE [UDP] (Incoming-3,null) received [dst: <null>, src: OM2:1299 (4 headers), size=566 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=7, rsp_expected=true, exclusion_list=[OM2:1299], NAKACK: [MSG, seqno=6], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,323 TRACE [NAKACK] (Incoming-3,null) OM1:1299: received OM2:1299#6 2013-08-30 09:49:27,323 TRACE [MFC] (Incoming-3,null) OM2:1299 used 566 credits, 1997305 remaining 2013-08-30 09:49:27,323 TRACE [RequestCorrelator] (Incoming-3,null) calling (org.jboss.ha.core.framework.server.CoreGroupCommunicationService$RpcHandler) with request 7 2013-08-30 09:49:27,339 TRACE [RequestCorrelator] (Incoming-3,null) sending rsp for 7 to OM2:1299 2013-08-30 09:49:27,354 TRACE [UNICAST] (Incoming-3,null) OM1:1299 --> DATA(OM2:1299: #8, conn_id=1) 2013-08-30 09:49:27,354 TRACE [UDP] (Incoming-3,null) sending msg to OM2:1299, src=OM1:1299, headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=RSP, id=7, rsp_expected=false, UNICAST: DATA, seqno=8, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,354 TRACE [UDP] (Incoming-6,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=8, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,354 TRACE [UNICAST] (Incoming-6,null) OM1:1299 <-- ACK(OM2:1299: #8) 2013-08-30 09:49:27,432 TRACE [UDP] (Incoming-5,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=0 bytes], headers are STREAMING_STATE_TRANSFER: type=STATE_REQ, sender=OM2:1299 id=0, UNICAST: DATA, seqno=7, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,432 TRACE [UNICAST] (Incoming-5,null) OM1:1299 <-- DATA(OM2:1299: #7) 2013-08-30 09:49:27,432 TRACE [UNICAST] (Incoming-5,null) OM1:1299 --> ACK(OM2:1299: #7) 2013-08-30 09:49:27,432 TRACE [UDP] (Incoming-5,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=7, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,432 DEBUG [STREAMING_STATE_TRANSFER] (Incoming-5,null) Responding to state requester OM2:1299 with address 192.168.1.200:50258 and digest null 2013-08-30 09:49:27,432 TRACE [UNICAST] (Incoming-5,null) OM1:1299 --> DATA(OM2:1299: #9, conn_id=1) 2013-08-30 09:49:27,432 TRACE [UDP] (Incoming-5,null) sending msg to OM2:1299, src=OM1:1299, headers are STREAMING_STATE_TRANSFER: type=STATE_RSP, sender=OM1:1299 id=0, UNICAST: DATA, seqno=9, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,432 TRACE [UDP] (Incoming-7,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=9, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,432 TRACE [UNICAST] (Incoming-7,null) OM1:1299 <-- ACK(OM2:1299: #9) 2013-08-30 09:49:27,432 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER server socket acceptor,om-agent-om-fence-HAPartition,OM1:1299) StateProviderThreadSpawner listening at 192.168.1.200:50258... 2013-08-30 09:49:27,432 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Accepted request for state transfer from /192.168.1.201:63701 handing of to PooledExecutor thread 2013-08-30 09:49:27,432 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Running on Thread[STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299,5,JGroups]. Accepted request for state transfer from /192.168.1.201:63701, original buffer size was 8192 and was reset to 8192, passing outputstream up... 2013-08-30 09:49:27,651 DEBUG [StateTransferManagerImpl] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Generating state. Can provide? true 2013-08-30 09:49:27,651 DEBUG [StateTransferManagerImpl] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) Writing 2 StoredEntries to stream 2013-08-30 09:49:27,651 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=9 bytes, flags=OOB|DONT_BUNDLE|NO_FC], headers are RequestCorrelator: id=201, type=REQ, id=8, rsp_expected=true, UNICAST: DATA, seqno=8, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,651 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM2:1299: #8) 2013-08-30 09:49:27,651 TRACE [RequestCorrelator] (OOB-20,null) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 8 2013-08-30 09:49:27,651 TRACE [RequestCorrelator] (OOB-20,null) sending rsp for 8 to OM2:1299 2013-08-30 09:49:27,651 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> DATA(OM2:1299: #10, conn_id=1) 2013-08-30 09:49:27,651 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are RequestCorrelator: id=201, type=RSP, id=8, rsp_expected=false, UNICAST: DATA, seqno=10, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM2:1299: #8) 2013-08-30 09:49:27,666 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=8, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 DEBUG [StateTransferManagerImpl] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) State generated, closing object stream 2013-08-30 09:49:27,666 DEBUG [STREAMING_STATE_TRANSFER] (STREAMING_STATE_TRANSFER-sender-1,om-agent-om-fence-HAPartition,OM1:1299) State writer is closing the socket 2013-08-30 09:49:27,666 TRACE [UDP] (Incoming-8,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=10, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 TRACE [UNICAST] (Incoming-8,null) OM1:1299 <-- ACK(OM2:1299: #10) 2013-08-30 09:49:27,666 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (3 headers), size=9 bytes, flags=OOB|DONT_BUNDLE|NO_FC], headers are RequestCorrelator: id=201, type=REQ, id=9, rsp_expected=true, UNICAST: DATA, seqno=9, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM2:1299: #9) 2013-08-30 09:49:27,666 TRACE [RequestCorrelator] (OOB-20,null) calling (org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher) with request 9 2013-08-30 09:49:27,666 TRACE [RequestCorrelator] (OOB-20,null) sending rsp for 9 to OM2:1299 2013-08-30 09:49:27,666 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> DATA(OM2:1299: #11, conn_id=1) 2013-08-30 09:49:27,666 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are RequestCorrelator: id=201, type=RSP, id=9, rsp_expected=false, UNICAST: DATA, seqno=11, conn_id=1, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM2:1299: #9) 2013-08-30 09:49:27,666 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=9, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 TRACE [UDP] (Incoming-10,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes], headers are UNICAST: ACK, seqno=11, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:27,666 TRACE [UNICAST] (Incoming-10,null) OM1:1299 <-- ACK(OM2:1299: #11) 2013-08-30 09:49:32,814 TRACE [NAKACK] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) sending OM1:1299#8 2013-08-30 09:49:32,814 TRACE [UDP] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) sending msg to null, src=OM1:1299, headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=2, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=8], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,814 TRACE [UDP] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) looping back message [dst: <null>, src: OM1:1299 (4 headers), size=354 bytes] 2013-08-30 09:49:32,830 TRACE [UDP] (Incoming-9,null) received [dst: <null>, src: OM1:1299 (4 headers), size=354 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=2, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=8], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,830 TRACE [NAKACK] (Incoming-9,null) OM1:1299: received OM1:1299#8 2013-08-30 09:49:32,830 TRACE [UDP] (Incoming-11,null) received [dst: <null>, src: OM1:1299 (4 headers), size=354 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=2, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=8], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,830 TRACE [MFC] (Incoming-9,null) OM1:1299 used 354 credits, 1999646 remaining 2013-08-30 09:49:32,845 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (4 headers), size=1024 bytes, flags=OOB|DONT_BUNDLE], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=RSP, id=2, rsp_expected=false, UNICAST: DATA, seqno=10, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,845 TRACE [UNICAST] (OOB-20,null) OM1:1299 <-- DATA(OM2:1299: #10) 2013-08-30 09:49:32,845 TRACE [UFC] (OOB-20,null) OM2:1299 used 1024 credits, 1998976 remaining 2013-08-30 09:49:32,845 TRACE [UNICAST] (OOB-20,null) OM1:1299 --> ACK(OM2:1299: #10) 2013-08-30 09:49:32,845 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are UNICAST: ACK, seqno=10, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,861 TRACE [NAKACK] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) sending OM1:1299#9 2013-08-30 09:49:32,861 TRACE [UDP] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) sending msg to null, src=OM1:1299, headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=3, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=9], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,861 TRACE [UDP] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) looping back message [dst: <null>, src: OM1:1299 (4 headers), size=1463 bytes] 2013-08-30 09:49:32,861 TRACE [UDP] (Incoming-12,null) received [dst: <null>, src: OM1:1299 (4 headers), size=1463 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=3, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=9], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,861 TRACE [NAKACK] (Incoming-12,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:32,861 TRACE [UDP] (Incoming-13,null) received [dst: <null>, src: OM1:1299 (4 headers), size=1463 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=3, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=9], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:32,861 TRACE [MFC] (Incoming-12,null) OM1:1299 used 1463 credits, 1998183 remaining 2013-08-30 09:49:34,187 TRACE [NAKACK] (Timer-4,<ADDR>) sending OM1:1299#10 2013-08-30 09:49:34,187 TRACE [UDP] (Timer-4,<ADDR>) sending msg to null, src=OM1:1299, headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=10], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:34,187 TRACE [UDP] (Timer-4,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB] 2013-08-30 09:49:34,187 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=10], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:34,187 TRACE [NAKACK] (OOB-20,null) OM1:1299: received OM1:1299#10 2013-08-30 09:49:34,187 TRACE [VIEW_SYNC] (OOB-20,null) view from OM1:1299 ([OM1:1299|1]) is same as my own view; ignoring 2013-08-30 09:49:34,187 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=10], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:34,515 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:34,515 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:34,515 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:34,515 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:34,515 TRACE [UDP] (Incoming-14,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:34,515 TRACE [NAKACK] (Incoming-14,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:34,515 TRACE [UDP] (Incoming-14,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,123 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,123 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:35,123 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,123 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:35,123 TRACE [UDP] (Incoming-16,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,123 TRACE [NAKACK] (Incoming-16,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:35,123 TRACE [UDP] (Incoming-16,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,544 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is OM2:1299: [0 : 7 (7)], OM1:1299: [1 : 8 (10)], NAKACK: [MSG, seqno=8], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,544 TRACE [NAKACK] (OOB-19,null) OM1:1299: received OM2:1299#8 2013-08-30 09:49:35,544 TRACE [Retransmitter] (OOB-19,null) added range OM2:1299 [7] 2013-08-30 09:49:35,544 TRACE [STABLE] (OOB-19,null) OM1:1299: handling digest from OM2:1299 (0 votes): mine: [OM1:1299#6, OM2:1299#0] other: [OM1:1299#8, OM2:1299#7] result: [OM1:1299#6, OM2:1299#0] 2013-08-30 09:49:35,856 DEBUG [FD] (Timer-3,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:49:35,856 TRACE [UDP] (Timer-3,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,856 TRACE [NAKACK] (Timer-5,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:35,856 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:35,856 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,137 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,137 TRACE [FD] (OOB-19,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:49:36,137 TRACE [UDP] (OOB-19,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,340 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,340 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:36,340 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,340 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:36,340 TRACE [UDP] (Incoming-18,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,340 TRACE [NAKACK] (Incoming-18,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:36,340 TRACE [UDP] (Incoming-18,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:36,465 TRACE [NAKACK] (Timer-2,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:36,465 TRACE [UDP] (Timer-2,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:37,666 TRACE [NAKACK] (Timer-4,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:37,666 TRACE [UDP] (Timer-4,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:38,742 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:38,742 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:38,742 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:38,742 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:38,742 TRACE [UDP] (Incoming-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:38,742 TRACE [NAKACK] (Incoming-20,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:38,742 TRACE [UDP] (Incoming-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:40,068 TRACE [NAKACK] (Timer-5,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:40,068 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:43,547 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:43,547 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:43,547 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:43,547 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:43,547 TRACE [UDP] (Incoming-1,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:43,547 TRACE [NAKACK] (Incoming-1,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:43,547 TRACE [UDP] (Incoming-1,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:44,218 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=9], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:44,218 TRACE [NAKACK] (OOB-19,null) OM1:1299: received OM2:1299#9 2013-08-30 09:49:44,218 TRACE [VIEW_SYNC] (OOB-19,null) view from OM2:1299 ([OM1:1299|1]) is same as my own view; ignoring 2013-08-30 09:49:44,873 TRACE [NAKACK] (Timer-2,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:44,873 TRACE [UDP] (Timer-2,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:45,872 DEBUG [FD] (Timer-4,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:49:45,872 TRACE [UDP] (Timer-4,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:45,872 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:46,152 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:46,152 TRACE [FD] (OOB-19,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:49:46,152 TRACE [UDP] (OOB-19,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:48,149 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=10], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:48,149 TRACE [NAKACK] (OOB-19,null) OM1:1299: received OM2:1299#10 2013-08-30 09:49:48,149 TRACE [VIEW_SYNC] (OOB-19,null) view from OM2:1299 ([OM1:1299|1]) is same as my own view; ignoring 2013-08-30 09:49:48,352 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:48,352 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:48,352 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:48,352 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:48,352 TRACE [UDP] (Incoming-3,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:48,352 TRACE [UDP] (Incoming-6,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:48,352 TRACE [NAKACK] (Incoming-3,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:49,678 TRACE [NAKACK] (Timer-3,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:49,678 TRACE [UDP] (Timer-3,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:52,673 DEBUG [arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== SCANNING 2013-08-30 09:49:52,673 DEBUG [arjuna] (Periodic Recovery) PeriodicRecovery: background thread scanning 2013-08-30 09:49:52,673 DEBUG [arjuna] (Periodic Recovery) Periodic recovery first pass at Fri, 30 Aug 2013 09:49:52 2013-08-30 09:49:52,673 DEBUG [arjuna] (Periodic Recovery) AtomicActionRecoveryModule first pass 2013-08-30 09:49:52,673 DEBUG [arjuna] (Periodic Recovery) processing /StateManager/BasicAction/TwoPhaseCoordinator/AtomicAction transactions 2013-08-30 09:49:52,673 DEBUG [arjuna] (Periodic Recovery) 2013-08-30 09:49:52,673 DEBUG [txoj] (Periodic Recovery) TORecoveryModule - first pass 2013-08-30 09:49:52,689 DEBUG [arjuna] (Periodic Recovery) 2013-08-30 09:49:52,689 DEBUG [jta] (Periodic Recovery) Local XARecoveryModule - first pass 2013-08-30 09:49:52,689 DEBUG [arjuna] (Periodic Recovery) 2013-08-30 09:49:53,157 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:53,157 TRACE [NAKACK] (OOB-19,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:53,157 TRACE [UDP] (OOB-19,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:53,157 TRACE [UDP] (OOB-19,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:53,157 TRACE [UDP] (Incoming-7,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:53,157 TRACE [UDP] (Incoming-5,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:53,157 TRACE [NAKACK] (Incoming-5,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:54,483 TRACE [NAKACK] (Timer-5,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:54,483 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:55,887 DEBUG [FD] (Timer-2,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:49:55,887 TRACE [UDP] (Timer-2,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:55,887 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,168 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,168 TRACE [FD] (OOB-19,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:49:56,168 TRACE [UDP] (OOB-19,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,511 TRACE [UDP] (Timer-3,<ADDR>) sending msg to null, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,511 TRACE [UDP] (Timer-3,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB] 2013-08-30 09:49:56,526 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,526 TRACE [PING] (OOB-19,null) received GET_MBRS_REQ from OM1:1299, sending response [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299] 2013-08-30 09:49:56,526 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,526 TRACE [UDP] (OOB-19,null) sending msg to OM1:1299, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,526 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,526 TRACE [PING] (OOB-19,null) received GET_MBRS_RSP from OM1:1299: own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299 2013-08-30 09:49:56,526 TRACE [UDP] (OOB-19,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM2:1299, view id=[OM1:1299|1], is_server=true, is_coord=false, logical_name=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:56,526 TRACE [PING] (OOB-19,null) received GET_MBRS_RSP from OM2:1299: own_addr=OM2:1299, view id=[OM1:1299|1], is_server=true, is_coord=false, logical_name=OM2:1299 2013-08-30 09:49:57,540 TRACE [UDP] (Timer-5,<ADDR>) sending msg to null, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,540 TRACE [UDP] (Timer-5,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB] 2013-08-30 09:49:57,540 TRACE [UDP] (OOB-19,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,540 TRACE [PING] (OOB-19,null) received GET_MBRS_REQ from OM1:1299, sending response [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299] 2013-08-30 09:49:57,540 TRACE [UDP] (OOB-19,null) sending msg to OM1:1299, src=OM1:1299, headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,540 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_REQ, cluster=om-agent-om-fence-HAPartition, arg=own_addr=OM1:1299, view id=null, is_server=false, is_coord=false, logical_name=OM1:1299, physical_addrs=192.168.1.200:55400], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,540 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM1:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,540 TRACE [PING] (OOB-17,null) received GET_MBRS_RSP from OM1:1299: own_addr=OM1:1299, view id=[OM1:1299|1], is_server=true, is_coord=true, logical_name=OM1:1299 2013-08-30 09:49:57,540 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are PING: [PING: type=GET_MBRS_RSP, arg=own_addr=OM2:1299, view id=[OM1:1299|1], is_server=true, is_coord=false, logical_name=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,540 TRACE [PING] (OOB-17,null) received GET_MBRS_RSP from OM2:1299: own_addr=OM2:1299, view id=[OM1:1299|1], is_server=true, is_coord=false, logical_name=OM2:1299 2013-08-30 09:49:57,837 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=11], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,837 TRACE [NAKACK] (OOB-17,null) OM1:1299: received OM2:1299#11 2013-08-30 09:49:57,837 TRACE [VIEW_SYNC] (OOB-17,null) view from OM2:1299 ([OM1:1299|1]) is same as my own view; ignoring 2013-08-30 09:49:57,962 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,962 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:49:57,962 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,962 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:49:57,962 TRACE [UDP] (Incoming-8,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:57,962 TRACE [NAKACK] (Incoming-8,null) OM1:1299: received OM1:1299#9 2013-08-30 09:49:57,962 TRACE [UDP] (Incoming-8,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:49:58,523 TRACE [PING] (Timer-4,<ADDR>) discovery took 2012 ms: responses: 2 total (2 servers (1 coord), 0 clients) 2013-08-30 09:49:58,523 TRACE [MERGE2] (Timer-4,<ADDR>) Discovery results: [OM1:1299]: [OM1:1299|1] [OM1:1299, OM2:1299] [OM2:1299]: [OM1:1299|1] [OM1:1299, OM2:1299] 2013-08-30 09:49:59,288 TRACE [NAKACK] (Timer-5,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:49:59,288 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) Periodic recovery second pass at Fri, 30 Aug 2013 09:50:02 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) AtomicActionRecoveryModule second pass 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) 2013-08-30 09:50:02,704 DEBUG [txoj] (Periodic Recovery) TORecoveryModule - second pass 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) 2013-08-30 09:50:02,704 DEBUG [jta] (Periodic Recovery) Local XARecoveryModule - second pass 2013-08-30 09:50:02,704 DEBUG [jta] (Periodic Recovery) Local XARecoveryModule.transactionInitiatedRecovery completed 2013-08-30 09:50:02,704 DEBUG [jta] (Periodic Recovery) Local XARecoveryModule.resourceInitiatedRecovery completed 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) PeriodicRecovery: background thread Status <== INACTIVE 2013-08-30 09:50:02,704 DEBUG [arjuna] (Periodic Recovery) PeriodicRecovery: background thread backing off 2013-08-30 09:50:02,766 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:02,766 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:02,766 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:02,766 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:02,766 TRACE [UDP] (Incoming-11,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:02,766 TRACE [NAKACK] (Incoming-11,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:02,766 TRACE [UDP] (Incoming-11,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,030 TRACE [STABLE] (Timer-4,<ADDR>) OM1:1299: setting latest_local_digest from NAKACK: [OM1:1299#10, OM2:1299#6] 2013-08-30 09:50:04,030 TRACE [STABLE] (Timer-4,<ADDR>) OM1:1299: sending stable msg [OM1:1299#10, OM2:1299#6] 2013-08-30 09:50:04,030 TRACE [NAKACK] (Timer-2,<ADDR>) sending OM1:1299#11 2013-08-30 09:50:04,030 TRACE [UDP] (Timer-2,<ADDR>) sending msg to null, src=OM1:1299, headers are STABLE: [STABLE_GOSSIP]: digest is OM2:1299: [0 : 6 (11)], OM1:1299: [1 : 10 (10)], NAKACK: [MSG, seqno=11], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,030 TRACE [UDP] (Timer-2,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB] 2013-08-30 09:50:04,030 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is OM2:1299: [0 : 6 (11)], OM1:1299: [1 : 10 (10)], NAKACK: [MSG, seqno=11], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,030 TRACE [NAKACK] (OOB-17,null) OM1:1299: received OM1:1299#11 2013-08-30 09:50:04,030 TRACE [STABLE] (OOB-17,null) OM1:1299: handling digest from OM1:1299 (1 votes): mine: [OM1:1299#6, OM2:1299#0] other: [OM1:1299#10, OM2:1299#6] result: [OM1:1299#6, OM2:1299#0] 2013-08-30 09:50:04,030 TRACE [STABLE] (OOB-17,null) OM1:1299: sending stability msg (in 276 ms) [OM1:1299#6, OM2:1299#0] (copy=1662754703) 2013-08-30 09:50:04,030 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABLE_GOSSIP]: digest is OM2:1299: [0 : 6 (11)], OM1:1299: [1 : 10 (10)], NAKACK: [MSG, seqno=11], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,092 TRACE [NAKACK] (Timer-3,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:04,092 TRACE [UDP] (Timer-3,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,311 TRACE [STABLE] (Timer-5,<ADDR>) OM1:1299: sending stability msg [OM1:1299#6, OM2:1299#0] (copy=1662754703) 2013-08-30 09:50:04,311 TRACE [NAKACK] (Timer-5,<ADDR>) sending OM1:1299#12 2013-08-30 09:50:04,311 TRACE [UDP] (Timer-5,<ADDR>) sending msg to null, src=OM1:1299, headers are STABLE: [STABILITY]: digest is OM2:1299: [0 : 0 (11)], OM1:1299: [1 : 6 (10)], NAKACK: [MSG, seqno=12], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,311 TRACE [UDP] (Timer-5,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB] 2013-08-30 09:50:04,311 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABILITY]: digest is OM2:1299: [0 : 0 (11)], OM1:1299: [1 : 6 (10)], NAKACK: [MSG, seqno=12], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,311 TRACE [NAKACK] (OOB-20,null) OM1:1299: received OM1:1299#12 2013-08-30 09:50:04,311 TRACE [STABLE] (OOB-20,null) OM1:1299: received stability msg from OM1:1299: [OM1:1299#6, OM2:1299#0] 2013-08-30 09:50:04,311 TRACE [STABLE] (OOB-20,null) OM1:1299: resetting digest from NAKACK: [OM1:1299#11, OM2:1299#6] 2013-08-30 09:50:04,311 TRACE [NAKACK] (OOB-20,null) received stable digest OM2:1299: [0 : 0 (11)], OM1:1299: [1 : 6 (10)] 2013-08-30 09:50:04,311 TRACE [NAKACK] (OOB-20,null) deleting msgs <= 0 from OM2:1299 2013-08-30 09:50:04,311 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are STABLE: [STABILITY]: digest is OM2:1299: [0 : 0 (11)], OM1:1299: [1 : 6 (10)], NAKACK: [MSG, seqno=12], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:04,311 TRACE [NAKACK] (OOB-20,null) deleting msgs <= 6 from OM1:1299 2013-08-30 09:50:05,902 DEBUG [FD] (Timer-4,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:50:05,902 TRACE [UDP] (Timer-4,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:05,902 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:06,183 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:06,183 TRACE [FD] (OOB-20,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:50:06,183 TRACE [UDP] (OOB-20,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:07,571 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:07,571 TRACE [NAKACK] (OOB-20,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:07,571 TRACE [UDP] (OOB-20,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:07,571 TRACE [UDP] (OOB-20,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:07,571 TRACE [UDP] (Incoming-13,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:07,571 TRACE [NAKACK] (Incoming-13,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:07,571 TRACE [UDP] (Incoming-13,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:08,897 TRACE [NAKACK] (Timer-2,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:08,897 TRACE [UDP] (Timer-2,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,376 TRACE [UDP] (OOB-20,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,376 TRACE [NAKACK] (OOB-20,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:12,376 TRACE [UDP] (OOB-20,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,376 TRACE [UDP] (OOB-20,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:12,376 TRACE [UDP] (Incoming-14,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,376 TRACE [NAKACK] (Incoming-14,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:12,376 TRACE [UDP] (Incoming-14,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,392 TRACE [NAKACK] (Timer-3,<ADDR>) sending OM1:1299#13 2013-08-30 09:50:12,392 TRACE [UDP] (Timer-3,<ADDR>) sending msg to null, src=OM1:1299, headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=13], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,392 TRACE [UDP] (Timer-3,<ADDR>) looping back message [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB] 2013-08-30 09:50:12,392 TRACE [UDP] (OOB-20,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=13], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:12,392 TRACE [NAKACK] (OOB-20,null) OM1:1299: received OM1:1299#13 2013-08-30 09:50:12,392 TRACE [VIEW_SYNC] (OOB-20,null) view from OM1:1299 ([OM1:1299|1]) is same as my own view; ignoring 2013-08-30 09:50:12,392 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM1:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=13], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:13,702 TRACE [NAKACK] (Timer-5,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:13,702 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:15,917 DEBUG [FD] (Timer-4,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:50:15,917 TRACE [UDP] (Timer-4,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:15,917 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:16,198 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:16,198 TRACE [FD] (OOB-17,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:50:16,198 TRACE [UDP] (OOB-17,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:17,181 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:17,181 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:17,181 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:17,181 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:17,181 TRACE [UDP] (Incoming-16,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:17,181 TRACE [NAKACK] (Incoming-16,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:17,181 TRACE [UDP] (Incoming-16,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:18,320 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=12], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:18,320 TRACE [NAKACK] (OOB-17,null) OM1:1299: received OM2:1299#12 2013-08-30 09:50:18,320 TRACE [VIEW_SYNC] (OOB-17,null) view from OM2:1299 ([OM1:1299|1]) is same as my own view; ignoring 2013-08-30 09:50:18,507 TRACE [NAKACK] (Timer-2,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:18,507 TRACE [UDP] (Timer-2,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:21,986 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:21,986 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:21,986 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:21,986 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:21,986 TRACE [UDP] (Incoming-18,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:21,986 TRACE [NAKACK] (Incoming-18,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:21,986 TRACE [UDP] (Incoming-18,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:23,312 TRACE [NAKACK] (Timer-3,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:23,312 TRACE [UDP] (Timer-3,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:25,932 DEBUG [FD] (Timer-5,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:50:25,932 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:25,932 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:26,213 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:26,213 TRACE [FD] (OOB-17,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:50:26,213 TRACE [UDP] (OOB-17,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:26,790 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:26,790 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:26,790 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:26,790 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:26,790 TRACE [UDP] (Incoming-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:26,790 TRACE [NAKACK] (Incoming-20,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:26,790 TRACE [UDP] (Incoming-20,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:27,789 TRACE [UDP] (Incoming-1,null) received [dst: <null>, src: OM2:1299 (4 headers), size=391 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=11, rsp_expected=true, exclusion_list=[OM2:1299], NAKACK: [MSG, seqno=13], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:27,789 TRACE [NAKACK] (Incoming-1,null) OM1:1299: received OM2:1299#13 2013-08-30 09:50:28,116 TRACE [NAKACK] (Timer-4,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:28,116 TRACE [UDP] (Timer-4,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:31,595 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:31,595 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:31,595 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:31,595 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:31,595 TRACE [UDP] (Incoming-4,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:31,595 TRACE [NAKACK] (Incoming-4,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:31,595 TRACE [UDP] (Incoming-4,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:32,921 TRACE [NAKACK] (Timer-2,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:32,921 TRACE [UDP] (Timer-2,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:35,948 DEBUG [FD] (Timer-3,<ADDR>) sending are-you-alive msg to OM2:1299 (own address=OM1:1299) 2013-08-30 09:50:35,948 TRACE [UDP] (Timer-3,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:35,948 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,228 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are FD: heartbeat, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,228 TRACE [FD] (OOB-17,null) received are-you-alive from OM2:1299, sending response 2013-08-30 09:50:36,228 TRACE [UDP] (OOB-17,null) sending msg to OM2:1299, src=OM1:1299, headers are FD: heartbeat ack, UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,400 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,400 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:36,400 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,400 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:36,400 TRACE [UDP] (Incoming-7,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,400 TRACE [UDP] (Incoming-3,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:36,400 TRACE [NAKACK] (Incoming-3,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:37,726 TRACE [NAKACK] (Timer-5,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:37,726 TRACE [UDP] (Timer-5,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:41,205 TRACE [UDP] (OOB-17,null) received [dst: OM1:1299, src: OM2:1299 (2 headers), size=0 bytes, flags=OOB], headers are NAKACK: [XMIT_REQ, range=[9 : 9], sender=OM1:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:41,205 TRACE [NAKACK] (OOB-17,null) OM1:1299: received xmit request from OM2:1299 for OM1:1299 [9 - 9] 2013-08-30 09:50:41,205 TRACE [UDP] (OOB-17,null) sending msg to null, src=OM1:1299, headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:41,205 TRACE [UDP] (OOB-17,null) looping back message [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes] 2013-08-30 09:50:41,205 TRACE [UDP] (Incoming-8,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:41,205 TRACE [UDP] (Incoming-5,null) received [dst: <null>, src: OM1:1299 (2 headers), size=1580 bytes], headers are NAKACK: [XMIT_RSP], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:41,205 TRACE [NAKACK] (Incoming-5,null) OM1:1299: received OM1:1299#9 2013-08-30 09:50:42,531 TRACE [NAKACK] (Timer-4,<ADDR>) OM1:1299: sending XMIT_REQ ([7, 7]) to OM2:1299 2013-08-30 09:50:42,531 TRACE [UDP] (Timer-4,<ADDR>) sending msg to OM2:1299, src=OM1:1299, headers are NAKACK: [XMIT_REQ, range=[7 : 7], sender=OM2:1299], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:42,890 TRACE [NAKACK] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) sending OM1:1299#14 2013-08-30 09:50:42,890 TRACE [UDP] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) sending msg to null, src=OM1:1299, headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=4, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=14], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:42,890 TRACE [UDP] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) looping back message [dst: <null>, src: OM1:1299 (4 headers), size=354 bytes] 2013-08-30 09:50:42,890 TRACE [UDP] (Incoming-11,null) received [dst: <null>, src: OM1:1299 (4 headers), size=354 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=4, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=14], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:42,890 TRACE [UDP] (Incoming-10,null) received [dst: <null>, src: OM1:1299 (4 headers), size=354 bytes], headers are MuxRequestCorrelator: [org.jgroups.blocks.mux.MuxHeader Header], RequestCorrelator: id=201, type=REQ, id=4, rsp_expected=true, exclusion_list=[OM1:1299], NAKACK: [MSG, seqno=14], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:42,890 TRACE [NAKACK] (Incoming-10,null) OM1:1299: received OM1:1299#14 2013-08-30 09:50:42,890 TRACE [MFC] (Incoming-10,null) OM1:1299 used 354 credits, 1997829 remaining 2013-08-30 09:50:44,824 TRACE [UDP] (OOB-17,null) received [dst: <null>, src: OM2:1299 (3 headers), size=0 bytes, flags=OOB], headers are VIEW_SYNC: [VIEW_SYNC], view= [OM1:1299|1] [OM1:1299, OM2:1299], NAKACK: [MSG, seqno=14], UDP: [channel_name=om-agent-om-fence-HAPartition] 2013-08-30 09:50:44,824 TRACE [NAKACK] (OOB-17,null) OM1:1299: received OM2:1299#14 2013-08-30 09:50:44,824 TRACE [VIEW_SYNC] (OOB-17,null) view from OM2:1299 ([OM1:1299|1]) is same as my own view; ignoring -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira