4 Replies Latest reply on Jul 4, 2014 11:03 AM by james.brealey

    What happens when the cluster splits?

    james.brealey
    james.brealey Jun 27, 2014 2:54 AM

      Hi,

       

      I have been looking at what happens to an Infinispan cluster during a network partition, and have come to the conclusion that even when the network is restored, the cluster remains split and each sub-cluster continues to act independently. Is this the defined/default behavior?

       

      Thanks for any help.

       

      James.

      • 389 Views
      • Tags:
        • 1. Re: What happens when the cluster splits?
          wdfink
          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.

            • Actions
          • 2. Re: What happens when the cluster splits?
            james.brealey
            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.

              • Actions
            • 3. Re: What happens when the cluster splits?
              wdfink
              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

                • Actions
              • 4. Re: What happens when the cluster splits?
                james.brealey
                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

                  • Actions