-
1. Re: What happens when the cluster splits?
wdfink Jun 27, 2014 3:57 AM (in response to james.brealey)The cluster should be merged. To understand what happen you need to provide a bit more of your configuration and what you see in the logfiles when split/merge.
It might be helpful if you enable DEBUG for org.jgroups to see more details.
-
2. Re: What happens when the cluster splits?
james.brealey Jun 27, 2014 4:30 AM (in response to wdfink)Thanks for quick response,
Infinispan was being run outside of an application server. The console display showed the "No Physical Address for <x>, dropping message" error on restoring the network. I tried using TCPPing and mcast for discovery with the same results. I'm using version 6.0.2.Final of Infinispan.
I'll have to re-run thee experiments to generate the log files but will do so shortly and post back.
-
3. Re: What happens when the cluster splits?
wdfink Jul 2, 2014 8:53 AM (in response to james.brealey)"No physical address" sounds like a network issue. You may check whether the network addresses are correct and reachable
-
4. Re: What happens when the cluster splits?
james.brealey Jul 4, 2014 11:03 AM (in response to wdfink)Hi,
Thanks for the response again. Sorry it has taken me so long to reply, but I now have something slightly more intelligent to reply with.
The error has become intermittent, and sometimes the cluster does re-form, however I have been entirely unable to re-connect it twice and often not at all.
Below is an example of a failed log. All other network services are working normally: I am able to ping and otherwise communicate directly between the two machines hosting the infinspan instance as normal.
The two machines are called Athene and Daenerys, and the connection test has been both to physically unplug Athene from the network and to power down the switch.
Thank you very much
James
Sample of Log from Athene
2014-07-04 11:58:08,009 [main] DEBUG (jboss.logging :15 ) - Logging Provider: org.jboss.logging.Log4jLoggerProvider 2014-07-04 11:58:08,024 [main] DEBUG (util.FileLookup :61 ) - Unable to find file generic-test-cfg.xml in classpath; searching for this file on the filesystem instead. 2014-07-04 11:58:08,165 [main] WARN (parsing.ParsedCacheMode :37 ) - ISPN000177: REPLICATION-CACH has been deprecated as a synonym for REPL. Use one of [R, REPL, REPLICATION] instead 2014-07-04 11:58:08,180 [main] DEBUG (util.ModuleProperties :50 ) - Loading lifecycle SPI class: org.infinispan.server.core.LifecycleCallbacks@30186ad2 2014-07-04 11:58:08,258 [main] DEBUG (util.ModuleProperties :96 ) - No module command extensions to load 2014-07-04 11:58:08,321 [main] DEBUG (nager.DefaultCacheManager:578 ) - Started cache manager testCluster on null 2014-07-04 11:58:08,461 [main] INFO (jgroups.JGroupsTransport :184 ) - ISPN000078: Starting JGroups Channel 2014-07-04 11:58:08,648 [main] WARN (stack.Configurator :1132) - JGRP000014: TP.loopback has been deprecated: enabled by default 2014-07-04 11:58:08,789 [main] DEBUG (stack.Configurator :820 ) - set property UDP.bind_addr to default value /192.168.1.74 2014-07-04 11:58:08,789 [main] DEBUG (stack.Configurator :820 ) - set property UDP.diagnostics_addr to default value /224.0.75.75 2014-07-04 11:58:08,868 [main] DEBUG (protocols.UDP :320 ) - sockets will use interface 192.168.1.74 2014-07-04 11:58:08,883 [main] DEBUG (protocols.UDP :387 ) - socket information: mcast_addr=228.6.7.8:46655, bind_addr=/192.168.1.74, ttl=2
sock: bound to 192.168.1.74:61232, receive buffer size=20000000, send buffer size=640000
mcast_sock: bound to 192.168.1.74:46655, send buffer size=640000, receive buffer size=25000000
2014-07-04 11:58:08,883 [main] WARN (protocols.UDP :1233) - JGRP000046: bundler_type=old has been removed; using sender-sends-with-timer 2014-07-04 11:58:08,883 [main] DEBUG (pbcast.GMS :1071) - address=Athene-62271, cluster=testCluster, physical address=192.168.1.74:61232 2014-07-04 11:58:11,910 [main] DEBUG (pbcast.NAKACK2 :1302) - [Athene-62271 setDigest()]
existing digest: []
new digest: Athene-62271: [0 (0)] resulting digest: Athene-62271: [0 (0)]
2014-07-04 11:58:11,910 [main] DEBUG (pbcast.GMS :690 ) - Athene-62271: installing view [Athene-62271|0] (1) [Athene-62271] 2014-07-04 11:58:11,910 [main] DEBUG (pbcast.STABLE :202 ) - resuming message garbage collection 2014-07-04 11:58:11,910 [main] DEBUG (protocols.FD_SOCK :338 ) - Athene-62271: VIEW_CHANGE received: [Athene-62271] 2014-07-04 11:58:11,910 [main] DEBUG (jgroups.JGroupsTransport :630 ) - New view accepted: [Athene-62271|0] (1) [Athene-62271] 2014-07-04 11:58:11,910 [main] INFO (jgroups.JGroupsTransport :657 ) - ISPN000094: Received new cluster view: [Athene-62271|0] (1) [Athene-62271] 2014-07-04 11:58:11,910 [main] DEBUG (pbcast.STABLE :202 ) - resuming message garbage collection 2014-07-04 11:58:11,910 [main] DEBUG (pbcast.GMS :307 ) - created cluster (first member). My view is [Athene-62271|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl 2014-07-04 11:58:11,910 [main] INFO (jgroups.JGroupsTransport :222 ) - ISPN000079: Cache local address is Athene-62271, physical addresses are [192.168.1.74:61232] 2014-07-04 11:58:11,910 [main] DEBUG (jgroups.JGroupsTransport :423 ) - Waiting on view being accepted 2014-07-04 11:58:11,925 [main] INFO (s.GlobalComponentRegistry:222 ) - ISPN000128: Infinispan version: Infinispan 'Infinium' 6.0.2.Final 2014-07-04 11:58:12,113 [main] DEBUG (rceptors.InterceptorChain:55 ) - Interceptor chain size: 9 2014-07-04 11:58:12,113 [main] DEBUG (rceptors.InterceptorChain:56 ) - Interceptor chain is: >> org.infinispan.interceptors.InvocationContextInterceptor
>> org.infinispan.interceptors.CacheMgmtInterceptor
>> org.infinispan.statetransfer.StateTransferInterceptor
>> org.infinispan.statetransfer.TransactionSynchronizerInterceptor
>> org.infinispan.interceptors.NotificationInterceptor
>> org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor
>> org.infinispan.interceptors.EntryWrappingInterceptor
>> org.infinispan.interceptors.distribution.NonTxDistributionInterceptor
>> org.infinispan.interceptors.CallInterceptor
2014-07-04 11:58:12,129 [main] DEBUG (jmx.JmxUtil :76 ) - Object name org.infinispan:type=Cache,name="rep(repl_sync)",manager="DefaultCacheManager",component=Cache already registered 2014-07-04 11:58:12,129 [main] INFO (jmx.CacheJmxRegistration :63 ) - ISPN000031: MBeans were successfully registered to the platform MBean server. 2014-07-04 11:58:12,129 [main] DEBUG (.LocalTopologyManagerImpl:86 ) - Node Athene-62271 joining cache rep 2014-07-04 11:58:12,129 [main] DEBUG (.LocalTopologyManagerImpl:183 ) - Updating local consistent hash(es) for cache rep: new topology = CacheTopology{id=0, currentCH=ReplicatedConsistentHash{members=[Athene-62271], numSegments=60, primaryOwners=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=null} 2014-07-04 11:58:12,129 [main] DEBUG (ransfer.StateConsumerImpl:637 ) - Adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] of cache rep 2014-07-04 11:58:12,129 [main] DEBUG (ransfer.StateConsumerImpl:653 ) - Finished adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] of cache rep 2014-07-04 11:58:12,129 [main] DEBUG (nsaction.TransactionTable:436 ) - Topology changed, recalculating minTopologyId 2014-07-04 11:58:12,145 [main] DEBUG (infinispan.CacheImpl :683 ) - Started cache rep on Athene-62271 2014-07-04 11:58:15,240 [INT-1,Athene-62271] WARN (protocols.UDP :1882) - JGRP000032: Athene-62271: no physical address for 8d4a12f0-9abb-934c-14ee-6f8cb5c7cf39, dropping message 2014-07-04 11:58:15,413 [INT-1,Athene-62271] WARN (protocols.UDP :1882) - JGRP000032: Athene-62271: no physical address for 8d4a12f0-9abb-934c-14ee-6f8cb5c7cf39, dropping message opping message
Sample of log From Daenerys:
2014-07-04 11:57:54,993 [main] DEBUG (jboss.logging :15 ) - Logging Provider: org.jboss.logging.Log4jLoggerProvider 2014-07-04 11:57:55,009 [main] DEBUG (util.FileLookup :61 ) - Unable to find file generic-test-cfg.xml in classpath; searching for this file on the filesystem instead. 2014-07-04 11:57:55,206 [main] WARN (parsing.ParsedCacheMode :37 ) - ISPN000177: REPLICATION-CACH has been deprecated as a synonym for REPL. Use one of [R, REPL, REPLICATION] instead 2014-07-04 11:57:55,231 [main] DEBUG (util.ModuleProperties :50 ) - Loading lifecycle SPI class: org.infinispan.server.core.LifecycleCallbacks@463b3d1c 2014-07-04 11:57:55,358 [main] DEBUG (util.ModuleProperties :96 ) - No module command extensions to load 2014-07-04 11:57:55,466 [main] DEBUG (nager.DefaultCacheManager:578 ) - Started cache manager testCluster on null 2014-07-04 11:57:55,619 [main] INFO (jgroups.JGroupsTransport :184 ) - ISPN000078: Starting JGroups Channel 2014-07-04 11:57:55,838 [main] WARN (stack.Configurator :1132) - JGRP000014: TP.loopback has been deprecated: enabled by default 2014-07-04 11:57:56,001 [main] DEBUG (stack.Configurator :820 ) - set property UDP.bind_addr to default value /192.168.1.65 2014-07-04 11:57:56,002 [main] DEBUG (stack.Configurator :820 ) - set property UDP.diagnostics_addr to default value /224.0.75.75 2014-07-04 11:57:56,299 [main] DEBUG (protocols.UDP :320 ) - sockets will use interface 192.168.1.65 2014-07-04 11:57:56,303 [main] WARN (protocols.UDP :525 ) - JGRP000015: the send buffer of socket DatagramSocket was set to 640KB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max send buffer in the OS correctly (e.g. net.core.wmem_max on Linux) 2014-07-04 11:57:56,304 [main] WARN (protocols.UDP :537 ) - JGRP000015: the receive buffer of socket DatagramSocket was set to 20MB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max receive buffer in the OS correctly (e.g. net.core.rmem_max on Linux) 2014-07-04 11:57:56,304 [main] WARN (protocols.UDP :525 ) - JGRP000015: the send buffer of socket MulticastSocket was set to 640KB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max send buffer in the OS correctly (e.g. net.core.wmem_max on Linux) 2014-07-04 11:57:56,305 [main] WARN (protocols.UDP :537 ) - JGRP000015: the receive buffer of socket MulticastSocket was set to 25MB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max receive buffer in the OS correctly (e.g. net.core.rmem_max on Linux) 2014-07-04 11:57:56,306 [main] DEBUG (protocols.UDP :387 ) - socket information: mcast_addr=228.6.7.8:46655, bind_addr=/192.168.1.65, ttl=2
sock: bound to 192.168.1.65:59122, receive buffer size=212992, send buffer size=212992
mcast_sock: bound to 192.168.1.65:46655, send buffer size=212992, receive buffer size=212992
2014-07-04 11:57:56,307 [main] WARN (protocols.UDP :1233) - JGRP000046: bundler_type=old has been removed; using sender-sends-with-timer 2014-07-04 11:57:56,311 [main] DEBUG (pbcast.GMS :1071) - address=daenerys-45263, cluster=testCluster, physical address=192.168.1.65:59122 2014-07-04 11:57:59,324 [main] DEBUG (pbcast.NAKACK2 :1302) - [daenerys-45263 setDigest()]
existing digest: []
new digest: daenerys-45263: [0 (0)] resulting digest: daenerys-45263: [0 (0)]
2014-07-04 11:57:59,325 [main] DEBUG (pbcast.GMS :690 ) - daenerys-45263: installing view [daenerys-45263|0] (1) [daenerys-45263] 2014-07-04 11:57:59,327 [main] DEBUG (pbcast.STABLE :202 ) - resuming message garbage collection 2014-07-04 11:57:59,329 [main] DEBUG (protocols.FD_SOCK :338 ) - daenerys-45263: VIEW_CHANGE received: [daenerys-45263] 2014-07-04 11:57:59,333 [main] DEBUG (jgroups.JGroupsTransport :630 ) - New view accepted: [daenerys-45263|0] (1) [daenerys-45263] 2014-07-04 11:57:59,335 [main] INFO (jgroups.JGroupsTransport :657 ) - ISPN000094: Received new cluster view: [daenerys-45263|0] (1) [daenerys-45263] 2014-07-04 11:57:59,342 [main] DEBUG (pbcast.STABLE :202 ) - resuming message garbage collection 2014-07-04 11:57:59,342 [main] DEBUG (pbcast.GMS :307 ) - created cluster (first member). My view is [daenerys-45263|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl 2014-07-04 11:57:59,343 [main] INFO (jgroups.JGroupsTransport :222 ) - ISPN000079: Cache local address is daenerys-45263, physical addresses are [192.168.1.65:59122] 2014-07-04 11:57:59,344 [main] DEBUG (jgroups.JGroupsTransport :423 ) - Waiting on view being accepted 2014-07-04 11:57:59,356 [main] INFO (s.GlobalComponentRegistry:222 ) - ISPN000128: Infinispan version: Infinispan 'Infinium' 6.0.2.Final 2014-07-04 11:57:59,560 [main] DEBUG (rceptors.InterceptorChain:55 ) - Interceptor chain size: 9 2014-07-04 11:57:59,560 [main] DEBUG (rceptors.InterceptorChain:56 ) - Interceptor chain is: >> org.infinispan.interceptors.InvocationContextInterceptor
>> org.infinispan.interceptors.CacheMgmtInterceptor
>> org.infinispan.statetransfer.StateTransferInterceptor
>> org.infinispan.statetransfer.TransactionSynchronizerInterceptor
>> org.infinispan.interceptors.NotificationInterceptor
>> org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor
>> org.infinispan.interceptors.EntryWrappingInterceptor
>> org.infinispan.interceptors.distribution.NonTxDistributionInterceptor
>> org.infinispan.interceptors.CallInterceptor
2014-07-04 11:57:59,570 [main] DEBUG (jmx.JmxUtil :76 ) - Object name org.infinispan:type=Cache,name="rep(repl_sync)",manager="DefaultCacheManager",component=Cache already registered 2014-07-04 11:57:59,571 [main] INFO (jmx.CacheJmxRegistration :63 ) - ISPN000031: MBeans were successfully registered to the platform MBean server. 2014-07-04 11:57:59,573 [main] DEBUG (.LocalTopologyManagerImpl:86 ) - Node daenerys-45263 joining cache rep 2014-07-04 11:57:59,578 [main] DEBUG (.LocalTopologyManagerImpl:183 ) - Updating local consistent hash(es) for cache rep: new topology = CacheTopology{id=0, currentCH=ReplicatedConsistentHash{members=[daenerys-45263], numSegments=60, primaryOwners=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=null} 2014-07-04 11:57:59,580 [main] DEBUG (ransfer.StateConsumerImpl:637 ) - Adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] of cache rep 2014-07-04 11:57:59,583 [main] DEBUG (ransfer.StateConsumerImpl:653 ) - Finished adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] of cache rep 2014-07-04 11:57:59,583 [main] DEBUG (nsaction.TransactionTable:436 ) - Topology changed, recalculating minTopologyId 2014-07-04 11:57:59,586 [main] DEBUG (infinispan.CacheImpl :683 ) - Started cache rep on daenerys-45263 2014-07-04 12:00:10,860 [main] DEBUG (jboss.logging :15 ) - Logging Provider: org.jboss.logging.Log4jLoggerProvider 2014-07-04 12:00:10,877 [main] DEBUG (util.FileLookup :61 ) - Unable to find file generic-test-cfg.xml in classpath; searching for this file on the filesystem instead. 2014-07-04 12:00:11,077 [main] WARN (parsing.ParsedCacheMode :37 ) - ISPN000177: REPLICATION-CACH has been deprecated as a synonym for REPL. Use one of [R, REPL, REPLICATION] instead 2014-07-04 12:00:11,113 [main] DEBUG (util.ModuleProperties :50 ) - Loading lifecycle SPI class: org.infinispan.server.core.LifecycleCallbacks@463b3d1c 2014-07-04 12:00:11,256 [main] DEBUG (util.ModuleProperties :96 ) - No module command extensions to load 2014-07-04 12:00:11,354 [main] DEBUG (nager.DefaultCacheManager:578 ) - Started cache manager testCluster on null 2014-07-04 12:00:11,507 [main] INFO (jgroups.JGroupsTransport :184 ) - ISPN000078: Starting JGroups Channel 2014-07-04 12:00:11,731 [main] WARN (stack.Configurator :1132) - JGRP000014: TP.loopback has been deprecated: enabled by default 2014-07-04 12:00:11,894 [main] DEBUG (stack.Configurator :820 ) - set property UDP.bind_addr to default value /192.168.1.65 2014-07-04 12:00:11,895 [main] DEBUG (stack.Configurator :820 ) - set property UDP.diagnostics_addr to default value /224.0.75.75 2014-07-04 12:00:12,181 [main] DEBUG (protocols.UDP :320 ) - sockets will use interface 192.168.1.65 2014-07-04 12:00:12,186 [main] WARN (protocols.UDP :525 ) - JGRP000015: the send buffer of socket DatagramSocket was set to 640KB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max send buffer in the OS correctly (e.g. net.core.wmem_max on Linux) 2014-07-04 12:00:12,187 [main] WARN (protocols.UDP :537 ) - JGRP000015: the receive buffer of socket DatagramSocket was set to 20MB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max receive buffer in the OS correctly (e.g. net.core.rmem_max on Linux) 2014-07-04 12:00:12,188 [main] WARN (protocols.UDP :525 ) - JGRP000015: the send buffer of socket MulticastSocket was set to 640KB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max send buffer in the OS correctly (e.g. net.core.wmem_max on Linux) 2014-07-04 12:00:12,189 [main] WARN (protocols.UDP :537 ) - JGRP000015: the receive buffer of socket MulticastSocket was set to 25MB, but the OS only allocated 212.99KB. This might lead to performance problems. Please set your max receive buffer in the OS correctly (e.g. net.core.rmem_max on Linux) 2014-07-04 12:00:12,191 [main] DEBUG (protocols.UDP :387 ) - socket information: mcast_addr=228.6.7.8:46655, bind_addr=/192.168.1.65, ttl=2
sock: bound to 192.168.1.65:34523, receive buffer size=212992, send buffer size=212992
mcast_sock: bound to 192.168.1.65:46655, send buffer size=212992, receive buffer size=212992
2014-07-04 12:00:12,193 [main] WARN (protocols.UDP :1233) - JGRP000046: bundler_type=old has been removed; using sender-sends-with-timer 2014-07-04 12:00:12,199 [main] DEBUG (pbcast.GMS :1071) - address=daenerys-33863, cluster=testCluster, physical address=192.168.1.65:34523 2014-07-04 12:00:12,301 [main] DEBUG (pbcast.GMS :123 ) - daenerys-33863: sending JOIN(daenerys-33863) to Athene-22069 2014-07-04 12:00:12,926 [main] DEBUG (pbcast.NAKACK2 :1302) - [daenerys-33863 setDigest()]
existing digest: []
new digest: Athene-22069: [0 (0)], daenerys-33863: [0 (0)] resulting digest: Athene-22069: [0 (0)], daenerys-33863: [0 (0)]
2014-07-04 12:00:12,927 [main] DEBUG (pbcast.GMS :690 ) - daenerys-33863: installing view [Athene-22069|1] (2) [Athene-22069, daenerys-33863] 2014-07-04 12:00:12,929 [main] DEBUG (protocols.FD_SOCK :338 ) - daenerys-33863: VIEW_CHANGE received: [Athene-22069, daenerys-33863] 2014-07-04 12:00:12,935 [main] DEBUG (jgroups.JGroupsTransport :630 ) - New view accepted: [Athene-22069|1] (2) [Athene-22069, daenerys-33863] 2014-07-04 12:00:12,937 [main] INFO (jgroups.JGroupsTransport :657 ) - ISPN000094: Received new cluster view: [Athene-22069|1] (2) [Athene-22069, daenerys-33863] 2014-07-04 12:00:12,944 [main] INFO (jgroups.JGroupsTransport :222 ) - ISPN000079: Cache local address is daenerys-33863, physical addresses are [192.168.1.65:34523] 2014-07-04 12:00:12,945 [main] DEBUG (jgroups.JGroupsTransport :423 ) - Waiting on view being accepted 2014-07-04 12:00:12,952 [main] INFO (s.GlobalComponentRegistry:222 ) - ISPN000128: Infinispan version: Infinispan 'Infinium' 6.0.2.Final 2014-07-04 12:00:12,980 [FD_SOCK pinger,daenerys-33863] DEBUG (protocols.FD_SOCK :395 ) - daenerys-33863: ping_dest is Athene-22069, pingable_mbrs=[Athene-22069, daenerys-33863] 2014-07-04 12:00:13,153 [main] DEBUG (rceptors.InterceptorChain:55 ) - Interceptor chain size: 9 2014-07-04 12:00:13,154 [main] DEBUG (rceptors.InterceptorChain:56 ) - Interceptor chain is: >> org.infinispan.interceptors.InvocationContextInterceptor
>> org.infinispan.interceptors.CacheMgmtInterceptor
>> org.infinispan.statetransfer.StateTransferInterceptor
>> org.infinispan.statetransfer.TransactionSynchronizerInterceptor
>> org.infinispan.interceptors.NotificationInterceptor
>> org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor
>> org.infinispan.interceptors.EntryWrappingInterceptor
>> org.infinispan.interceptors.distribution.NonTxDistributionInterceptor
>> org.infinispan.interceptors.CallInterceptor
2014-07-04 12:00:13,164 [main] DEBUG (jmx.JmxUtil :76 ) - Object name org.infinispan:type=Cache,name="rep(repl_sync)",manager="DefaultCacheManager",component=Cache already registered 2014-07-04 12:00:13,164 [main] INFO (jmx.CacheJmxRegistration :63 ) - ISPN000031: MBeans were successfully registered to the platform MBean server. 2014-07-04 12:00:13,167 [main] DEBUG (.LocalTopologyManagerImpl:86 ) - Node daenerys-33863 joining cache rep 2014-07-04 12:00:13,291 [main] DEBUG (.LocalTopologyManagerImpl:183 ) - Updating local consistent hash(es) for cache rep: new topology = CacheTopology{id=0, currentCH=ReplicatedConsistentHash{members=[Athene-22069], numSegments=60, primaryOwners=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=null} 2014-07-04 12:00:13,297 [main] DEBUG (nsaction.TransactionTable:436 ) - Topology changed, recalculating minTopologyId 2014-07-04 12:00:13,298 [remote-thread-0] DEBUG (.LocalTopologyManagerImpl:231 ) - Starting local rebalance for cache rep, top ology = CacheTopology{id=1, currentCH=ReplicatedConsistentHash{members=[Athene-22069], numSegments=60, primaryOwners=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=ReplicatedConsistentHash{members=[Athene-22069, daenerys-33863], numSegments=60, primaryOwners=[1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}}
2014-07-04 12:00:13,302 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:920 ) - Removing state for segments [] of cache rep 2014-07-04 12:00:13,303 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:935 ) - Removing state for segments not in [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] or [] for cache rep 2014-07-04 12:00:13,303 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:637 ) - Adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] of cache rep 2014-07-04 12:00:13,307 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:653 ) - Finished adding inbound state transfer for segments [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] of cache rep 2014-07-04 12:00:13,307 [remote-thread-0] DEBUG (nsaction.TransactionTable:436 ) - Topology changed, recalculating minTopologyId 2014-07-04 12:00:13,343 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 0 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,344 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 0 of cache rep 2014-07-04 12:00:13,344 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 1 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,345 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 1 of cache rep 2014-07-04 12:00:13,345 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 2 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,345 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 2 of cache rep 2014-07-04 12:00:13,346 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 3 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,346 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 3 of cache rep 2014-07-04 12:00:13,347 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 4 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,347 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 4 of cache rep 2014-07-04 12:00:13,348 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 5 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,348 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 5 of cache rep 2014-07-04 12:00:13,349 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 6 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,349 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 6 of cache rep 2014-07-04 12:00:13,349 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 7 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,350 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 7 of cache rep 2014-07-04 12:00:13,351 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 8 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,351 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 8 of cache rep 2014-07-04 12:00:13,352 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 9 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,352 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 9 of cache rep 2014-07-04 12:00:13,352 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 10 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,353 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 10 of cache rep 2014-07-04 12:00:13,353 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 11 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,353 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 11 of cache rep 2014-07-04 12:00:13,354 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 12 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,354 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 12 of cache rep 2014-07-04 12:00:13,355 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 13 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,355 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 13 of cache rep 2014-07-04 12:00:13,355 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 14 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,355 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 14 of cache rep 2014-07-04 12:00:13,356 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 15 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,356 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 15 of cache rep 2014-07-04 12:00:13,357 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 17 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,357 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 17 of cache rep 2014-07-04 12:00:13,357 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 16 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,358 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 16 of cache rep 2014-07-04 12:00:13,358 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 19 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,359 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 19 of cache rep 2014-07-04 12:00:13,359 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 18 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,359 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 18 of cache rep 2014-07-04 12:00:13,360 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 21 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,360 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 21 of cache rep 2014-07-04 12:00:13,360 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 20 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,361 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 20 of cache rep 2014-07-04 12:00:13,361 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 23 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,362 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 23 of cache rep 2014-07-04 12:00:13,362 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 22 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,363 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 22 of cache rep 2014-07-04 12:00:13,363 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 25 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,364 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 25 of cache rep 2014-07-04 12:00:13,365 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 24 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,365 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 24 of cache rep 2014-07-04 12:00:13,365 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 27 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,366 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 27 of cache rep 2014-07-04 12:00:13,366 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 26 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,366 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 26 of cache rep 2014-07-04 12:00:13,367 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 29 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,367 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 29 of cache rep 2014-07-04 12:00:13,368 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 28 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,368 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 28 of cache rep 2014-07-04 12:00:13,368 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 31 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,369 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 31 of cache rep 2014-07-04 12:00:13,369 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 30 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,370 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 30 of cache rep 2014-07-04 12:00:13,370 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 34 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,370 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 34 of cache rep 2014-07-04 12:00:13,371 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 35 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,371 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 35 of cache rep 2014-07-04 12:00:13,372 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 32 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,372 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 32 of cache rep 2014-07-04 12:00:13,373 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 33 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,373 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 33 of cache rep 2014-07-04 12:00:13,374 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 38 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,374 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 38 of cache rep 2014-07-04 12:00:13,374 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 39 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,375 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 39 of cache rep 2014-07-04 12:00:13,375 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 36 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,375 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 36 of cache rep 2014-07-04 12:00:13,376 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 37 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,376 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 37 of cache rep 2014-07-04 12:00:13,376 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 42 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,377 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 42 of cache rep 2014-07-04 12:00:13,377 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 43 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,377 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 43 of cache rep 2014-07-04 12:00:13,378 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 40 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,378 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 40 of cache rep 2014-07-04 12:00:13,379 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 41 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,380 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 41 of cache rep 2014-07-04 12:00:13,380 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 46 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,381 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 46 of cache rep 2014-07-04 12:00:13,381 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 47 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,382 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 47 of cache rep 2014-07-04 12:00:13,382 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 44 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,383 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 44 of cache rep 2014-07-04 12:00:13,383 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 45 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,384 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 45 of cache rep 2014-07-04 12:00:13,385 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 51 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,385 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 51 of cache rep 2014-07-04 12:00:13,386 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 50 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,386 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 50 of cache rep 2014-07-04 12:00:13,387 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 49 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,387 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 49 of cache rep 2014-07-04 12:00:13,388 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 48 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,388 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 48 of cache rep 2014-07-04 12:00:13,389 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 55 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,389 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 55 of cache rep 2014-07-04 12:00:13,390 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 54 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,390 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 54 of cache rep 2014-07-04 12:00:13,391 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 53 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,391 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 53 of cache rep 2014-07-04 12:00:13,392 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 52 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,392 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 52 of cache rep 2014-07-04 12:00:13,392 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 59 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,393 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 59 of cache rep 2014-07-04 12:00:13,393 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 58 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,393 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 58 of cache rep 2014-07-04 12:00:13,394 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 57 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,394 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 57 of cache rep 2014-07-04 12:00:13,394 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:513 ) - Applying new state for segment 56 of cache rep from node Athene-22069: received 0 cache entries 2014-07-04 12:00:13,394 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:565 ) - Finished applying state for segment 56 of cache rep 2014-07-04 12:00:13,395 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:452 ) - Finished receiving of segments for cache rep for topology 1. 2014-07-04 12:00:13,401 [remote-thread-0] DEBUG (.LocalTopologyManagerImpl:183 ) - Updating local consistent hash(es) for cache rep: new topology = CacheTopology{id=2, currentCH=ReplicatedConsistentHash{members=[Athene-22069, daenerys-33863], numSegments=60, primaryOwners=[1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=null} 2014-07-04 12:00:13,401 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:920 ) - Removing state for segments [] of cache rep 2014-07-04 12:00:13,402 [remote-thread-0] DEBUG (ransfer.StateConsumerImpl:935 ) - Removing state for segments not in [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] or [] for cache rep 2014-07-04 12:00:13,402 [remote-thread-0] DEBUG (nsaction.TransactionTable:436 ) - Topology changed, recalculating minTopologyId 2014-07-04 12:00:13,404 [main] DEBUG (infinispan.CacheImpl :683 ) - Started cache rep on daenerys-33863 2014-07-04 12:00:28,937 [Timer-3,daenerys-33863] DEBUG (protocols.FD_ALL :434 ) - haven't received a heartbeat from Athene-22069 for 16012 ms, adding it to suspect list 2014-07-04 12:00:28,937 [Timer-3,daenerys-33863] DEBUG (protocols.FD_ALL :363 ) - suspecting [Athene-22069] 2014-07-04 12:00:44,943 [Timer-2,daenerys-33863] DEBUG (protocols.FD_ALL :434 ) - haven't received a heartbeat from Athene-22069 for 15012 ms, adding it to suspect list 2014-07-04 12:00:44,944 [Timer-2,daenerys-33863] DEBUG (protocols.FD_ALL :363 ) - suspecting [Athene-22069] 2014-07-04 12:00:46,445 [VERIFY_SUSPECT.TimerThread,daenerys-33863] DEBUG (blocks.RequestCorrelator :294 ) - suspect=Athene-22069 2014-07-04 12:00:46,499 [ViewHandler,daenerys-33863] DEBUG (pbcast.GMS :121 ) - daenerys-33863: members are [Athene-22069, daenerys-33863], coord=daenerys-33863: I'm the new coord ! 2014-07-04 12:00:46,501 [ViewHandler,daenerys-33863] DEBUG (pbcast.STABLE :202 ) - resuming message garbage collection 2014-07-04 12:00:46,554 [Incoming-2,daenerys-33863] DEBUG (pbcast.GMS :690 ) - daenerys-33863: installing view [daenerys-33863|2] (1) [daenerys-33863] 2014-07-04 12:00:46,555 [Incoming-2,daenerys-33863] DEBUG (pbcast.NAKACK2 :1161) - daenerys-33863: removed Athene-22069 from xmit_table (not member anymore) 2014-07-04 12:00:46,555 [Incoming-2,daenerys-33863] DEBUG (protocols.FD_SOCK :338 ) - daenerys-33863: VIEW_CHANGE received: [daenerys-33863] 2014-07-04 12:00:46,945 [Timer-3,daenerys-33863] DEBUG (protocols.FD_ALL :434 ) - haven't received a heartbeat from Athene-22069 for 17014 ms, adding it to suspect list 2014-07-04 12:00:46,945 [Timer-3,daenerys-33863] DEBUG (protocols.FD_ALL :363 ) - suspecting [Athene-22069] 2014-07-04 12:00:47,857 [FD_SOCK pinger,daenerys-33863] DEBUG (protocols.FD_SOCK :489 ) - daenerys-33863: socket to null was closed gracefully 2014-07-04 12:00:47,860 [Incoming-2,daenerys-33863] DEBUG (jgroups.JGroupsTransport :630 ) - New view accepted: [daenerys-33863|2] (1) [daenerys-33863] 2014-07-04 12:00:47,861 [Incoming-2,daenerys-33863] INFO (jgroups.JGroupsTransport :657 ) - ISPN000094: Received new cluster view: [daenerys-33863|2] (1) [daenerys-33863] 2014-07-04 12:00:47,865 [transport-thread-1] DEBUG (lusterTopologyManagerImpl:406 ) - Recovering running caches in the cluster 2014-07-04 12:00:47,871 [transport-thread-1] DEBUG (lusterTopologyManagerImpl:323 ) - Updating cluster-wide consistent hash for cache rep, topology = CacheTopology{id=4, currentCH=ReplicatedConsistentHash{members=[daenerys-33863], numSegments=60, primaryOwners=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=null} 2014-07-04 12:00:47,873 [transport-thread-3] DEBUG (.LocalTopologyManagerImpl:183 ) - Updating local consistent hash(es) for cache rep: new topology = CacheTopology{id=4, currentCH=ReplicatedConsistentHash{members=[daenerys-33863], numSegments=60, primaryOwners=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]}, pendingCH=null} 2014-07-04 12:00:47,875 [transport-thread-3] DEBUG (ransfer.StateConsumerImpl:920 ) - Removing state for segments [] of cache rep 2014-07-04 12:00:47,876 [transport-thread-3] DEBUG (ransfer.StateConsumerImpl:935 ) - Removing state for segments not in [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 17, 16, 19, 18, 21, 20, 23, 22, 25, 24, 27, 26, 29, 28, 31, 30, 34, 35, 32, 33, 38, 39, 36, 37, 42, 43, 40, 41, 46, 47, 44, 45, 51, 50, 49, 48, 55, 54, 53, 52, 59, 58, 57, 56] or [] for cache rep 2014-07-04 12:00:47,876 [transport-thread-3] DEBUG (nsaction.TransactionTable:436 ) - Topology changed, recalculating minTopologyId 2014-07-04 12:00:48,446 [VERIFY_SUSPECT.TimerThread,daenerys-33863] DEBUG (blocks.RequestCorrelator :294 ) - suspect=Athene-22069 2014-07-04 12:01:02,521 [Timer-2,daenerys-33863] DEBUG (protocols.MERGE2 :328 ) - daenerys-33863 found different views : [Athene-22069|2], [daenerys-33863|2]; sending up MERGE event with merge participants [Athene-22069, daenerys-33863]. Discovery results:
[Athene-22069]: coord=Athene-22069
[daenerys-33863]: coord=daenerys-33863
2014-07-04 12:01:21,244 [Timer-2,daenerys-33863] DEBUG (protocols.MERGE2 :328 ) - daenerys-33863 found different views : [Athene-22069|2], [daenerys-33863|2]; sending up MERGE event with merge participants [Athene-22069, daenerys-33863]. Discovery results:
[Athene-22069]: coord=Athene-22069
[daenerys-33863]: coord=daenerys-33863
2014-07-04 12:01:46,768 [Timer-3,daenerys-33863] DEBUG (protocols.UNICAST3 :1061) - daenerys-33863: removing expired connection for Athene-22069 (60047 ms old) from send_table 2014-07-04 12:01:46,769 [Timer-3,daenerys-33863] DEBUG (protocols.UNICAST3 :1074) - daenerys-33863: removing expired connection for Athene-22069 (60047 ms old) from recv_table 2014-07-04 12:01:47,589 [Timer-2,daenerys-33863] DEBUG (protocols.MERGE2 :328 ) - daenerys-33863 found different views : [Athene-22069|2], [daenerys-33863|2]; sending up MERGE event with merge participants [Athene-22069, daenerys-33863]. Discovery results:
[Athene-22069]: coord=Athene-22069
[daenerys-33863]: coord=daenerys-33863
2014-07-04 12:02:10,248 [Timer-2,daenerys-33863] DEBUG (protocols.MERGE2 :328 ) - daenerys-33863 found different views : [Athene-22069|2], [daenerys-33863|2]; sending up MERGE event with merge participants [Athene-22069, daenerys-33863]. Discovery results:
[Athene-22069]: coord=Athene-22069
[daenerys-33863]: coord=daenerys-33863