[Logo] Terracotta Discussion Forums (LEGACY READ-ONLY ARCHIVE)
  [Search] Search   [Recent Topics] Recent Topics   [Members]  Member Listing   [Groups] Back to home page 
[Register] Register / 
[Login] Login 
[Expert]
Terracotta clients not reconnecting to server  XML
Forum Index -> Terracotta Platform
Author Message
quasiboo

neo

Joined: 10/01/2013 03:03:57
Messages: 4
Offline

Hi,

We are having problems in all our envs (UAT, Prod) where clients get ejected and are unable to connect back to the server. In each env we have a single terracotta server and about 12 clients.

tc-config.xml
Code:
<?xml version="1.0" encoding="UTF-8"?>
 <tc:tc-config xmlns:tc="http://www.terracotta.org/config"
               xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
               xsi:schemaLocation="http://www.terracotta.org/schema/terracotta-5.xsd">
 
     <!--Added props for avoiding long gc ? -->
 	<!--
  	    Max Time = (ping.idletime) + socketConnectCount * [(ping.interval * ping.probes) + (socketConnectTimeout * ping.interval)] 
 
 		5000 + 20[3 * 1000 + 5 * 1000 ] = 165,000 ms
 
 		Max Time = (ping.idletime) + [socketConnectCount * (ping.interval * ping.probes)] 
 
 		5000 + 1[3 * 1000 + 5 * 1000 ] = 13,000 ms
  	 -->
     <tc-properties>
 
 	<!-- This allows clients to survive short network disruptions, 20 seconds for now -->
 	<property name="l2.l1reconnect.enabled" value="true" /> 
 	<property name="l2.l1reconnect.timeout.millis" value="20000" /> 
 
 
   	<!-- Tolerant timeout settings taken from: http://www.terracotta.org/documentation/high-availability.html -->
          <!-- l1 to l2 is Client timing out (and disconnecting from) the Server  -->
          <property name="l1.healthcheck.l2.ping.enabled" value="true" />
          <property name="l1.healthcheck.l2.ping.idletime" value="5000" />
          <property name="l1.healthcheck.l2.ping.interval" value="1000" />
          <property name="l1.healthcheck.l2.ping.probes" value="3" />
          <property name="l1.healthcheck.l2.socketConnect" value="true" />
          <property name="l1.healthcheck.l2.socketConnectTimeout" value="5" />
          <property name="l1.healthcheck.l2.socketConnectCount" value="20" />
          
          <!-- Tolerant timeout settings taken from: http://www.terracotta.org/documentation/high-availability.html -->
          <!-- l2 to l1 is Server timing out (and ejecting) the Client  -->
          <property name="l2.healthcheck.l1.ping.enabled" value="true" />
          <property name="l2.healthcheck.l1.ping.idletime" value="5000" />
          <property name="l2.healthcheck.l1.ping.interval" value="1000" />
          <property name="l2.healthcheck.l1.ping.probes" value="3" />
          <property name="l2.healthcheck.l1.socketConnect" value="true" />
          <property name="l2.healthcheck.l1.socketConnectTimeout" value="5" />
          <property name="l2.healthcheck.l1.socketConnectCount" value="20" />
  
 	<!-- Trying to set debug options here-->
 	<property name="l2.transactionmanager.logging.verbose" value="true"/>
 	<property name="session.debug.invalidate" value="true"/>
 	<property name="session.debug.sessions" value="true"/>
 
 	 <!-- Max log file size 50MB -->
 	<property name="logging.maxLogFileSize" value="50"/> 
 
 
     </tc-properties>
 
 
     <!-- Production mode forces all clients to use server config -->
     <system>
         <configuration-model>production</configuration-model>
     </system>
 
     <servers>
         <!--
             Tell DSO where the Terracotta server can be found.
             In addition to the active server, every new server entry in here acts
             as another level of a failover.
         -->
         <server host="lonindapnp155" name="primary">
             <!-- Configure all ports -->
 <!--
             <dso-port>9510</dso-port>
             <jmx-port>9520</jmx-port>
             <l2-group-port>9530</l2-group-port>
 -->
 
 <!-- Ports below are based on what's available in DAP for this instance -->
             <dso-port>19599</dso-port>
             <jmx-port>19597</jmx-port>
             <l2-group-port>19598</l2-group-port>
 
             <!-- Configure all local data/log locations -->
             <data>/opt/dap/domains/ja0009/int1/java/tmp</data>
             <logs>/opt/dap/domains/ja0009/int1/logs</logs>
             <statistics>/opt/dap/domains/ja0009/int1/java/tmp</statistics>
 
             <!-- Secure JMX connections -->
             <!--authentication>
                 <password-file>/somepath/jmxremote.password</password-file>
                 <access-file>/somepath/jmxremote.access</access-file>
             </authentication-->
 
             <!-- Secure HTTP connections to this server -->
             <!--http-authentication>
                 <user-realm-file>../config/realm.properties</user-realm-file>
             </http-authentication-->
 
             <dso>
                 <!--
                     The window during which the standby server will wait for
                     clients to reconnect before becoming active.
                 -->
                 <client-reconnect-window>120</client-reconnect-window>
 
                 <persistence>
                     <!--mode>permanent-store</mode-->
                     <mode>temporary-swap-only</mode>
                 </persistence>
 
                 <!--
                     Should only disable clustered garbage collection if you are
                     absolutely certain that none of the data underneath your
                     roots will ever become garbage; certain applications, such
                     as those that read a large amount of data into a Map and
                     never remove it (merely look up values in it) can safely do
                     this.
                 -->
                 <garbage-collection>
                     <enabled>true</enabled>
                     <verbose>false</verbose>
 
                     <!--
                         How often should the DSO server perform distributed
                         garbage collection, in seconds?
 
                        Default: 3600 (60 minutes)
                     -->
                     <interval>3600</interval>
                 </garbage-collection>
             </dso>
         </server>	
 	
         <!--
             Tell DSO where the Terracotta server can be found.
             In addition to the active server, every new server entry in here acts
             as another level of a failover.
         -->
       
 
         <!--
             Configure servers for HA using network clustering. The election time
             is the window in seconds during which a stand-by must be elected as a
             the new active.
         -->
 		<!--
         <ha>
             <mode>networked-active-passive</mode>
             <networked-active-passive>
                 <election-time>5</election-time>
             </networked-active-passive>
         </ha>
 		-->
 
     </servers>
 
     <clients>
         <!-- Tell DSO where to put the generated logs/statistics on the client host -->
         <logs>%(tc.client.log)</logs>
        
         <!--
             Name all required Terracotta Integration Modules (TIM) 
         -->
 
         <modules>
             <module name="tim-ehcache-2.x"/>			
         </modules>
 
         <dso>
             <!--
                 Fault count is the maximum number of reachable objects that are pre-fetched from the Terracotta server
                 to the Terracotta client when an object is faulted from that server to that client.
 
                 Pre-fetching an object does not fault the entire object, only the minimum amount of metadata needed to
                 construct the object on the client if necessary. Unused pre-fetched objects are eventually cleared from
                 the client heap.
 
                 Objects qualify for pre-fetching either by being referenced by the original object (being part of
                 original object's object graph) or because they are peers. An example of peers are primitives found in
                 the same map.
 
                 In most applications, pre-fetching improves locality of reference, which benefits performance. But in
                 some applications, for example a queue fed by producer nodes that shouldn't pre-fetch objects, it may be
                 advantageous to set the fault count to 0.            
             -->
             <fault-count>500</fault-count>
 
             <debugging>
                 <!-- Control instrumentation logging -->
                 <instrumentation-logging>
                     <class>true</class>                             <!-- Log instrumentation classes -->
                     <roots>true</roots>                             <!-- Log instrumentation of roots -->
                     <locks>true</locks>                             <!-- Log class methods that match lock patterns -->
                     <distributed-methods>true</distributed-methods> <!-- Log distributed class methods -->
                 </instrumentation-logging>
 
                 <!-- Control runtime logging -->
                 <runtime-logging>
                     <lock-debug>true</lock-debug>                               <!-- Log whenever a lock is acquired -->
                     <new-object-debug>true</new-object-debug>                   <!-- Log additions to the cluster -->
                     <wait-notify-debug>true</wait-notify-debug>                 <!-- Log wait/notify calls -->
                     <named-loader-debug>true</named-loader-debug>               <!-- Log classloader registration -->
                     <distributed-method-debug>true</distributed-method-debug>   <!-- Log distributed method calls -->
                 </runtime-logging>
 
                 <!-- Add more detail to runtime logging -->
                 <runtime-output-options>
                     <full-stack>false</full-stack>
                     <auto-lock-details>false</auto-lock-details>
                 </runtime-output-options>
             </debugging>
 
             <!--
                 If we want to add Cluster Event listener classes they will need
                 to be injected with cluster awareness at run-time by Terracotta.
 
                 Only instrumented class can be injected.
 
                 http://www.terracotta.org/confluence/display/docs/Cluster+Events
             -->
             <!--injected-instances>
                 <injected-field>
                     <field-name>com.mypackage.myClasses.ClusterAwareClass.theField</field-name>
                 </injected-field>
                 <injected-field>
                     <field-name>com.mypackage.myClasses.OtherClusterAwareClass.theOtherField</field-name>
                 </injected-field>
             </injected-instances-->            
         </dso>
     </clients>
 
     <application>
         <dso>
             <!--
                 Specify the (web) applications that need access to the Cluster
                 state. Web applications are identified by their contexts while
                 standard Java applications are identified by a named
                 classloader.
 
                 Within a given app group all applications must be running in
                 separate JVM/containers.
 
                 All web applications must be running the same container
                 (i.e.: Tomcat) and version.
 
                 All applications must be running the same JVM version.
             -->
             <app-groups>
                 <app-group name="DT">
 					<!-- Cover TC enabled Axis2 Web Services -->
                     <named-classloader>Axis2</named-classloader>
 					<!-- Cover all stand-alone POJO JVM processes-->
                     <named-classloader>Standard.system</named-classloader>
                 </app-group>
             </app-groups>
 
             <!--
                 Declare roots by name and bind them to specific fields in classes. Each root stanza requires either a
                 fully qualified field name (any field in any class) or an AspectWerkz-compatible field expression (but
                 not both).
 
                 A root may be assigned to more than one field by declaring multiple root stanzas in the configuration.
                 Each stanza would have the same root name, but bind that root to different fields.
 
                 A field that is declared a root is endowed with special properties by Terracotta. If the root specified
                 by the given root name has not been created yet, the first assignment to that root field will cause the
                 root to be created. If the root specified by the given root name has already been created (at any other
                 time by any thread in any virtual machine), all assignments to that root field will be ignored.
 
                 This usually implies a small code change around root field setting. Generally, this means that you
                 should check to see if the root has already been created and initialized prior to running any
                 initialization code for that root object.            
             --> 
 
 
 
 
             <!--
                 This section specifies methods to invoke in a distributed
                 fashion via Terracotta DSO. When a method matching one of the
                 patterns here is invoked in one JVM, Terracotta DSO will
                 cause it to be invoked simultaneously in all JVMs throughout
                 the Terracotta cluster. This is often used for 'event listener'
                 methods (for example, those used by Swing), to make sure that
                 all JVMs throughout the cluster are informed when a particular
                 event occurs.
 
                 Specify methods using an AspectWerkz-compatible expression.
                 An optional attribute run-on-all-nodes (default value "true")
                 can be set to false to execute distributed only on those nodes
                 that already have a reference to the object on which the method
                 is called.
 
                 Distributed methods should be used sparingly and incur a heavy
                 performance hit.
             -->
             <!--distributed-methods>
                 <method-expression run-on-all-nodes="false">
                     String[] com.mycompany.pkgc.AnotherClass.eventOccurred(Boolean, Double)
                 </method-expression>
             </distributed-methods-->
 
             <!--
                 Specify any additional pre-instrumented classes to be added to
                 the boot jar if they are loaded by the JVM before Terracotta.
             -->
             <additional-boot-jar-classes>
                 <include>java.util.Random</include>
 
             </additional-boot-jar-classes>
 
             <!--
                 By default, Terracotta is sensitive to access to fields
                 (including arrays) of clustered objects made through
                 reflection so we turn this off for performance gains. 
             -->
             <dso-reflection-enabled>false</dso-reflection-enabled>
         </dso>
     </application>
 
 </tc:tc-config>


Client Log:
Code:
2013-09-24 08:48:29,826 [ClientLockManager LockGC] INFO com.tc.object.locks.ClientLockManager - ClientID[28]: Lock GC collected 1 garbage locks
 2013-09-24 09:00:29,610 [Statistics Logger] INFO com.terracottatech.dso - memory free : 2593.027031 MB
 2013-09-24 09:00:29,610 [Statistics Logger] INFO com.terracottatech.dso - memory used : 1047.910469 MB
 2013-09-24 09:00:29,610 [Statistics Logger] INFO com.terracottatech.dso - memory max : 3640.937500 MB
 2013-09-24 09:14:56,570 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] WARN com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - lonindapnp203:20789 might be in Long GC. Ping-probe cycles completed since last reply : 1
 2013-09-24 09:15:26,148 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[123440])] acquired with level WRITE
 2013-09-24 09:15:26,207 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM123448:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,218 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[121815])] acquired with level WRITE
 2013-09-24 09:15:26,241 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM121823:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,255 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - Unexpected connection event: com.tc.net.core.TCConnectionImpl@352480343: connected: false, closed: true local=10.240.150.2:60872 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:15:26 BST 2013] idle=3010ms [0 read, 0 write]. Current state: State[ ALIVE ]
 2013-09-24 09:15:26,536 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[121001])] acquired with level WRITE
 2013-09-24 09:15:26,633 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM121010:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,736 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[122627])] acquired with level WRITE
 2013-09-24 09:15:26,842 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM122634:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,851 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[188235])] acquired with level WRITE
 2013-09-24 09:15:26,856 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM188247:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,896 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[191114])] acquired with level WRITE
 2013-09-24 09:15:26,905 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM191125:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,920 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[183586])] acquired with level WRITE
 2013-09-24 09:15:26,929 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM183597:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:26,957 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[181001])] acquired with level WRITE
 2013-09-24 09:15:27,005 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM181012:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,034 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[571003])] acquired with level WRITE
 2013-09-24 09:15:27,040 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM571006:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,046 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[193845])] acquired with level WRITE
 2013-09-24 09:15:27,075 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM193850:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,095 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[189195])] acquired with level WRITE
 2013-09-24 09:15:27,118 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM189201:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,150 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[195469])] acquired with level WRITE
 2013-09-24 09:15:27,173 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM195479:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,191 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[186319])] acquired with level WRITE
 2013-09-24 09:15:27,204 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM186327:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,230 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[184401])] acquired with level WRITE
 2013-09-24 09:15:27,302 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM184411:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,308 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[181814])] acquired with level WRITE
 2013-09-24 09:15:27,315 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM181826:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,336 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[191927])] acquired with level WRITE
 2013-09-24 09:15:27,348 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM191934:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,357 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[192073])] acquired with level WRITE
 2013-09-24 09:15:27,380 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM192082:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,397 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[182627])] acquired with level WRITE
 2013-09-24 09:15:27,445 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM182639:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,451 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[187277])] acquired with level WRITE
 2013-09-24 09:15:27,508 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM187283:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,527 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[2633])] acquired with level WRITE
 2013-09-24 09:15:27,552 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM2643:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,556 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[3445])] acquired with level WRITE
 2013-09-24 09:15:27,564 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM3453:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,654 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[1005])] acquired with level WRITE
 2013-09-24 09:15:27,742 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM1018:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:27,829 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [DsoLockID(ObjectID=[1818])] acquired with level WRITE
 2013-09-24 09:15:27,929 [WorkerThread(cluster_events_stage, 0)] INFO com.terracottatech.dso.runtime - Lock [StringLockID(@CDM1825:a0a72766)] acquired with level WRITE
 2013-09-24 09:15:29,610 [Statistics Logger] INFO com.terracottatech.dso - memory free : 2478.045868 MB
 2013-09-24 09:15:29,610 [Statistics Logger] INFO com.terracottatech.dso - memory used : 1162.891632 MB
 2013-09-24 09:15:29,610 [Statistics Logger] INFO com.terracottatech.dso - memory max : 3640.937500 MB
 2013-09-24 09:16:29,833 [ClientLockManager LockGC] INFO com.tc.object.locks.ClientLockManager - ClientID[28]: Lock GC collected 44 garbage locks
 2013-09-24 09:17:29,833 [ClientLockManager LockGC] INFO com.tc.object.locks.ClientLockManager - ClientID[28]: Lock GC collected 2 garbage locks
 2013-09-24 09:21:15,339 [HealthChecker] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - Socket Connect to lonindapnp203:20789(callbackport:20789) taking long time. probably not reachable.
 2013-09-24 09:21:15,339 [HealthChecker] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - lonindapnp203:20789 is DEAD
 2013-09-24 09:21:15,339 [HealthChecker] ERROR com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Client - Declared connection dead ConnectionID(28.f97b492998e14101924dbefc2c592074) idle time 15001ms
 2013-09-24 09:21:15,348 [L1_L2:TCComm Main Selector Thread_W (listen 0:0:0:0:0:0:0:0:46350)] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1409363365: connected: false, closed: true local=10.240.150.2:55958 remote=10.235.178.2:20789 connect=[Tue Sep 24 00:45:29 BST 2013] idle=7010ms [2694321 read, 939388 write]. STATUS : DISCONNECTED
 2013-09-24 09:21:15,349 [L1_L2:TCComm Main Selector Thread_W (listen 0:0:0:0:0:0:0:0:46350)] INFO com.tc.net.protocol.tcm.ClientMessageChannel - ClientMessageChannel moves to SessionID=[1]
 2013-09-24 09:21:15,349 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[28]: Disconnected: Pausing from State[ RUNNING ] RemoteNode : GroupID[0]. Disconnect count: 0
 2013-09-24 09:21:15,372 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[28]: ClientHandshakeManager moves to SessionID=[1]
 2013-09-24 09:21:15,508 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Reconnect attempt 0 of unlimited reconnect tries to lonindapnp203:20789:Tc-Group-0, timeout=10000
 2013-09-24 09:21:18,602 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@476508803: connected: true, closed: false local=10.240.150.2:40173 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:21:18 BST 2013] idle=3091ms [0 read, 0 write]
 2013-09-24 09:21:18,897 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - Health monitoring agent started for lonindapnp203:20789
 2013-09-24 09:21:18,921 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Client - HealthCheckCallbackPort verification PASSED for lonindapnp203:20789(callbackport: 20789)
 2013-09-24 09:21:18,924 [WorkerThread(client_coordination_stage, 0)] INFO com.tc.object.handshakemanager.ClientHandshakeManagerImpl - ClientID[28]: Connected: Unpausing from State[ PAUSED ] RemoteNode : GroupID[0]. Disconnect count : 1
 2013-09-24 09:21:18,952 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@476508803: connected: false, closed: true local=10.240.150.2:40173 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:21:18 BST 2013] idle=23ms [165 read, 250 write]. STATUS : ESTABLISHED
 2013-09-24 09:21:18,952 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Client - Connection to [lonindapnp203:20789] DISCONNECTED. Health Monitoring for this node is now disabled.
 2013-09-24 09:21:18,972 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@342260952: connected: true, closed: false local=10.240.150.2:40175 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:21:18 BST 2013] idle=19ms [0 read, 0 write]
 2013-09-24 09:21:19,004 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] ERROR com.terracottatech.console - com.tc.net.protocol.transport.TransportHandshakeErrorContext: com.tc.net.protocol.transport.TransportHandshakeErrorContext: "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40175 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"Message Class: com.tc.net.protocol.transport.TransportMessageImpl
 Sealed: true, Header Length: 32, Data Length: 619, Total Length: 651
 Header (com.tc.net.protocol.transport.WireProtocolHeader)
 	Version: 2, Header Length: 8, TOS: 0, TTL: 64, Protocol: TRANSPORT HANDSHAKE
 	Total Packet Length: 651
 	Adler32 Checksum: 2484275437 (valid: true)
 	Source Addresss: 10.235.178.2
 	Destination Addresss: 10.240.150.2
 	Source Port: 20789, Destination Port: 40175
 	Total Msg Count: 1
 	Header Validity: true (no message)
 Payload:
 	type: SYN_ACK, connectionId: ConnectionID(28.f97b492998e14101924dbefc2c592074), errorContext com.tc.net.protocol.transport.TransportHandshakeErrorContext: "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40175 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 
 2013-09-24 09:21:19,008 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Reconnection rejected due to stack not found. Default Behaviour.
 2013-09-24 09:21:19,009 [L1_L2:TCComm Main Selector Thread_W (listen 0:0:0:0:0:0:0:0:46350)] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@342260952: connected: false, closed: true local=10.240.150.2:40175 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:21:18 BST 2013] idle=4ms [651 read, 85 write]. STATUS : START
 2013-09-24 09:21:19,010 [L1_L2:TCComm Main Selector Thread_W (listen 0:0:0:0:0:0:0:0:46350)] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@342260952: connected: false, closed: true local=10.240.150.2:40175 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:21:18 BST 2013] idle=5ms [651 read, 85 write]
 2013-09-24 09:21:20,024 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@1005116346: connected: true, closed: false local=10.240.150.2:40176 remote=10.235.178.2:20789 connect=[Tue Sep 24 09:21:20 BST 2013] idle=16ms [0 read, 0 write]
 2013-09-24 09:21:20,162 [L1_L2:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:46350)] ERROR com.terracottatech.console - com.tc.net.protocol.transport.TransportHandshakeErrorContext: com.tc.net.protocol.transport.TransportHandshakeErrorContext: "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40176 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"Message Class: com.tc.net.protocol.transport.TransportMessageImpl
 Sealed: true, Header Length: 32, Data Length: 619, Total Length: 651
 Header (com.tc.net.protocol.transport.WireProtocolHeader)
 	Version: 2, Header Length: 8, TOS: 0, TTL: 64, Protocol: TRANSPORT HANDSHAKE
 	Total Packet Length: 651
 	Adler32 Checksum: 2484603118 (valid: true)
 	Source Addresss: 10.235.178.2
 	Destination Addresss: 10.240.150.2
 	Source Port: 20789, Destination Port: 40176
 	Total Msg Count: 1
 	Header Validity: true (no message)
 Payload:
 	type: SYN_ACK, connectionId: ConnectionID(28.f97b492998e14101924dbefc2c592074), errorContext com.tc.net.protocol.transport.TransportHandshakeErrorContext: "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40176 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"

