[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]
Got error when trying in Virtual Machines  XML
Forum Index -> Terracotta 中文社区
Author Message
mosesgi

neo

Joined: 06/17/2013 06:49:40
Messages: 4
Offline

I got everything work good if implementing in two real PCs.
But once I try to implement terracotta in 1 real PC and 1 virtual machine, or 2 virtual machines. I got errors.
I tried in VMWare, in VirtualBox, tried 1 real PC(win7) and 1 VM(fedora). always errors.
Btw, I believe I have shutdown all the firewalls in every system.
"Trusted" zone in Fedora. in Win7 or Xp, closed firewall.

Expecting for your help.

Here is the log, tried in 2 fedora in VirtualBox.

Code:
 2013-06-25 09:30:23,847 [main] INFO com.terracottatech.general - New logging session started.
 2013-06-25 09:30:23,921 [main] INFO com.terracottatech.console - Terracotta 3.7.5, as of 20130319-165505 (Revision 22474 by cruise@su10vmo125 from 3.7.5)
 2013-06-25 09:30:24,037 [main] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - Attempting to load configuration from the file at '/usr/terracotta/bin/tc-config.xml'...
 2013-06-25 09:30:24,966 [main] INFO com.terracottatech.console - Successfully loaded base configuration from file at '/usr/terracotta/bin/tc-config.xml'.
 2013-06-25 09:30:25,002 [main] INFO com.tc.config.schema.setup.StandardXMLFileConfigurationCreator - The configuration specified by 'base configuration from file at '/usr/terracotta/bin/tc-config.xml'':
 
 <tc:tc-config xsi:schemaLocation="http://www.terracotta.org/schema/terracotta-6.xsd" xmlns:tc="http://www.terracotta.org/config" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
   <tc-properties>
     <!--<property name="l1.cachemanager.percentageToEvict" value="10"/> 
 			<property name="l1.cachemanager.sleepInterval" value="3000"/> 
 			<property name="l1.cachemanager.criticalThreshold" value="90"/> 
 			<property name="l1.cachemanager.threshold" value="70"/> 
 			<property name="l1.cachemanager.monitorOldGenOnly" value="true"/>-->
     <property name="l2.nha.dirtydb.autoDelete" value="true"/>
     <property name="l2.nha.tcgroupcomm.reconnect.enabled" value="true"/>
     <property name="l2.nha.tcgroupcomm.reconnect.timeout" value="15000"/>
     <property name="l2.l1reconnect.enabled" value="true"/>
     <property name="l2.l1reconnect.timeout.millis" value="15000"/>
     <property name="l1.cachemanager.enabled" value="true"/>
     <property name="logging.maxLogFileSize" value="1024"/>
   </tc-properties>
   <system>
     <!--default:development can setup "production"-->
     <configuration-model>development</configuration-model>
   </system>
   <servers>
     <server host="192.168.1.230" name="fedora1" bind="192.168.1.230">
       <data>/usr/terracotta/server-data</data>
       <logs>/usr/terracotta/server-logs</logs>
       <index>/usr/terracotta/server-index</index>
       <statistics>/usr/terracotta/server-statistics</statistics>
       <dso-port>9510</dso-port>
       <jmx-port>9520</jmx-port>
       <l2-group-port>9530</l2-group-port>
       <dso>
         <client-reconnect-window>120</client-reconnect-window>
         <persistence>
           <mode>permanent-store</mode>
         </persistence>
         <garbage-collection>
           <enabled>true</enabled>
           <verbose>false</verbose>
           <interval>3600</interval>
         </garbage-collection>
       </dso>
     </server>
     <server host="192.168.1.231" name="fedora2" bind="192.168.1.231">
       <data>/usr/terracotta/server-data</data>
       <logs>/usr/terracotta/server-logs</logs>
       <index>/usr/terracotta/server-index</index>
       <statistics>/usr/terracotta/server-statistics</statistics>
       <dso-port>9510</dso-port>
       <jmx-port>9520</jmx-port>
       <l2-group-port>9530</l2-group-port>
       <dso>
         <client-reconnect-window>120</client-reconnect-window>
         <persistence>
           <mode>permanent-store</mode>
         </persistence>
         <garbage-collection>
           <enabled>true</enabled>
           <verbose>false</verbose>
           <interval>3600</interval>
         </garbage-collection>
       </dso>
     </server>
     <ha>
       <mode>networked-active-passive</mode>
       <networked-active-passive>
         <election-time>5</election-time>
       </networked-active-passive>
     </ha>
   </servers>
   <clients>
     <logs>/usr/terracotta/client-logs/pojo/%i</logs>
   </clients>
   <application>
     <dso>
       <web-applications>
         <web-application>web</web-application>
       </web-applications>
     </dso>
   </application>
 </tc:tc-config>
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - Loading default properties from tc.properties
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l2.dump.on.exception.timeout" was read before initialization completed. "l2.dump.on.exception.timeout" = 30
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "tc.config.total.timeout" was read before initialization completed. "tc.config.total.timeout" = 300000
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "tc.config.getFromSource.timeout" was read before initialization completed. "tc.config.getFromSource.timeout" = 30000
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "logging.maxLogFileSize" was overridden to 1024 from 512 by the tc-config file
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l2.nha.tcgroupcomm.reconnect.timeout" was overridden to 15000 from 5000 by the tc-config file
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l2.nha.dirtydb.autoDelete" was overridden to true from true by the tc-config file
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l2.nha.tcgroupcomm.reconnect.enabled" was overridden to true from true by the tc-config file
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l2.l1reconnect.enabled" was overridden to true from true by the tc-config file
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l2.l1reconnect.timeout.millis" was overridden to 15000 from 5000 by the tc-config file
 2013-06-25 09:30:25,005 [main] INFO com.tc.properties.TCProperties - The property "l1.cachemanager.enabled" was overridden to true from true by the tc-config file
 2013-06-25 09:30:25,020 [main] INFO com.tc.properties.TCProperties - Loaded TCProperties : TCProperties = { appgroups.debug = false, aw.asmclassinfo.ignore.errors = com.jinspired., cvt.buffer.randomsuffix.enabled = false, cvt.client.fail.buffer.open = false, cvt.rest.interface.enabled = false, cvt.retriever.notification.interval = 60, cvt.statistics.logging.interval = 900, cvt.store.randomsuffix.enabled = false, dev.console.max.operator.events = 5000, ehcache.clusterAllCacheManagers = true, ehcache.concurrency = 128, ehcache.evictor.logging.enabled = false, ehcache.evictor.pool.size = 1, ehcache.global.eviction.enable = true, ehcache.global.eviction.frequency = 10, ehcache.global.eviction.rest.timeMillis = 10, ehcache.global.eviction.segments = 2, ehcache.lock.readLevel = READ, ehcache.lock.writeLevel = WRITE, ehcache.logging.enabled = false, ehcache.storageStrategy.dcv2.evictUnexpiredEntries.enabled = true, ehcache.storageStrategy.dcv2.eviction.overshoot = 15, ehcache.storageStrategy.dcv2.localcache.enabled = true, ehcache.storageStrategy.dcv2.perElementTTITTL.enabled = false, ehcache.storageStrategy.dcv2.periodicEviction.enabled = true, ehcache.storageStrategy.dcv2.pinSegments.enabled = true, http.defaultservlet.attribute.aliases = false;, http.defaultservlet.attribute.dirallowed = false;, http.defaultservlet.enabled = false;, instrumentation.finalField.fastRead = true, l1.cachemanager.criticalObjectThreshold = -1, l1.cachemanager.criticalThreshold = 70, l1.cachemanager.enabled = true, l1.cachemanager.leastCount = 2, l1.cachemanager.logging.enabled = false, l1.cachemanager.monitorOldGenOnly = true, l1.cachemanager.percentageToEvict = 10, l1.cachemanager.sleepInterval = 3000, l1.cachemanager.threshold = 50, l1.clusterevents.outofbandnotifier.jointime.millis = 100, l1.connect.versionMatchCheck.enabled = true, l1.healthcheck.l2.bindAddress = 0.0.0.0, l1.healthcheck.l2.bindPort = 0, l1.healthcheck.l2.ping.enabled = true, l1.healthcheck.l2.ping.idletime = 5000, l1.healthcheck.l2.ping.interval = 1000, l1.healthcheck.l2.ping.probes = 3, l1.healthcheck.l2.socketConnect = true, l1.healthcheck.l2.socketConnectCount = 13, l1.healthcheck.l2.socketConnectTimeout = 5, l1.jvm.check.compatibility = true, l1.l2.config.validation.enabled = true, l1.lock.statistics.gatherInterval = 1, l1.lock.statistics.traceDepth = 0, l1.lockmanager.pinning.enabled = true, l1.lockmanager.striped.count = 128, l1.lockmanager.timeout.interval = 60000, l1.max.connect.retries = -1, l1.modules.additional = , l1.modules.default = , l1.modules.repositories = , l1.modules.tc-version-check = , l1.modules.toolkitSearchRange = 100, l1.objectmanager.fault.logging.enabled = false, l1.objectmanager.flush.logging.enabled = false, l1.objectmanager.objectid.request.size = 50000, l1.objectmanager.remote.batchLookupTimePeriod = 1, l1.objectmanager.remote.logging.enabled = false, l1.objectmanager.remote.maxDNALRUSize = 60, l1.objectmanager.remote.maxRequestSentImmediately = 4, l1.seda.pinned.entry.fault.stage.threads = 8, l1.seda.stage.sink.capacity = -1, l1.serverarray.objectCreationStrategy = round-robin, l1.serverarray.objectCreationStrategy.groupAffinity.groupName = mirror-group1, l1.serverarray.objectCreationStrategy.roundRobin.startIndex = sequential, l1.servermapmanager.remote.batchLookupTimePeriod = 1, l1.servermapmanager.remote.maxRequestSentImmediately = 4, l1.shutdown.threadgroup.gracetime = 30000, l1.socket.connect.timeout = 10000, l1.socket.reconnect.waitInterval = 1000, l1.transactionmanager.completedAckFlushTimeout = 5000, l1.transactionmanager.folding.debug = false, l1.transactionmanager.folding.enabled = true, l1.transactionmanager.folding.lock.limit = 0, l1.transactionmanager.folding.object.limit = 0, l1.transactionmanager.logging.enabled = false, l1.transactionmanager.maxBatchSizeInKiloBytes = 128, l1.transactionmanager.maxOutstandingBatchSize = 4, l1.transactionmanager.maxPendingBatches = 88, l1.transactionmanager.maxSleepTimeBeforeHalt = 1024, l1.transactionmanager.strings.compress.enabled = true, l1.transactionmanager.strings.compress.logging.enabled = false, l1.transactionmanager.strings.compress.minSize = 512, l1.transactionmanager.timeoutForAckOnExit = 300, l2.beanshell.enabled = false, l2.beanshell.port = 9929, l2.berkeleydb.je.checkpointer.bytesInterval = 100000000, l2.berkeleydb.je.cleaner.bytesInterval = 20000000, l2.berkeleydb.je.cleaner.detailMaxMemoryPercentage = 5, l2.berkeleydb.je.cleaner.lookAheadCacheSize = 32768, l2.berkeleydb.je.cleaner.minAge = 5, l2.berkeleydb.je.lock.nLockTables = 7, l2.berkeleydb.je.lock.timeout = 180000000, l2.berkeleydb.je.maxMemoryPercent = 25, l2.cachemanager.criticalObjectThreshold = -1, l2.cachemanager.enabled = true, l2.cachemanager.leastCount = 2, l2.cachemanager.logging.enabled = false, l2.cachemanager.monitorOldGenOnly = true, l2.cachemanager.percentageToEvict = 10, l2.cachemanager.sleepInterval = 3000, l2.data.backup.throttle.timeInMillis = 0, l2.db.factory.name = com.tc.objectserver.storage.berkeleydb.BerkeleyDBFactory, l2.derbydb.derby.locks.deadlockTimeout = 170, l2.derbydb.derby.locks.deadlockTrace = true, l2.derbydb.derby.locks.escalationThreshold = 100000, l2.derbydb.derby.locks.waitTimeout = 180, l2.derbydb.derby.maxMemoryPercent = 25, l2.derbydb.derby.storage.checkpointInterval = 134217728, l2.derbydb.derby.storage.logSwitchInterval = 134217728, l2.derbydb.derby.storage.pageSize = 32768, l2.dump.on.exception.timeout = 30, l2.healthcheck.l1.ping.enabled = true, l2.healthcheck.l1.ping.idletime = 5000, l2.healthcheck.l1.ping.interval = 1000, l2.healthcheck.l1.ping.probes = 3, l2.healthcheck.l1.socketConnect = true, l2.healthcheck.l1.socketConnectCount = 10, l2.healthcheck.l1.socketConnectTimeout = 5, l2.healthcheck.l2.ping.enabled = true, l2.healthcheck.l2.ping.idletime = 5000, l2.healthcheck.l2.ping.interval = 1000, l2.healthcheck.l2.ping.probes = 3, l2.healthcheck.l2.socketConnect = true, l2.healthcheck.l2.socketConnectCount = 10, l2.healthcheck.l2.socketConnectTimeout = 5, l2.l1reconnect.enabled = true, l2.l1reconnect.maxDelayedAcks = 16, l2.l1reconnect.sendWindow = 32, l2.l1reconnect.sendqueue.cap = 5000, l2.l1reconnect.timeout.millis = 15000, l2.lfu.agingFactor = 1, l2.lfu.recentlyAccessedIgnorePercentage = 20, l2.lockmanager.greedy.lease.enabled = true, l2.lockmanager.greedy.lease.leaseTimeInMillis = 50, l2.lockmanager.greedy.locks.enabled = true, l2.nha.autoRestart = true, l2.nha.dirtydb.autoDelete = true, l2.nha.dirtydb.backup.enabled = true, l2.nha.dirtydb.rolling = 0, l2.nha.send.timeout.millis = 16000, l2.nha.tcgroupcomm.discovery.interval = 1000, l2.nha.tcgroupcomm.handshake.timeout = 5000, l2.nha.tcgroupcomm.reconnect.enabled = true, l2.nha.tcgroupcomm.reconnect.maxDelayedAcks = 16, l2.nha.tcgroupcomm.reconnect.sendWindow = 32, l2.nha.tcgroupcomm.reconnect.sendqueue.cap = 5000, l2.nha.tcgroupcomm.reconnect.timeout = 15000, l2.objectmanager.cachePolicy = lfu, l2.objectmanager.deleteBatchSize = 5000, l2.objectmanager.dgc.enterpriseMarkStageInterval = 1000, l2.objectmanager.dgc.faulting.optimization = true, l2.objectmanager.dgc.inline.intervalInSeconds = 10, l2.objectmanager.dgc.inline.maxObjects = 10000, l2.objectmanager.dgc.throttle.requestsPerThrottle = 1000, l2.objectmanager.dgc.throttle.timeInMillis = 0, l2.objectmanager.dgc.young.enabled = false, l2.objectmanager.dgc.young.frequencyInMillis = 180000, l2.objectmanager.fault.logging.enabled = false, l2.objectmanager.flush.logging.enabled = false, l2.objectmanager.loadObjectID.checkpoint.maxlimit = -1, l2.objectmanager.loadObjectID.checkpoint.maxsleep = 10000, l2.objectmanager.loadObjectID.longsPerDiskEntry = 8, l2.objectmanager.loadObjectID.mapsdatabase.longsPerDiskEntry = 1, l2.objectmanager.maxObjectsInTxnObjGrouping = 5000, l2.objectmanager.maxObjectsToCommit = 5000, l2.objectmanager.maxTxnsInTxnObjectGrouping = 500, l2.objectmanager.objectrequest.logging.enabled = false, l2.objectmanager.objectrequest.split.size = 500, l2.objectmanager.passive.sync.batch.size = 500, l2.objectmanager.passive.sync.message.maxSizeInMegaBytes = 10, l2.objectmanager.passive.sync.throttle.maxPendingMessages = 10, l2.objectmanager.passive.sync.throttle.timeInMillis = 0, l2.objectmanager.persistor.logging.enabled = false, l2.objectmanager.request.logging.enabled = false, l2.offHeapCache.allocation.critical = 15000, l2.offHeapCache.allocation.critical.halt = true, l2.offHeapCache.allocation.slow = 1500, l2.offHeapCache.map.concurrency = 1, l2.offHeapCache.map.max.page.size = 8m, l2.offHeapCache.map.min.page.size = 4k, l2.offHeapCache.map.tableSize = 128, l2.offHeapCache.operator.event.generator.sleepInterval = 60000, l2.offHeapCache.operator.event.generator.threshold = 80, l2.offHeapCache.temp.swap.flush.to.disk.count = 5000, l2.offHeapCache.temp.swap.throttle.megaBytes = 100, l2.operator.events.store = 1500, l2.remotejmx.idletime = 5, l2.remotejmx.maxthreads = 50, l2.seda.commitstage.threads = 4, l2.seda.evictionprocessorstage.sink.capacity = 1000, l2.seda.gcdeletestage.threads = 1, l2.seda.local.cache.invalidations.sink.capacity = 5000, l2.seda.local.cache.transaction.complete.sink.capacity = -1, l2.seda.local.cache.transaction.complete.threads = 8, l2.seda.query.threads = 4, l2.seda.search.threads = 16, l2.seda.stage.sink.capacity = -1, l2.serverarray.2pc.enabled = true, l2.servermap.eviction.broadcast.maxkeys = 10000, l2.servermap.eviction.clientObjectReferences.refresh.interval = 60000, l2.startuplock.retries.enabled = false, l2.transactionmanager.logging.enabled = false, l2.transactionmanager.logging.printBroadcastStats = false, l2.transactionmanager.logging.printCommits = false, l2.transactionmanager.logging.printStats = true, l2.transactionmanager.logging.verbose = false, l2.transactionmanager.passive.throttle.enabled = true, l2.transactionmanager.passive.throttle.maxSleepSeconds = 5, l2.transactionmanager.passive.throttle.threshold = 20000, lock.statistics.enabled = false, logging.longgc.threshold = 8000, logging.maxBackups = 20, logging.maxLogFileSize = 1024, memory.monitor.forcebasic = false, net.core.keepalive = false, net.core.tcpnodelay = true, offHeapFileSystem.file.maxDataPageSize = 262144, offHeapFilesystem.chm.segments = 4, offHeapFilesystem.file.blockSize = 8192, search.lucene.indexes.per.cache = 4, search.lucene.max.boolean.clauses = 1024, search.lucene.max.buffer = 16.0, search.lucene.use.offHeap.directory = false, search.lucene.use.ram.directory = false, search.passive.max.chunk = 2097152, search.passive.max.pending = 8, session.debug.hops = false, session.debug.hops.interval = 100, session.debug.invalidate = false, session.debug.sessions = false, session.invalidator.bench.enabled = true, session.invalidator.sleep = 300, session.request.bench.enabled = false, session.request.tracking = false, session.request.tracking.dump = false, session.request.tracking.interval = 2500, session.request.tracking.threshold = 15000, session.statistics.enabled = false, session.verify.set.attribute = false, session.vhosts.excluded = , sigar.enabled = false, stats.printer.intervalInMillis = 5000, tc.bytebuffer.common.pool.maxcount = 3000, tc.bytebuffer.pooling.enabled = true, tc.bytebuffer.threadlocal.pool.maxcount = 2000, tc.config.getFromSource.timeout = 30000, tc.config.total.timeout = 300000, tc.management.mbeans.enabled = true, tc.management.test.mbeans.enabled = false, tc.messages.grouping.enabled = true, tc.messages.grouping.maxSizeKiloBytes = 1024, tc.messages.packup.enabled = true, tc.stage.monitor.delay = 5000, tc.stage.monitor.enabled = false, tc.time.sync.threshold = 30, tc.transport.handshake.timeout = 10000, tcm.monitor.delay = 5, tcm.monitor.enabled = false }
 2013-06-25 09:30:25,157 [main] INFO com.terracottatech.console - Log file: '/usr/terracotta/server-logs/terracotta-server.log'.
 2013-06-25 09:30:25,160 [main] INFO com.tc.logging.TCLogging - All Java System Properties for this Terracotta instance:
 ========================================================================
 JVM arguments: [-XX:MaxDirectMemorySize=9223372036854775807, -Xms512m, -Xmx512m, -XX:+HeapDumpOnOutOfMemoryError, -Dcom.sun.management.jmxremote, -Dtc.install-root=./.., -Dsun.rmi.dgc.server.gcInterval=31536000000]
 com.sun.management.jmxremote : 
 file.encoding                : UTF-8
 file.encoding.pkg            : sun.io
 file.separator               : /
 java.awt.graphicsenv         : sun.awt.X11GraphicsEnvironment
 java.awt.printerjob          : sun.print.PSPrinterJob
 java.class.path              : ./../lib/tc.jar
 java.class.version           : 50.0
 java.endorsed.dirs           : /usr/java/jdk1.6.0_21/jre/lib/endorsed
 java.ext.dirs                : /usr/java/jdk1.6.0_21/jre/lib/ext:/usr/java/packages/lib/ext
 java.home                    : /usr/java/jdk1.6.0_21/jre
 java.io.tmpdir               : /tmp
 java.library.path            : /usr/java/jdk1.6.0_21/jre/lib/amd64/server:/usr/java/jdk1.6.0_21/jre/lib/amd64:/usr/java/jdk1.6.0_21/jre/../lib/amd64:/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
 java.rmi.server.randomIDs    : true
 java.runtime.name            : Java(TM) SE Runtime Environment
 java.runtime.version         : 1.6.0_21-b07
 java.specification.name      : Java Platform API Specification
 java.specification.vendor    : Sun Microsystems Inc.
 java.specification.version   : 1.6
 java.vendor                  : Sun Microsystems Inc.
 java.vendor.url              : http://java.sun.com/
 java.vendor.url.bug          : http://java.sun.com/cgi-bin/bugreport.cgi
 java.version                 : 1.6.0_21
 java.vm.info                 : mixed mode
 java.vm.name                 : Java HotSpot(TM) 64-Bit Server VM
 java.vm.specification.name   : Java Virtual Machine Specification
 java.vm.specification.vendor : Sun Microsystems Inc.
 java.vm.specification.version: 1.0
 java.vm.vendor               : Sun Microsystems Inc.
 java.vm.version              : 17.0-b17
 line.separator               : 
 
 os.arch                      : amd64
 os.name                      : Linux
 os.version                   : 3.6.10-4.fc18.x86_64
 path.separator               : :
 sun.arch.data.model          : 64
 sun.boot.class.path          : /usr/java/jdk1.6.0_21/jre/lib/resources.jar:/usr/java/jdk1.6.0_21/jre/lib/rt.jar:/usr/java/jdk1.6.0_21/jre/lib/sunrsasign.jar:/usr/java/jdk1.6.0_21/jre/lib/jsse.jar:/usr/java/jdk1.6.0_21/jre/lib/jce.jar:/usr/java/jdk1.6.0_21/jre/lib/charsets.jar:/usr/java/jdk1.6.0_21/jre/classes
 sun.boot.library.path        : /usr/java/jdk1.6.0_21/jre/lib/amd64
 sun.cpu.endian               : little
 sun.cpu.isalist              : 
 sun.io.unicode.encoding      : UnicodeLittle
 sun.java.launcher            : SUN_STANDARD
 sun.jnu.encoding             : UTF-8
 sun.management.compiler      : HotSpot 64-Bit Server Compiler
 sun.os.patch.level           : unknown
 sun.rmi.dgc.server.gcInterval: 31536000000
 tc.install-root              : ./..
 user.country                 : CN
 user.dir                     : /usr/terracotta/bin
 user.home                    : /root
 user.language                : zh
 user.name                    : root
 user.timezone                : Asia/Shanghai
 ========================================================================
 2013-06-25 09:30:28,106 [main] INFO com.terracottatech.dso - Statistics store: '/usr/terracotta/server-statistics'.
 2013-06-25 09:30:28,135 [main] INFO com.terracottatech.console - Available Max Runtime Memory: 494MB
 2013-06-25 09:30:28,494 [main] INFO com.terracottatech.dso - Standard DSO Server created
 2013-06-25 09:30:28,507 [main] INFO com.terracottatech.dso - Creating server nodeID: NodeID[192.168.1.231:9510]
 2013-06-25 09:30:28,566 [Statistics Logger] INFO com.terracottatech.dso - memory free : 442.970001 MB
 2013-06-25 09:30:28,566 [Statistics Logger] INFO com.terracottatech.dso - memory used : 51.967499 MB
 2013-06-25 09:30:28,566 [Statistics Logger] INFO com.terracottatech.dso - memory max : 494.937500 MB
 2013-06-25 09:30:30,717 [main] INFO com.terracottatech.dso - Statistics buffer: '/usr/terracotta/server-statistics'.
 2013-06-25 09:30:30,764 [main] INFO com.tc.objectserver.managedobject.ConcurrentDistributedMapManagedObjectState - Eviction overshoot threshold is 15.0
 2013-06-25 09:30:30,894 [main] INFO com.terracottatech.console - JMX Server started. Available at URL[service:jmx:jmxmp://192.168.1.231:9520]
 2013-06-25 09:30:30,945 [main] INFO com.tc.objectserver.storage.berkeleydb.BerkeleyDBEnvironment - Sleepy cat version being used 5.0.55
 2013-06-25 09:30:31,031 [main] INFO com.tc.objectserver.storage.berkeleydb.BerkeleyDBEnvironment - Env config = allowCreate=true
 cacheSize=0
 txnNoSync=false
 txnWriteNoSync=false
 {je.cleaner.minAge=5, je.cleaner.bytesInterval=20000000, je.env.isTransactional=true, je.cleaner.lookAheadCacheSize=32768, je.env.isReadOnly=false, je.maxMemoryPercent=25, je.lock.nLockTables=7, je.checkpointer.bytesInterval=100000000, je.cleaner.detailMaxMemoryPercentage=5, je.lock.timeout=180000000}
  DB Config = allowCreate=true
 exclusiveCreate=false
 transactional=true
 readOnly=false
 sortedDuplicates=false
 deferredWrite=false
 temporary=false
 keyPrefixing=false
  JE Properties = {je.cleaner.detailMaxMemoryPercentage=5, je.cleaner.bytesInterval=20000000, je.cleaner.lookAheadCacheSize=32768, je.checkpointer.bytesInterval=100000000, je.maxMemoryPercent=25, je.lock.nLockTables=7, je.cleaner.minAge=5, je.lock.timeout=180000000}
 2013-06-25 09:30:31,713 [main] INFO com.terracottatech.dso - Terracotta persistence version is 2.2
 2013-06-25 09:30:31,714 [main] INFO com.tc.objectserver.persistence.db.DBPersistorImpl - Dirty Objectdb Auto-delete requested.
 2013-06-25 09:30:31,715 [main] INFO com.terracottatech.dso - DB Environment: Closing...
 2013-06-25 09:30:31,716 [main] INFO com.terracottatech.dso - DB Environment: Closing database: global_sequence_db...
 2013-06-25 09:30:31,717 [main] INFO com.terracottatech.dso - DB Environment: Closing database: objects...
 2013-06-25 09:30:31,717 [main] INFO com.terracottatech.dso - DB Environment: Closing database: objects_oid_store...
 2013-06-25 09:30:31,718 [main] INFO com.terracottatech.dso - DB Environment: Closing database: mapsdatabase_oid_store...
 2013-06-25 09:30:31,719 [main] INFO com.terracottatech.dso - DB Environment: Closing database: oid_store_log...
 2013-06-25 09:30:31,719 [main] INFO com.terracottatech.dso - DB Environment: Closing database: evictable_oid_store...
 2013-06-25 09:30:31,720 [main] INFO com.terracottatech.dso - DB Environment: Closing database: roots...
 2013-06-25 09:30:31,721 [main] INFO com.terracottatech.dso - DB Environment: Closing database: clientstates...
 2013-06-25 09:30:31,722 [main] INFO com.terracottatech.dso - DB Environment: Closing database: transactions...
 2013-06-25 09:30:31,723 [main] INFO com.terracottatech.dso - DB Environment: Closing database: stringindex...
 2013-06-25 09:30:31,723 [main] INFO com.terracottatech.dso - DB Environment: Closing database: classdefinitions...
 2013-06-25 09:30:31,723 [main] INFO com.terracottatech.dso - DB Environment: Closing database: mapsdatabase...
 2013-06-25 09:30:31,723 [main] INFO com.terracottatech.dso - DB Environment: Closing database: clusterstatestore...
 2013-06-25 09:30:31,724 [main] INFO com.terracottatech.dso - DB Environment: Closing class catalog...
 2013-06-25 09:30:31,729 [main] INFO com.terracottatech.dso - DB Environment: Closing control database...
 2013-06-25 09:30:31,729 [main] INFO com.terracottatech.dso - DB Environment: Closing environment...
 2013-06-25 09:30:31,741 [main] INFO com.terracottatech.dso - DB Environment: Closed.
 2013-06-25 09:30:31,741 [main] INFO com.tc.objectserver.persistence.db.DBPersistorImpl - dirtyDbBackupPath : /usr/terracotta/server-data/dirty-objectdb-backup
 2013-06-25 09:30:31,742 [main] INFO com.tc.objectserver.persistence.db.DBPersistorImpl - Successfully moved dirty objectdb to /usr/terracotta/server-data/dirty-objectdb-backup/dirty-objectdb-20130625093031741.
 2013-06-25 09:30:32,374 [main] INFO com.tc.net.core.TCWorkerCommManager - Creating 2 worker comm threads for L2_L1
 2013-06-25 09:30:32,430 [main] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: DSO Server - HealthChecker Started
 2013-06-25 09:30:32,430 [main] INFO com.tc.net.protocol.tcm.CommunicationsManager - HealthCheck CallbackPort Listener not requested
 2013-06-25 09:30:32,441 [main] INFO com.tc.objectserver.l1.impl.ClientObjectReferenceSet - ServerMapEviction Client Object References refresh interval 60 seconds.
 2013-06-25 09:30:32,471 [main] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: Copy
 2013-06-25 09:30:32,471 [main] INFO com.tc.runtime.TCMemoryManagerImpl - GarbageCollector: MarkSweepCompact
 2013-06-25 09:30:32,650 [main] INFO com.tc.net.core.TCWorkerCommManager - Creating 2 worker comm threads for L2_L2
 2013-06-25 09:30:32,654 [main] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: TCGroupManager - HealthChecker Started
 2013-06-25 09:30:32,655 [main] INFO com.tc.net.protocol.tcm.CommunicationsManager - HealthCheck CallbackPort Listener not requested
 2013-06-25 09:30:32,678 [main] INFO com.terracottatech.dso - L2 Networked HA Enabled 
 2013-06-25 09:30:33,070 [main] INFO com.tc.statistics.StatisticRetrievalAction - "message monitor" statistic is not enabled. Please enable the property "tcm.monitor.delay" to collect this statistics.
 2013-06-25 09:30:33,071 [main] INFO com.tc.statistics.retrieval.actions.SRAL2FaultsFromDisk - "l2 faults from disk" statistic is not enabled. Please enable the property "l2.objectmanager.fault.logging.enabled" to collect this statistic.
 2013-06-25 09:30:33,093 [main] INFO com.tc.l2.L2DebugLogging - L2 debug logging: DISABLED
 2013-06-25 09:30:33,175 [main] INFO com.terracottatech.dso - This L2 Node ID = NodeID[192.168.1.231:9510]
 2013-06-25 09:30:33,191 [main] INFO com.tc.l2.state.ElectionManagerImpl - Election Started : Enrollment [ NodeID[192.168.1.231:9510], isNew = true, weights = -3358988253262513001,4312333675720265990 ]
 2013-06-25 09:30:33,278 [WorkerThread(group_discovery_stage, 0, 0)] INFO com.tc.net.core.TCConnection - Comms Message Batching enabled
 2013-06-25 09:30:33,294 [WorkerThread(group_discovery_stage, 0, 0)] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(-1.ffffffffffffffffffffffffffffffff.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@357662302: connected: true, closed: false local=192.168.1.231:43199 remote=192.168.1.230:9530 connect=[Tue Jun 25 09:30:33 CST 2013] idle=14ms [0 read, 0 write]
 2013-06-25 09:30:33,301 [WorkerThread(group_discovery_stage, 0, 0)] INFO com.tc.net.core.TCWorkerCommManager - Selecting [L2_L2:TCWorkerComm # 0, FD, wt:0]  from [[L2_L2:TCWorkerComm # 0, FD, wt:0], [L2_L2:TCWorkerComm # 1, FD, wt:0]]
 2013-06-25 09:30:33,960 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(0.3eda855f97604522869c7130491ca5c2.4a63bd84-2d3c-46ed-b2df-82156ae4c518-13f78f3b7f2)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@74017119: connected: true, closed: false local=192.168.1.231:9530 remote=192.168.1.230:60197 connect=[Tue Jun 25 09:30:33 CST 2013] idle=2ms [0 read, 0 write]
 2013-06-25 09:30:33,963 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ServerStackProvider - User null successfully authenticated
 2013-06-25 09:30:33,968 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.core.CoreNIOServices - selection key cancelled key@612687420
 2013-06-25 09:30:38,193 [main] INFO com.tc.l2.state.ElectionManagerImpl - Election Complete : [Enrollment [ NodeID[192.168.1.231:9510], isNew = true, weights = -3358988253262513001,4312333675720265990 ]] : State[ Election-Complete ]
 2013-06-25 09:30:38,194 [main] INFO com.tc.l2.state.StateManagerImpl - Becoming State[ ACTIVE-COORDINATOR ]
 2013-06-25 09:30:38,195 [main] INFO com.terracottatech.console - Becoming State[ ACTIVE-COORDINATOR ]
 2013-06-25 09:30:38,202 [main] INFO tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: Moved to ACTIVE-COORDINATOR
 2013-06-25 09:30:38,202 [main] INFO com.tc.l2.state.ElectionManagerImpl - Declared as Winner: Winner is : Enrollment [ NodeID[192.168.1.231:9510], isNew = true, weights = -3358988253262513001,4312333675720265990 ]
 2013-06-25 09:30:38,215 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.l2.ha.StripeIDStateManagerImpl - putToStore GroupID[0] StripeID[27515c1f5cca46fb9079b947150c6fb3]
 2013-06-25 09:30:38,218 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.l2.ha.StripeIDStateManagerImpl - Notify local StripeID ready
 2013-06-25 09:30:38,219 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.l2.ha.StripeIDStateManagerImpl - Notify StripeIDMap ready
 2013-06-25 09:30:38,224 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.tx.ServerTransactionManager - Waiting for txns to complete
 2013-06-25 09:30:38,232 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.tx.ServerTransactionManager - No more txns in the system.
 2013-06-25 09:30:38,243 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.tx.ResentTransactionSequencer - Making callback com.tc.objectserver.gtx.GlobalTransactionIDLowWaterMarkProvider$2@36598d00 pending since in State[ ADD_RESENT ] resent txns size : 0
 2013-06-25 09:30:38,244 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.handshakemanager.ServerClientHandshakeManager - Starting DSO services...
 2013-06-25 09:30:38,245 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.persistence.db.TransactionStoreImpl - shutdownAllClientsExcept() : Removing txns from DB : 0
 2013-06-25 09:30:38,246 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.impl.GarbageCollectionManagerImpl$PassiveGarbageCollectionManager - In passive mode, not scheduling inline cleanup.
 2013-06-25 09:30:38,246 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.impl.ObjectRequestManagerRestartImpl - Processing Pending Lookups = 0
 2013-06-25 09:30:38,252 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.tx.ResentTransactionSequencer - Unregistering ResentTransactionSequencer since no more resent Transactions : 0
 2013-06-25 09:30:38,253 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.tx.ResentTransactionSequencer - Adding Pending resent CallBacks to  TxnMgr : com.tc.objectserver.gtx.GlobalTransactionIDLowWaterMarkProvider$2@36598d00
 2013-06-25 09:30:38,253 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.gtx.GlobalTransactionIDLowWaterMarkProvider - Switching GlobalTransactionID Low Water mark provider since all resent transactions are applied
 2013-06-25 09:30:38,253 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.impl.ServerMapEvictionManagerImpl - Server Map Eviction : Evictor will run every 1800000 ms
 2013-06-25 09:30:38,254 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.impl.ServerMapEvictionManagerImpl - ehcache.evictor.logging.enabled : false
 2013-06-25 09:30:38,254 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.impl.ServerMapEvictionManagerImpl - ehcache.storageStrategy.dcv2.periodicEviction.enabled : true
 2013-06-25 09:30:38,254 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.impl.ServerMapEvictionManagerImpl - ehcache.storageStrategy.dcv2.perElementTTITTL.enabled : false
 2013-06-25 09:30:38,255 [WorkerThread(l2_state_change_stage, 0)] INFO com.tc.objectserver.l1.impl.InvalidateObjectManagerImpl - Restart txn processing complete : Adding validation of Objects for 0 Clients
 2013-06-25 09:30:38,255 [WorkerThread(l2_state_change_stage, 0)] INFO com.terracottatech.console - Terracotta Server instance has started up as ACTIVE node on 192.168.1.231:9510 successfully, and is now ready for work.
 2013-06-25 09:30:38,264 [main] INFO com.tc.server.TCServer - Server started as fedora2
 2013-06-25 09:30:38,264 [Update Checker] INFO com.tc.server.UpdateCheckAction - Update Checker: Checking...
 2013-06-25 09:30:38,988 [L2_L2:TCWorkerComm # 1_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - Health monitoring agent started for 192.168.1.230:60197
 2013-06-25 09:30:38,993 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - HealthCheckCallbackPort verification PASSED for 192.168.1.230:60197(callbackport: 9530)
 2013-06-25 09:30:39,222 [WorkerThread(group_handshake_message_stage, 0)] INFO tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: Node fedora1 joined the cluster
 2013-06-25 09:30:39,223 [WorkerThread(group_events_dispatch_stage, 0)] INFO com.tc.l2.ha.L2HACoordinator - NodeID[192.168.1.230:9510] joined the cluster
 2013-06-25 09:30:39,223 [WorkerThread(group_events_dispatch_stage, 0)] INFO com.terracottatech.console - NodeID[192.168.1.230:9510] joined the cluster
 2013-06-25 09:30:39,230 [WorkerThread(l2_state_message_handler_stage, 0)] ERROR com.tc.l2.state.StateManagerImpl - State[ ACTIVE-COORDINATOR ] Received Election Won Msg : L2StateMessage [ NodeID[192.168.1.230:9510], type = ELECTION_WON_ALREADY, Enrollment [ NodeID[192.168.1.230:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]]. A Terracotta server tried to join the mirror group as a second ACTIVE
 2013-06-25 09:30:39,233 [WorkerThread(l2_state_message_handler_stage, 0)] WARN com.terracottatech.console - Requesting node to quit : NodeID : NodeID[192.168.1.230:9510] Error Type : Two or more Active servers detected in the cluster
 2013-06-25 09:30:39,234 [WorkerThread(l2_state_message_handler_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:39,235 [WorkerThread(l2_state_message_handler_stage, 0)] WARN com.tc.net.groups.TCGroupManagerImpl - Zapping node : NodeID[192.168.1.230:9510] type = 255 reason = State[ ACTIVE-COORDINATOR ] Received Election Won Msg : L2StateMessage [ NodeID[192.168.1.230:9510], type = ELECTION_WON_ALREADY, Enrollment [ NodeID[192.168.1.230:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]]. A Terracotta server tried to join the mirror group as a second ACTIVE my weight = [0, -9223372036854775808, 0, 211827818964262, 3372417089178011275]
 2013-06-25 09:30:39,238 [WorkerThread(group_events_dispatch_stage, 0)] ERROR com.tc.l2.state.StateManagerImpl - Recd wrong response from : NodeID[192.168.1.230:9510] : msg = L2StateMessage [ NodeID[192.168.1.230:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 2013-06-25 09:30:39,240 [WorkerThread(group_events_dispatch_stage, 0)] ERROR com.tc.l2.ha.L2HACoordinator - A Terracotta server tried to join the mirror group as a second ACTIVE: NodeID[192.168.1.230:9510] Zapping it to allow it to join as PASSIVE standby (backup): 
 com.tc.net.groups.GroupException: Recd wrong response from : NodeID[192.168.1.230:9510] : msg = L2StateMessage [ NodeID[192.168.1.230:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 	at com.tc.l2.state.StateManagerImpl.validateResponse(StateManagerImpl.java:355)
 	at com.tc.l2.state.StateManagerImpl.publishActiveState(StateManagerImpl.java:347)
 	at com.tc.l2.ha.L2HACoordinator.nodeJoined(L2HACoordinator.java:340)
 	at com.tc.l2.handler.GroupEventsDispatchHandler.handleEvent(GroupEventsDispatchHandler.java:29)
 	at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:149)
 2013-06-25 09:30:39,241 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.terracottatech.console - Requesting node to quit : NodeID : NodeID[192.168.1.230:9510] Error Type : COMMUNICATION ERROR
 2013-06-25 09:30:39,244 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - State[ ACTIVE-COORDINATOR ] received Zap Node request from another State[ ACTIVE-COORDINATOR ]
 NodeID : NodeID[192.168.1.230:9510] Error Type : Two or more Active servers detected in the cluster Details : State[ ACTIVE-COORDINATOR ] Received Election Won Msg : L2StateMessage [ NodeID[192.168.1.231:9510], type = ELECTION_WON_ALREADY, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]]. A Terracotta server tried to join the mirror group as a second ACTIVE
 2013-06-25 09:30:39,245 [WorkerThread(receive_group_message_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:39,246 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - A Terracotta server tried to join the mirror group as a second ACTIVE : My weights = 0,-9223372036854775808,0,211827818964262,5327811563257844455 Other servers weights = 0,-9223372036854775808,0,211827818898726,8429431442619700378
 2013-06-25 09:30:39,246 [WorkerThread(receive_group_message_stage, 0)] FATAL tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: SPLIT BRAIN, fedora2 and fedora1 are ACTIVE
 2013-06-25 09:30:39,246 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - Not quiting since the other servers weight = 0,-9223372036854775808,0,211827818898726,8429431442619700378 is not greater than my weight = 0,-9223372036854775808,0,211827818964262,5327811563257844455
 2013-06-25 09:30:39,246 [WorkerThread(receive_group_message_stage, 0)] WARN com.terracottatech.console - Ignoring Quit request from NodeID[192.168.1.230:9510] since remote servers weight is not greater than local weight
 2013-06-25 09:30:39,247 [WorkerThread(group_events_dispatch_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:39,248 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.tc.net.groups.TCGroupManagerImpl - Zapping node : NodeID[192.168.1.230:9510] type = 1 reason = A Terracotta server tried to join the mirror group as a second ACTIVE: NodeID[192.168.1.230:9510] Zapping it to allow it to join as PASSIVE standby (backup): 
 Exception : com.tc.net.groups.GroupException: Recd wrong response from : NodeID[192.168.1.230:9510] : msg = L2StateMessage [ NodeID[192.168.1.230:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 	at com.tc.l2.state.StateManagerImpl.validateResponse(StateManagerImpl.java:355)
 	at com.tc.l2.state.StateManagerImpl.publishActiveState(StateManagerImpl.java:347)
 	at com.tc.l2.ha.L2HACoordinator.nodeJoined(L2HACoordinator.java:340)
 	at com.tc.l2.handler.GroupEventsDispatchHandler.handleEvent(GroupEventsDispatchHandler.java:29)
 	at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:149)
 
  my weight = [0, -9223372036854775808, 0, 211827818964262, -6029728321373463620]
 2013-06-25 09:30:39,274 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - State[ ACTIVE-COORDINATOR ] received Zap Node request from another State[ ACTIVE-COORDINATOR ]
 NodeID : NodeID[192.168.1.230:9510] Error Type : COMMUNICATION ERROR Details : A Terracotta server tried to join the mirror group as a second ACTIVE: NodeID[192.168.1.231:9510] Zapping it to allow it to join as PASSIVE standby (backup): 
 Exception : com.tc.net.groups.GroupException: Recd wrong response from : NodeID[192.168.1.231:9510] : msg = L2StateMessage [ NodeID[192.168.1.231:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.230:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 	at com.tc.l2.state.StateManagerImpl.validateResponse(StateManagerImpl.java:355)
 	at com.tc.l2.state.StateManagerImpl.publishActiveState(StateManagerImpl.java:347)
 	at com.tc.l2.ha.L2HACoordinator.nodeJoined(L2HACoordinator.java:340)
 	at com.tc.l2.handler.GroupEventsDispatchHandler.handleEvent(GroupEventsDispatchHandler.java:29)
 	at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:149)
 
 
 2013-06-25 09:30:39,274 [WorkerThread(receive_group_message_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:39,274 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - A Terracotta server tried to join the mirror group as a second ACTIVE : My weights = 0,-9223372036854775808,0,211827818964262,-1932363354875285566 Other servers weights = 0,-9223372036854775808,0,211827818898726,8330013147507936594
 2013-06-25 09:30:39,275 [WorkerThread(receive_group_message_stage, 0)] FATAL tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: SPLIT BRAIN, fedora2 and fedora1 are ACTIVE
 2013-06-25 09:30:39,275 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - Not quiting since the other servers weight = 0,-9223372036854775808,0,211827818898726,8330013147507936594 is not greater than my weight = 0,-9223372036854775808,0,211827818964262,-1932363354875285566
 2013-06-25 09:30:39,275 [WorkerThread(receive_group_message_stage, 0)] WARN com.terracottatech.console - Ignoring Quit request from NodeID[192.168.1.230:9510] since remote servers weight is not greater than local weight
 2013-06-25 09:30:41,617 [L2_L2:TCWorkerComm # 0_R] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: CLOSE EVENT : com.tc.net.core.TCConnectionImpl@357662302: connected: false, closed: true local=192.168.1.231:43199 remote=192.168.1.230:9530 connect=[Tue Jun 25 09:30:33 CST 2013] idle=8267ms [135 read, 271 write]. STATUS : ESTABLISHED
 2013-06-25 09:30:41,619 [L2_L2:TCWorkerComm # 1_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(0.3eda855f97604522869c7130491ca5c2.4a63bd84-2d3c-46ed-b2df-82156ae4c518-13f78f3b7f2)[]: CLOSE EVENT : com.tc.net.core.TCConnectionImpl@74017119: connected: false, closed: true local=192.168.1.231:9530 remote=192.168.1.230:60197 connect=[Tue Jun 25 09:30:33 CST 2013] idle=2345ms [2730 read, 2614 write]. STATUS : ESTABLISHED
 2013-06-25 09:30:41,619 [L2_L2:TCWorkerComm # 1_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: TCGroupManager - Connection to [192.168.1.230:60197] DISCONNECTED. Health Monitoring for this node is now disabled.
 2013-06-25 09:30:43,387 [WorkerThread(group_discovery_stage, 0, 0)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - Health monitoring agent started for 192.168.1.230:9530
 2013-06-25 09:30:43,390 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.core.CoreNIOServices - IOException attempting to finish socket connection
 java.net.ConnectException: Connection refused
 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
 	at com.tc.net.core.CoreNIOServices$CommThread.doConnect(CoreNIOServices.java:676)
 	at com.tc.net.core.CoreNIOServices$CommThread.selectLoop(CoreNIOServices.java:616)
 	at com.tc.net.core.CoreNIOServices$CommThread.run(CoreNIOServices.java:290)
 2013-06-25 09:30:43,391 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.core.TCConnectionManager - error event on connection com.tc.net.core.TCConnectionImpl@2036672674: connected: false, closed: false connect=[no connect time] idle=3ms [0 read, 0 write]: Connection refused
 2013-06-25 09:30:43,393 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - Config Factor updated from  1 to 3
 2013-06-25 09:30:43,393 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - HealthCheckCallbackPort verification FAILED for 192.168.1.230:9530(callbackport: 9530)
 2013-06-25 09:30:43,398 [WorkerThread(group_discovery_stage, 0, 0)] WARN com.tc.net.groups.TCGroupMemberDiscoveryStatic - DiscoverStateMachine [Node{host=192.168.1.230:9510}]: Ignored switching state from: Connecting, to: Connected, current: Member-In-Group
 2013-06-25 09:30:43,400 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ClientConnectionEstablisher$AsyncReconnect - Handling connection request: RestoreConnectionRequest [type=RESTORE_CONNECTION, clientMessageTransport=com.tc.net.protocol.transport.ClientMessageTransport@41b9da92, callback=com.tc.net.protocol.delivery.OOOConnectionWatcher@10bcc8f4, timeoutMillis=15000, sa=192.168.1.230:9530]
 2013-06-25 09:30:43,403 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:43,663 [HealthChecker] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: TCGroupManager - [192.168.1.230:9530] is not connected. Health Monitoring for this node is now disabled.
 2013-06-25 09:30:44,406 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:45,408 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:46,410 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:47,412 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:48,396 [TC Group Manager Handshake timer] WARN com.tc.net.groups.TCGroupManagerImpl - Group member handshake timeout. NodeID[192.168.1.231:9510] switching to state: Read-Peer-NodeID channel: ChannelID=[0]:192.168.1.231:43199 <--> 192.168.1.230:9530
 2013-06-25 09:30:48,415 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:49,417 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:30:50,227 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(1.3eda855f97604522869c7130491ca5c2.50df72dc-35cb-4e7e-8aff-2effa5c404eb-13f78f442df)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@1394841115: connected: true, closed: false local=192.168.1.231:9530 remote=192.168.1.230:60201 connect=[Tue Jun 25 09:30:50 CST 2013] idle=0ms [0 read, 0 write]
 2013-06-25 09:30:50,228 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ServerStackProvider - User null successfully authenticated
 2013-06-25 09:30:50,230 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.core.CoreNIOServices - selection key cancelled key@1163129153
 2013-06-25 09:30:50,419 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@1364143063: connected: true, closed: false local=192.168.1.231:43209 remote=192.168.1.230:9530 connect=[Tue Jun 25 09:30:50 CST 2013] idle=1ms [0 read, 0 write]
 2013-06-25 09:30:50,420 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection stack is already closed. CLOSED; Conn: com.tc.net.core.TCConnectionImpl@1364143063: connected: true, closed: false local=192.168.1.231:43209 remote=192.168.1.230:9530 connect=[Tue Jun 25 09:30:50 CST 2013] idle=2ms [0 read, 0 write]
 2013-06-25 09:30:50,421 [L2_L2:TCWorkerComm # 0_R] WARN com.tc.net.core.CoreNIOServices - Exception trying to process interest request: java.nio.channels.ClosedChannelException
 2013-06-25 09:30:50,422 [L2_L2:TCWorkerComm # 0_W] WARN com.tc.net.core.CoreNIOServices - Exception trying to process interest request: java.nio.channels.ClosedChannelException
 2013-06-25 09:30:55,248 [L2_L2:TCWorkerComm # 1_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - Health monitoring agent started for 192.168.1.230:60201
 2013-06-25 09:30:55,254 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - HealthCheckCallbackPort verification PASSED for 192.168.1.230:60201(callbackport: 9530)
 2013-06-25 09:30:55,337 [WorkerThread(group_handshake_message_stage, 0)] WARN tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: Node fedora1 left the cluster
 2013-06-25 09:30:55,338 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.tc.l2.ha.L2HACoordinator - NodeID[192.168.1.230:9510] left the cluster
 2013-06-25 09:30:55,338 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.terracottatech.console - NodeID[192.168.1.230:9510] left the cluster
 2013-06-25 09:30:55,340 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.tc.l2.objectserver.L2ObjectStateManagerImpl - L2State Not found for NodeID[192.168.1.230:9510]
 2013-06-25 09:30:55,341 [WorkerThread(group_discovery_stage, 0, 0)] INFO com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(-1.ffffffffffffffffffffffffffffffff.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Attaching new connection: com.tc.net.core.TCConnectionImpl@1395706699: connected: true, closed: false local=192.168.1.231:43211 remote=192.168.1.230:9530 connect=[Tue Jun 25 09:30:55 CST 2013] idle=3ms [0 read, 0 write]
 2013-06-25 09:30:55,343 [WorkerThread(channel_life_cycle_stage, 0)] INFO com.tc.objectserver.handler.ChannelLifeCycleHandler - : Received transport disconnect.  Shutting down client NodeID[192.168.1.230:9510]
 2013-06-25 09:30:55,343 [WorkerThread(channel_life_cycle_stage, 0)] INFO com.tc.objectserver.persistence.db.TransactionStoreImpl - shutdownClient() : Removing txns from DB : 0
 2013-06-25 09:30:55,344 [WorkerThread(group_handshake_message_stage, 0)] WARN com.tc.net.groups.TCGroupManagerImpl - Removed old member Group Member: NodeID[192.168.1.231:9510] <-> NodeID[192.168.1.230:9510] ChannelID[NULL_ID, Status:CLOSED]:192.168.1.231:9530 <--> 192.168.1.230:60197; Ready:false; Joined: false; memberAdding:false; HighPri: true for NodeID[192.168.1.230:9510]
 2013-06-25 09:30:55,476 [WorkerThread(group_handshake_message_stage, 0)] INFO tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: Node fedora1 joined the cluster
 2013-06-25 09:30:55,476 [WorkerThread(group_events_dispatch_stage, 0)] INFO com.tc.l2.ha.L2HACoordinator - NodeID[192.168.1.230:9510] joined the cluster
 2013-06-25 09:30:55,476 [WorkerThread(group_events_dispatch_stage, 0)] INFO com.terracottatech.console - NodeID[192.168.1.230:9510] joined the cluster
 2013-06-25 09:30:55,488 [WorkerThread(l2_state_message_handler_stage, 0)] ERROR com.tc.l2.state.StateManagerImpl - State[ ACTIVE-COORDINATOR ] Received Election Won Msg : L2StateMessage [ NodeID[192.168.1.230:9510], type = ELECTION_WON_ALREADY, Enrollment [ NodeID[192.168.1.230:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]]. A Terracotta server tried to join the mirror group as a second ACTIVE
 2013-06-25 09:30:55,488 [WorkerThread(l2_state_message_handler_stage, 0)] WARN com.terracottatech.console - Requesting node to quit : NodeID : NodeID[192.168.1.230:9510] Error Type : Two or more Active servers detected in the cluster
 2013-06-25 09:30:55,490 [WorkerThread(l2_state_message_handler_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:55,490 [WorkerThread(l2_state_message_handler_stage, 0)] WARN com.tc.net.groups.TCGroupManagerImpl - Zapping node : NodeID[192.168.1.230:9510] type = 255 reason = State[ ACTIVE-COORDINATOR ] Received Election Won Msg : L2StateMessage [ NodeID[192.168.1.230:9510], type = ELECTION_WON_ALREADY, Enrollment [ NodeID[192.168.1.230:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]]. A Terracotta server tried to join the mirror group as a second ACTIVE my weight = [0, -9223372036854775808, 0, 211827818964262, 2463579588973678181]
 2013-06-25 09:30:55,504 [WorkerThread(group_events_dispatch_stage, 0)] ERROR com.tc.l2.state.StateManagerImpl - Recd wrong response from : NodeID[192.168.1.230:9510] : msg = L2StateMessage [ NodeID[192.168.1.230:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 2013-06-25 09:30:55,504 [WorkerThread(group_events_dispatch_stage, 0)] ERROR com.tc.l2.ha.L2HACoordinator - A Terracotta server tried to join the mirror group as a second ACTIVE: NodeID[192.168.1.230:9510] Zapping it to allow it to join as PASSIVE standby (backup): 
 com.tc.net.groups.GroupException: Recd wrong response from : NodeID[192.168.1.230:9510] : msg = L2StateMessage [ NodeID[192.168.1.230:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 	at com.tc.l2.state.StateManagerImpl.validateResponse(StateManagerImpl.java:355)
 	at com.tc.l2.state.StateManagerImpl.publishActiveState(StateManagerImpl.java:347)
 	at com.tc.l2.ha.L2HACoordinator.nodeJoined(L2HACoordinator.java:340)
 	at com.tc.l2.handler.GroupEventsDispatchHandler.handleEvent(GroupEventsDispatchHandler.java:29)
 	at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:149)
 2013-06-25 09:30:55,504 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.terracottatech.console - Requesting node to quit : NodeID : NodeID[192.168.1.230:9510] Error Type : COMMUNICATION ERROR
 2013-06-25 09:30:55,505 [WorkerThread(group_events_dispatch_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:55,505 [WorkerThread(group_events_dispatch_stage, 0)] WARN com.tc.net.groups.TCGroupManagerImpl - Zapping node : NodeID[192.168.1.230:9510] type = 1 reason = A Terracotta server tried to join the mirror group as a second ACTIVE: NodeID[192.168.1.230:9510] Zapping it to allow it to join as PASSIVE standby (backup): 
 Exception : com.tc.net.groups.GroupException: Recd wrong response from : NodeID[192.168.1.230:9510] : msg = L2StateMessage [ NodeID[192.168.1.230:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 	at com.tc.l2.state.StateManagerImpl.validateResponse(StateManagerImpl.java:355)
 	at com.tc.l2.state.StateManagerImpl.publishActiveState(StateManagerImpl.java:347)
 	at com.tc.l2.ha.L2HACoordinator.nodeJoined(L2HACoordinator.java:340)
 	at com.tc.l2.handler.GroupEventsDispatchHandler.handleEvent(GroupEventsDispatchHandler.java:29)
 	at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:149)
 
  my weight = [0, -9223372036854775808, 0, 211827818964262, -2551077814224807218]
 2013-06-25 09:30:55,528 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - State[ ACTIVE-COORDINATOR ] received Zap Node request from another State[ ACTIVE-COORDINATOR ]
 NodeID : NodeID[192.168.1.230:9510] Error Type : Two or more Active servers detected in the cluster Details : State[ ACTIVE-COORDINATOR ] Received Election Won Msg : L2StateMessage [ NodeID[192.168.1.231:9510], type = ELECTION_WON_ALREADY, Enrollment [ NodeID[192.168.1.231:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]]. A Terracotta server tried to join the mirror group as a second ACTIVE
 2013-06-25 09:30:55,530 [WorkerThread(receive_group_message_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:55,530 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - A Terracotta server tried to join the mirror group as a second ACTIVE : My weights = 0,-9223372036854775808,0,211827818964262,-6233568013191730958 Other servers weights = 0,-9223372036854775808,0,211827818898726,8845657465461158403
 2013-06-25 09:30:55,530 [WorkerThread(receive_group_message_stage, 0)] FATAL tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: SPLIT BRAIN, fedora2 and fedora1 are ACTIVE
 2013-06-25 09:30:55,531 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - Not quiting since the other servers weight = 0,-9223372036854775808,0,211827818898726,8845657465461158403 is not greater than my weight = 0,-9223372036854775808,0,211827818964262,-6233568013191730958
 2013-06-25 09:30:55,531 [WorkerThread(receive_group_message_stage, 0)] WARN com.terracottatech.console - Ignoring Quit request from NodeID[192.168.1.230:9510] since remote servers weight is not greater than local weight
 2013-06-25 09:30:55,535 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - State[ ACTIVE-COORDINATOR ] received Zap Node request from another State[ ACTIVE-COORDINATOR ]
 NodeID : NodeID[192.168.1.230:9510] Error Type : COMMUNICATION ERROR Details : A Terracotta server tried to join the mirror group as a second ACTIVE: NodeID[192.168.1.231:9510] Zapping it to allow it to join as PASSIVE standby (backup): 
 Exception : com.tc.net.groups.GroupException: Recd wrong response from : NodeID[192.168.1.231:9510] : msg = L2StateMessage [ NodeID[192.168.1.231:9510], type = RESULT_CONFLICT, Enrollment [ NodeID[192.168.1.230:9510], isNew = false, weights = 9223372036854775807,9223372036854775807 ]] while publishing Active State
 	at com.tc.l2.state.StateManagerImpl.validateResponse(StateManagerImpl.java:355)
 	at com.tc.l2.state.StateManagerImpl.publishActiveState(StateManagerImpl.java:347)
 	at com.tc.l2.ha.L2HACoordinator.nodeJoined(L2HACoordinator.java:340)
 	at com.tc.l2.handler.GroupEventsDispatchHandler.handleEvent(GroupEventsDispatchHandler.java:29)
 	at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:149)
 
 
 2013-06-25 09:30:55,535 [WorkerThread(receive_group_message_stage, 0)] INFO com.tc.net.core.TCConnectionManager - Active connections : 0 out of 0
 2013-06-25 09:30:55,535 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - A Terracotta server tried to join the mirror group as a second ACTIVE : My weights = 0,-9223372036854775808,0,211827818964262,-6919526753161750107 Other servers weights = 0,-9223372036854775808,0,211827818898726,1111334906113981467
 2013-06-25 09:30:55,536 [WorkerThread(receive_group_message_stage, 0)] FATAL tc.operator.event - NODE : fedora2  Subsystem: CLUSTER_TOPOLOGY Message: SPLIT BRAIN, fedora2 and fedora1 are ACTIVE
 2013-06-25 09:30:55,536 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - Not quiting since the other servers weight = 0,-9223372036854775808,0,211827818898726,1111334906113981467 is not greater than my weight = 0,-9223372036854775808,0,211827818964262,-6919526753161750107
 2013-06-25 09:30:55,536 [WorkerThread(receive_group_message_stage, 0)] WARN com.terracottatech.console - Ignoring Quit request from NodeID[192.168.1.230:9510] since remote servers weight is not greater than local weight
 2013-06-25 09:30:57,896 [L2_L2:TCWorkerComm # 1_R] WARN com.tc.net.protocol.transport.ServerMessageTransport - ConnectionID(1.3eda855f97604522869c7130491ca5c2.50df72dc-35cb-4e7e-8aff-2effa5c404eb-13f78f442df)[]: CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1394841115: connected: false, closed: true local=192.168.1.231:9530 remote=192.168.1.230:60201 connect=[Tue Jun 25 09:30:50 CST 2013] idle=2361ms [2730 read, 2594 write]. STATUS : ESTABLISHED
 2013-06-25 09:30:57,897 [L2_L2:TCWorkerComm # 0_R] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fcd0cb6d29d84cfab361781c469ce9a9.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: CLOSE EVENT : com.tc.net.core.TCConnectionImpl@1395706699: connected: false, closed: true local=192.168.1.231:43211 remote=192.168.1.230:9530 connect=[Tue Jun 25 09:30:55 CST 2013] idle=2411ms [135 read, 271 write]. STATUS : ESTABLISHED
 2013-06-25 09:30:57,897 [L2_L2:TCWorkerComm # 1_R] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: TCGroupManager - Connection to [192.168.1.230:60201] DISCONNECTED. Health Monitoring for this node is now disabled.
 2013-06-25 09:30:58,401 [Update Checker] INFO com.tc.server.UpdateCheckAction - Update Checker: Check failed (java.net.UnknownHostException: www.terracotta.org)
 2013-06-25 09:30:58,402 [Update Checker] INFO com.tc.server.UpdateCheckAction - Update Checker: Next check at Tue Jul 02 09:30:58 CST 2013
 2013-06-25 09:31:00,423 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fe15fac2cd684a9eb5da368fecbfb648.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Timeout of 10000 milliseconds occured
 2013-06-25 09:31:00,553 [WorkerThread(group_discovery_stage, 0, 0)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - Health monitoring agent started for 192.168.1.230:9530
 2013-06-25 09:31:00,559 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.core.CoreNIOServices - IOException attempting to finish socket connection
 java.net.ConnectException: Connection refused
 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574)
 	at com.tc.net.core.CoreNIOServices$CommThread.doConnect(CoreNIOServices.java:676)
 	at com.tc.net.core.CoreNIOServices$CommThread.selectLoop(CoreNIOServices.java:616)
 	at com.tc.net.core.CoreNIOServices$CommThread.run(CoreNIOServices.java:290)
 2013-06-25 09:31:00,560 [WorkerThread(group_discovery_stage, 0, 0)] WARN com.tc.net.groups.TCGroupMemberDiscoveryStatic - DiscoverStateMachine [Node{host=192.168.1.230:9510}]: Ignored switching state from: Connecting, to: Connected, current: Member-In-Group
 2013-06-25 09:31:00,563 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.core.TCConnectionManager - error event on connection com.tc.net.core.TCConnectionImpl@936826397: connected: false, closed: false connect=[no connect time] idle=8ms [0 read, 0 write]: Connection refused
 2013-06-25 09:31:00,563 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - Config Factor updated from  1 to 3
 2013-06-25 09:31:00,564 [L2_L2:TCComm Main Selector Thread_R (listen 192.168.1.231:9530)] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl. TCGroupManager - HealthCheckCallbackPort verification FAILED for 192.168.1.230:9530(callbackport: 9530)
 2013-06-25 09:31:00,564 [ConnectionEstablisher] INFO com.tc.net.protocol.transport.ClientConnectionEstablisher$AsyncReconnect - Handling connection request: RestoreConnectionRequest [type=RESTORE_CONNECTION, clientMessageTransport=com.tc.net.protocol.transport.ClientMessageTransport@1d7aa55b, callback=com.tc.net.protocol.delivery.OOOConnectionWatcher@5efe087b, timeoutMillis=15000, sa=192.168.1.230:9530]
 2013-06-25 09:31:00,566 [ConnectionEstablisher] WARN com.tc.net.protocol.transport.ClientMessageTransport - ConnectionID(0.fcd0cb6d29d84cfab361781c469ce9a9.edb189e7-ef09-4875-a23a-f1459c331ec9-13f78f3f7ce)[]: Connection refused
 2013-06-25 09:31:00,670 [HealthChecker] INFO com.tc.net.protocol.transport.ConnectionHealthCheckerImpl: TCGroupManager - [192.168.1.230:9530] is not connected. Health Monitoring for this node is now disabled.
 2013-06-25 09:31:00,888 [CommonShutDownHook] INFO com.terracottatech.dso - L2 Exiting...
 
rajoshi

seraphim

Joined: 07/04/2011 04:36:10
Messages: 1491
Offline

Looks like a network issue, as both active and passive are not able to communicate and paasive tries to become active after waiting for time set by "l2.nha.tcgroupcomm.reconnect.timeout" . This finally leads to Split brain scenario with two active in system as depicted by below log snippet :


2013-06-25 09:30:39,246 [WorkerThread(receive_group_message_stage, 0)] FATAL tc.operator.event - NODE : fedora2 Subsystem: CLUSTER_TOPOLOGY Message: SPLIT BRAIN, fedora2 and fedora1 are ACTIVE
2013-06-25 09:30:39,246 [WorkerThread(receive_group_message_stage, 0)] WARN com.tc.l2.ha.L2HAZapNodeRequestProcessor - Not quiting since the other servers weight = 0,-9223372036854775808,0,211827818898726,8429431442619700378 is not greater than my weight = 0,-9223372036854775808,0,211827818964262,5327811563257844455


So you've got to adjust that value up -- and also look at the HealthChecker values for server-server (see the documentation) -- until split-brains no longer occur. But note that your cluster will pause for that time, and you'll also have a longer time-to-failover should that be needed. It's a balancing act (assuming that fixing the network isn't an option).

Rakesh Joshi
Senior Consultant
Terracotta.
mosesgi

neo

Joined: 06/17/2013 06:49:40
Messages: 4
Offline

I've solved this issue. Thanks anyway.

Yeah it should be caused by network issue.
I downloaded nmap and tried to check the port status. Checking result is good, 9510-9530 are all open.
After that I restart terracotta, and they work good...
Not sure what happened but it works now.
rajoshi

seraphim

Joined: 07/04/2011 04:36:10
Messages: 1491
Offline

okk good to know its resolved.

Rakesh Joshi
Senior Consultant
Terracotta.
 
Forum Index -> Terracotta 中文社区
Go to:   
Powered by JForum 2.1.7 © JForum Team