Server Log:
Code:
2013-09-24 09:21:14,923 [L2_L1:TCWorkerComm # 4_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@123325850: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:55958 connect=[Tue Sep 24 00:45:29 BST 2013] idle=0ms [939388 read, 2694321 write]. STATUS : ESTABLISHED
 2013-09-24 09:21:14,923 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Server - Connection to [lonindapnp204:55958] DISCONNECTED. Health Monitoring for this node is now disabled.
 2013-09-24 09:21:14,925 [L2_L1:TCWorkerComm # 4_W] WARN com.tc.net.core.CoreNIOServices - Exception trying to process interest request: java.nio.channels.ClosedChannelException
 2013-09-24 09:21:14,962 [L2_L1:TCWorkerComm # 6_W] WARN com.tc.net.core.CoreNIOServices - Exception trying to process interest request: java.nio.channels.ClosedChannelException
 2013-09-24 09:21:17,891 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Server - Health monitoring agent started for lonindapnp211:49090
 2013-09-24 09:21:17,892 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.delivery.OnceAndOnlyOnceProtocolNetworkLayerImpl - Requesting OOO reset for different session client ConnectionID(26.f97b492998e14101924dbefc2c592074)
 2013-09-24 09:21:17,895 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Server - Connection to [lonindapnp211:49090] CLOSED. Health Monitoring for this node is now disabled.
 2013-09-24 09:21:17,895 [L2_L1:TCWorkerComm # 4_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(26.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@467704046: connected: false, closed: true local=10.235.178.2:20789 remote=10.235.178.6:49090 connect=[Tue Sep 24 09:21:17 BST 2013] idle=1ms [202 read, 245 write]. STATUS : CLOSED
 2013-09-24 09:21:17,895 [L2_L1:TCWorkerComm # 4_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(26.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@467704046: connected: false, closed: true local=10.235.178.2:20789 remote=10.235.178.6:49090 connect=[Tue Sep 24 09:21:17 BST 2013] idle=1ms [202 read, 245 write]
 2013-09-24 09:21:17,910 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Server - HealthCheckCallbackPort verification PASSED for lonindapnp211:49090(callbackport: 42002)
 2013-09-24 09:21:17,910 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Runtime Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,914 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Runtime Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,914 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Cluster Bean,type=Terracotta Cluster,node=lonindapnp211/52651
 2013-09-24 09:21:17,914 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.core.CoreNIOServices - selection key cancelled key@427310711
 2013-09-24 09:21:17,914 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Cluster Bean,type=Terracotta Cluster,node=lonindapnp211/52651
 2013-09-24 09:21:17,914 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Emitter,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Emitter,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Manager,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Manager,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=L1 Info Bean,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=L1 Info Bean,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Runtime Output Options Bean,subsystem=Logging,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Runtime Output Options Bean,subsystem=Logging,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,915 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-hibernate-ui-1.7.7,name=Hibernate,type=Loader,clients=Clients,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-hibernate-ui-1.7.7,name=Hibernate,type=Loader,clients=Clients,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Instrumentation Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Instrumentation Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta.internal:clients=Clients,name=DSO Client Dump Bean,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta.internal:clients=Clients,name=DSO Client Dump Bean,type=DSO Client,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-ui-1.7.7,name=Ehcache,type=Loader,clients=Clients,node=lonindapnp211/52651
 2013-09-24 09:21:17,916 [Job_Executor56] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-ui-1.7.7,name=Ehcache,type=Loader,clients=Clients,node=lonindapnp211/52651
 2013-09-24 09:21:17,917 [WorkerThread(channel_life_cycle_stage, 0)] INFO com.tc.objectserver.handler.ChannelLifeCycleHandler - : Received transport disconnect.  Shutting down client ClientID[26]
 2013-09-24 09:21:17,957 [WorkerThread(channel_life_cycle_stage, 0)] INFO com.tc.objectserver.persistence.db.TransactionStoreImpl - shutdownClient() : Removing txns from DB : 0
 2013-09-24 09:21:18,861 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@129036637: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40173 connect=[Tue Sep 24 09:21:18 BST 2013] idle=141ms [32 read, 0 write]
 2013-09-24 09:21:18,863 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.core.TCWorkerCommManager - Selecting [L2_L1:TCWorkerComm # 4, FD, wt:0]  from [[L2_L1:TCWorkerComm # 0, FD, wt:1], [L2_L1:TCWorkerComm # 1, FD, wt:2], [L2_L1:TCWorkerComm # 2, FD, wt:1], [L2_L1:TCWorkerComm # 3, FD, wt:1], [L2_L1:TCWorkerComm # 4, FD, wt:0], [L2_L1:TCWorkerComm # 5, FD, wt:2], [L2_L1:TCWorkerComm # 6, FD, wt:1], [L2_L1:TCWorkerComm # 7, FD, wt:2]]
 2013-09-24 09:21:18,863 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.core.CoreNIOServices - selection key cancelled key@1761822742
 2013-09-24 09:21:18,901 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Server - Health monitoring agent started for lonindapnp204:40173
 2013-09-24 09:21:18,901 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.delivery.OnceAndOnlyOnceProtocolNetworkLayerImpl - Requesting OOO reset for different session client ConnectionID(28.f97b492998e14101924dbefc2c592074)
 2013-09-24 09:21:18,903 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Server - Connection to [lonindapnp204:40173] CLOSED. Health Monitoring for this node is now disabled.
 2013-09-24 09:21:18,903 [L2_L1:TCWorkerComm # 4_W] INFO com.tc.net.core.CoreNIOServices - selection key cancelled key@1500161747
 2013-09-24 09:21:18,904 [L2_L1:TCWorkerComm # 4_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@129036637: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40173 connect=[Tue Sep 24 09:21:18 BST 2013] idle=1ms [202 read, 165 write]. STATUS : CLOSED
 2013-09-24 09:21:18,904 [L2_L1:TCWorkerComm # 4_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@129036637: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40173 connect=[Tue Sep 24 09:21:18 BST 2013] idle=1ms [202 read, 165 write]
 2013-09-24 09:21:18,905 [L2_L1:TCWorkerComm # 4_R] INFO com.tc.net.core.CoreNIOServices - selection key cancelled key@1760466049
 2013-09-24 09:21:18,906 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Instrumentation Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,909 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. DSO Server - HealthCheckCallbackPort verification PASSED for lonindapnp204:40173(callbackport: 46350)
 2013-09-24 09:21:18,911 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Instrumentation Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,911 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-hibernate-ui-1.7.7,name=Hibernate,type=Loader,clients=Clients,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-hibernate-ui-1.7.7,name=Hibernate,type=Loader,clients=Clients,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Cluster Bean,type=Terracotta Cluster,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Cluster Bean,type=Terracotta Cluster,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Manager,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Manager,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Runtime Output Options Bean,subsystem=Logging,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Runtime Output Options Bean,subsystem=Logging,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Emitter,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta.internal:clients=Clients,name=Terracotta Statistics Emitter,subsystem=Statistics,type=Terracotta Agent,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta.internal:clients=Clients,name=DSO Client Dump Bean,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta.internal:clients=Clients,name=DSO Client Dump Bean,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,912 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-ui-1.7.7,name=Ehcache,type=Loader,clients=Clients,node=lonindapnp204/55958
 2013-09-24 09:21:18,913 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:feature=org.terracotta.modules.tim-ehcache-2.x-ui-1.7.7,name=Ehcache,type=Loader,clients=Clients,node=lonindapnp204/55958
 2013-09-24 09:21:18,914 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=Terracotta Runtime Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,914 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=Terracotta Runtime Logging Bean,subsystem=Logging,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,914 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - unregisterBean: org.terracotta:clients=Clients,name=L1 Info Bean,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,914 [Job_Executor46] INFO com.tc.management.remote.connect.ClientBeanBag - Ignoring bean for unregistration: org.terracotta:clients=Clients,name=L1 Info Bean,type=DSO Client,node=lonindapnp204/55958
 2013-09-24 09:21:18,914 [WorkerThread(channel_life_cycle_stage, 0)] INFO com.tc.objectserver.handler.ChannelLifeCycleHandler - : Received transport disconnect.  Shutting down client ClientID[28]
 2013-09-24 09:21:18,918 [WorkerThread(channel_life_cycle_stage, 0)] INFO com.tc.objectserver.persistence.db.TransactionStoreImpl - shutdownClient() : Removing txns from DB : 0
 2013-09-24 09:21:19,000 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@1720385278: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40175 connect=[Tue Sep 24 09:21:18 BST 2013] idle=0ms [32 read, 0 write]
 2013-09-24 09:21:19,000 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40175 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:19,001 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40175 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:19,006 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1720385278: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40175 connect=[Tue Sep 24 09:21:18 BST 2013] idle=5ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:19,006 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@1720385278: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40175 connect=[Tue Sep 24 09:21:18 BST 2013] idle=5ms [85 read, 651 write]
 2013-09-24 09:21:20,160 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@312889391: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40176 connect=[Tue Sep 24 09:21:20 BST 2013] idle=1ms [32 read, 0 write]
 2013-09-24 09:21:20,160 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40176 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:20,160 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40176 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:20,164 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@312889391: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40176 connect=[Tue Sep 24 09:21:20 BST 2013] idle=3ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:20,164 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@312889391: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40176 connect=[Tue Sep 24 09:21:20 BST 2013] idle=4ms [85 read, 651 write]
 2013-09-24 09:21:21,289 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@244036324: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40177 connect=[Tue Sep 24 09:21:21 BST 2013] idle=31ms [32 read, 0 write]
 2013-09-24 09:21:21,356 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40177 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:21,357 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40177 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:21,367 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@244036324: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40177 connect=[Tue Sep 24 09:21:21 BST 2013] idle=10ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:21,367 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@244036324: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40177 connect=[Tue Sep 24 09:21:21 BST 2013] idle=10ms [85 read, 651 write]
 2013-09-24 09:21:22,403 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@1025309860: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40178 connect=[Tue Sep 24 09:21:22 BST 2013] idle=4ms [32 read, 0 write]
 2013-09-24 09:21:22,483 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40178 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:22,507 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40178 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:22,545 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1025309860: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40178 connect=[Tue Sep 24 09:21:22 BST 2013] idle=56ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:22,558 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@1025309860: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40178 connect=[Tue Sep 24 09:21:22 BST 2013] idle=75ms [85 read, 651 write]
 2013-09-24 09:21:23,633 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@107156277: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40179 connect=[Tue Sep 24 09:21:23 BST 2013] idle=83ms [32 read, 0 write]
 2013-09-24 09:21:23,704 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40179 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:23,707 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40179 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:23,762 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@107156277: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40179 connect=[Tue Sep 24 09:21:23 BST 2013] idle=48ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:23,765 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@107156277: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40179 connect=[Tue Sep 24 09:21:23 BST 2013] idle=48ms [85 read, 651 write]
 2013-09-24 09:21:24,775 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@1714891377: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40180 connect=[Tue Sep 24 09:21:24 BST 2013] idle=18ms [32 read, 0 write]
 2013-09-24 09:21:24,815 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40180 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:24,828 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40180 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:25,084 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1714891377: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40180 connect=[Tue Sep 24 09:21:24 BST 2013] idle=295ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:25,084 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@1714891377: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40180 connect=[Tue Sep 24 09:21:24 BST 2013] idle=295ms [85 read, 651 write]
 2013-09-24 09:21:25,818 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@150957689: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40182 connect=[Tue Sep 24 09:21:25 BST 2013] idle=0ms [32 read, 0 write]
 2013-09-24 09:21:25,819 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40182 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:25,819 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40182 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:25,822 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@150957689: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40182 connect=[Tue Sep 24 09:21:25 BST 2013] idle=3ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:25,822 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@150957689: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40182 connect=[Tue Sep 24 09:21:25 BST 2013] idle=3ms [85 read, 651 write]
 2013-09-24 09:21:26,840 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): Attaching new connection: com.tc.net.core.TCConnectionImpl@1713014114: connected: true, closed: false local=10.235.178.2:20789 remote=10.240.150.2:40183 connect=[Tue Sep 24 09:21:26 BST 2013] idle=7ms [32 read, 0 write]
 2013-09-24 09:21:26,851 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.terracottatech.console - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40183 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:26,862 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] INFO com.tc.net.protocol.transport.ServerStackProvider - "Client Cannot Reconnect ConnectionID(28.f97b492998e14101924dbefc2c592074) not found. Connection attempts from the Terracotta node at 10.240.150.2:40183 are being rejected by the Terracotta server array. Restart the Client to allow it to rejoin the cluster. Many Client reconnection failures can be avoided by configuring the Terracotta server array for "permanent-store" and tuning reconnection parameters. For more information, see http://www.terracotta.org/kit/reflector?kitID=default&pageID=HA"
 2013-09-24 09:21:26,881 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1713014114: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40183 connect=[Tue Sep 24 09:21:26 BST 2013] idle=24ms [85 read, 651 write]. STATUS : START
 2013-09-24 09:21:27,116 [L2_L1:TCComm Main Selector Thread_R (listen 0:0:0:0:0:0:0:0:20789)] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(28.f97b492998e14101924dbefc2c592074): closing down connection - com.tc.net.core.TCConnectionImpl@1713014114: connected: false, closed: true local=10.235.178.2:20789 remote=10.240.150.2:40183 connect=[Tue Sep 24 09:21:26 BST 2013] idle=141ms [85 read, 651 write]


Other clients got disconnected too, so their msgs appear in the server log but the client referenced here is the one with ID 28. We've noticed a couple of things:

1. If we pull the network cable for a client process, it disconnects and reconnects succesfully as long as the cable is plugged back in within the configured time (20 s)
2. The server log has a line which we do not see when disconnect the network cable - "Requesting OOO reset for different session client ConnectionID(28.f97b492998e14101924dbefc2c592074)"
3. This line seems to cause the next reconnect attempt to close the client connection and reject subsequent attempts.

Can someone please advise what causes this behavior and what needs to be done to resolve it? Many thanks
rmahajan

journeyman

Joined: 12/28/2011 21:53:45
Messages: 47
Offline

This should help :
http://terracotta.org/documentation/4.0/terracotta-server-array/high-availability#71266

Cheers,
Ridhav
quasiboo

neo

Joined: 10/01/2013 03:03:57
Messages: 4
Offline

Hi Ridhav,

Thanks for the link. It talks about rejoin functionality which I believe also requires persistent store right? In my case, we're using temporary-swap mode and I'm not sure what the functional impact to my app would be if we moved to persistent store as we don't have prior experience with this option.

My issue seems to be that the healthchecker socket attempt is timing out and causing the client to be ejected. Could increasing this from it's current value of 5 seconds help mitigate the problem?
rmahajan

journeyman

Joined: 12/28/2011 21:53:45
Messages: 47
Offline

Hi,

The persistence is not necessary for Rejoin functionality.

You only need persistence if you want clients to rejoin even after complete TSA restart - where as your problem is clients getting disconnected after the network disruptions.

To address your concerns about persistence, it will adds a little bit to the put latency but doesn't necessarily impact reads but it mainly depends on the drive you have. You can use SSD or flash drives as your persistent store disks to over come any latency issues.

The best way to solve this problem is by fixing network disruptions if any.
Yes, You can also play with the health checker settings to increase decrease the tolerance, but make sure that doesnt impact the general health checking by large amount.
If the requirement is Rejoining of clients after any disruptions, then I recommend using Rejoin functionality.

Cheers,
Ridhav

quasiboo

neo

Joined: 10/01/2013 03:03:57
Messages: 4
Offline

Hi Ridhav,

Thanks v much for the feedback. Am looking into the rejoin functionality now.

Btw, is there an obv line that gets written in the log that helps identify a network disruption v/s a socket timeout? And is a socket timeout possible because the other side of the connection has 100% CPU usage and thus the OS is unable to accept incoming connections once the socket buffer fills up?

Regards,
Kush
quasiboo

neo

Joined: 10/01/2013 03:03:57
Messages: 4
Offline

I'm dealing with a vendor application here so I don't have a lot of experience working with Terracotta, so please bear with me. What's the difference between a reconnect and rejoin if both allow clients to reconnect to a server after short network disruptions?
rmahajan

journeyman

Joined: 12/28/2011 21:53:45
Messages: 47
Offline

In case of reconnect, the client is still part of the cluster and holding references/locks etc , once it is ejected from the cluster by the health check after certain reconnect tries, it can no longer come back and claim as the existing client.

Now either you have to restart your client to join back the cluster or if the rejoin functionality is enabled, it can automatically rejoin as a fresh client without having to restart your client JVM. You should also look at NonStop cache which is generally used along with rejoin functionality.
vivekt

neo

Joined: 05/12/2016 03:14:20
Messages: 2
Offline

Hi All,

I am also facing the same problem. Trying to use 'rejoin' with quartz property in terracotta version 3.7.5.

<prop key="org.quartz.jobStore.class">org.terracotta.quartz.TerracottaJobStore</prop>
<prop key="org.quartz.jobStore.tcConfigUrl">192.168.220.78:9510</prop>
<prop key="org.quartz.jobStore.tcConfig.rejoin">true</prop>

But rejoin property is not working. Can any one please help me to configure rejoin property.
 
Forum Index -> Terracotta Platform
Go to:   
Powered by JForum 2.1.7 © JForum Team