Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 924AE200CE0 for ; Thu, 27 Jul 2017 02:30:17 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 90897169044; Thu, 27 Jul 2017 00:30:17 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id B9CE5169016 for ; Thu, 27 Jul 2017 02:30:14 +0200 (CEST) Received: (qmail 45995 invoked by uid 500); 27 Jul 2017 00:30:13 -0000 Mailing-List: contact dev-help@zookeeper.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@zookeeper.apache.org Delivered-To: mailing list dev@zookeeper.apache.org Received: (qmail 45979 invoked by uid 99); 27 Jul 2017 00:30:13 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd1-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 27 Jul 2017 00:30:13 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd1-us-west.apache.org (ASF Mail Server at spamd1-us-west.apache.org) with ESMTP id 269E6C238C for ; Thu, 27 Jul 2017 00:30:13 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd1-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -99.202 X-Spam-Level: X-Spam-Status: No, score=-99.202 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, RP_MATCHES_RCVD=-0.001, SPF_PASS=-0.001, USER_IN_WHITELIST=-100] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd1-us-west.apache.org [10.40.0.7]) (amavisd-new, port 10024) with ESMTP id 7tSH8NzPhuEo for ; Thu, 27 Jul 2017 00:30:05 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id B92EF5FDBF for ; Thu, 27 Jul 2017 00:30:04 +0000 (UTC) Received: from jira-lw-us.apache.org (unknown [207.244.88.139]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id A0AADE0635 for ; Thu, 27 Jul 2017 00:30:03 +0000 (UTC) Received: from jira-lw-us.apache.org (localhost [127.0.0.1]) by jira-lw-us.apache.org (ASF Mail Server at jira-lw-us.apache.org) with ESMTP id 1BA6F2481B for ; Thu, 27 Jul 2017 00:30:01 +0000 (UTC) Date: Thu, 27 Jul 2017 00:30:01 +0000 (UTC) From: "Hadoop QA (JIRA)" To: dev@zookeeper.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (ZOOKEEPER-2577) Flaky Test: org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 archived-at: Thu, 27 Jul 2017 00:30:17 -0000 [ https://issues.apache.org/jira/browse/ZOOKEEPER-2577?page=3Dcom.atlas= sian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=3D= 16102525#comment-16102525 ]=20 Hadoop QA commented on ZOOKEEPER-2577: -------------------------------------- +1 overall. GitHub Pull Request Build =20 +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 3 new or modified test= s. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of java= c compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 3.= 0.1) warnings. +1 release audit. The applied patch does not increase the total number= of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-github-pr-b= uild/904//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-github= -pr-build/904//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.= html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-github-pr= -build/904//console This message is automatically generated. > Flaky Test: org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTe= st.testDuringLeaderSync > -------------------------------------------------------------------------= ----------------------- > > Key: ZOOKEEPER-2577 > URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2577 > Project: ZooKeeper > Issue Type: Test > Components: tests > Affects Versions: 3.5.2 > Reporter: Michael Han > Assignee: Michael Han > Labels: flaky, flaky-test > Fix For: 3.6.0 > > > {noformat} > Error Message > zoo.cfg.dynamic.next is not deleted. > Stacktrace > junit.framework.AssertionFailedError: zoo.cfg.dynamic.next is not deleted= . > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tes= tDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155) > =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate= (JUnit4ZKTestRunner.java:79) > Standard Output > 2016-09-13 05:09:25,247 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No= test.method specified. using default methods. > 2016-09-13 05:09:25,349 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No= test.method specified. using default methods. > 2016-09-13 05:09:25,370 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING= testDuringLeaderSync > 2016-09-13 05:09:25,372 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedIn= vokeMethod@77] - RUNNING TEST METHOD testDuringLeaderSync > 2016-09-13 05:09:25,375 [myid:] - INFO [main:PortAssignment@151] - Test = process 2/8 using ports from 13914 - 16606. > 2016-09-13 05:09:25,380 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13915 from range 13914 - 16606. > 2016-09-13 05:09:25,380 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13916 from range 13914 - 16606. > 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13917 from range 13914 - 16606. > 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13918 from range 13914 - 16606. > 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13919 from range 13914 - 16606. > 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13920 from range 13914 - 16606. > 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13921 from range 13914 - 16606. > 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13922 from range 13914 - 16606. > 2016-09-13 05:09:25,383 [myid:] - INFO [main:PortAssignment@85] - Assign= ed port 13923 from range 13914 - 16606. > 2016-09-13 05:09:25,406 [myid:] - INFO [main:QuorumPeerTestBase$MainThre= ad@131] - id =3D 0 tmpDir =3D /home/jenkins/jenkins-slave/workspace/ZooKeep= er-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir clientPo= rt =3D 13915 adminServerPort =3D 8080 > 2016-09-13 05:09:25,416 [myid:] - INFO [main:QuorumPeerTestBase$MainThre= ad@131] - id =3D 1 tmpDir =3D /home/jenkins/jenkins-slave/workspace/ZooKeep= er-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir clientPo= rt =3D 13918 adminServerPort =3D 8080 > 2016-09-13 05:09:25,420 [myid:] - INFO [main:QuorumPeerTestBase$MainThre= ad@131] - id =3D 2 tmpDir =3D /home/jenkins/jenkins-slave/workspace/ZooKeep= er-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir clientPo= rt =3D 13921 adminServerPort =3D 8080 > 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-0:QuorumPeerConfig@116] -= Reading configuration from: /home/jenkins/jenkins-slave/workspace/ZooKeepe= r-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/zoo.cfg > 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-2:QuorumPeerConfig@116] -= Reading configuration from: /home/jenkins/jenkins-slave/workspace/ZooKeepe= r-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/zoo.cfg > 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-1:QuorumPeerConfig@116] -= Reading configuration from: /home/jenkins/jenkins-slave/workspace/ZooKeepe= r-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/zoo.cfg > 2016-09-13 05:09:25,424 [myid:] - INFO [main:FourLetterWordMain@85] - co= nnecting to 127.0.0.1 13915 > 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-0:QuorumPeerConfig@318] -= clientPortAddress is 0.0.0.0/0.0.0.0:13915 > 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-0:QuorumPeerConfig@322] -= secureClientPort is not set > 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-1:QuorumPeerConfig@318] -= clientPortAddress is 0.0.0.0/0.0.0.0:13918 > 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-1:QuorumPeerConfig@322] -= secureClientPort is not set > 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-2:QuorumPeerConfig@318] -= clientPortAddress is 0.0.0.0/0.0.0.0:13921 > 2016-09-13 05:09:25,426 [myid:] - INFO [Thread-2:QuorumPeerConfig@322] -= secureClientPort is not set > 2016-09-13 05:09:25,430 [myid:] - INFO [main:ClientBase@248] - server 12= 7.0.0.1:13915 not up > java.net.ConnectException: Connection refused > =09at java.net.PlainSocketImpl.socketConnect(Native Method) > =09at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.= java:339) > =09at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSock= etImpl.java:200) > =09at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.ja= va:182) > =09at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > =09at java.net.Socket.connect(Socket.java:579) > =09at org.apache.zookeeper.client.FourLetterWordMain.send4LetterWord(Four= LetterWordMain.java:99) > =09at org.apache.zookeeper.client.FourLetterWordMain.send4LetterWord(Four= LetterWordMain.java:69) > =09at org.apache.zookeeper.test.ClientBase.waitForServerUp(ClientBase.jav= a:241) > =09at org.apache.zookeeper.test.ClientBase.waitForServerUp(ClientBase.jav= a:232) > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tes= tDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:85) > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImp= l.java:57) > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcc= essorImpl.java:43) > =09at java.lang.reflect.Method.invoke(Method.java:606) > =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framewo= rkMethod.java:50) > =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveC= allable.java:12) > =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(Framework= Method.java:47) > =09at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeM= ethod.java:17) > =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate= (JUnit4ZKTestRunner.java:79) > =09at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.= java:27) > =09at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > =09at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:78) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:57) > =09at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > =09at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > =09at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > =09at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > =09at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > =09at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > =09at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JU= nitTestRunner.java:535) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch= (JUnitTestRunner.java:1182) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(J= UnitTestRunner.java:1033) > 2016-09-13 05:09:25,444 [myid:1] - INFO [Thread-1:DatadirCleanupManager@= 78] - autopurge.snapRetainCount set to 3 > 2016-09-13 05:09:25,445 [myid:2] - INFO [Thread-2:DatadirCleanupManager@= 78] - autopurge.snapRetainCount set to 3 > 2016-09-13 05:09:25,445 [myid:2] - INFO [Thread-2:DatadirCleanupManager@= 79] - autopurge.purgeInterval set to 0 > 2016-09-13 05:09:25,444 [myid:0] - INFO [Thread-0:DatadirCleanupManager@= 78] - autopurge.snapRetainCount set to 3 > 2016-09-13 05:09:25,445 [myid:2] - INFO [Thread-2:DatadirCleanupManager@= 101] - Purge task is not scheduled. > 2016-09-13 05:09:25,445 [myid:1] - INFO [Thread-1:DatadirCleanupManager@= 79] - autopurge.purgeInterval set to 0 > 2016-09-13 05:09:25,446 [myid:1] - INFO [Thread-1:DatadirCleanupManager@= 101] - Purge task is not scheduled. > 2016-09-13 05:09:25,445 [myid:0] - INFO [Thread-0:DatadirCleanupManager@= 79] - autopurge.purgeInterval set to 0 > 2016-09-13 05:09:25,446 [myid:0] - INFO [Thread-0:DatadirCleanupManager@= 101] - Purge task is not scheduled. > 2016-09-13 05:09:25,446 [myid:2] - INFO [Thread-2:ManagedUtil@46] - Log4= j found with jmx enabled. > 2016-09-13 05:09:25,447 [myid:0] - INFO [Thread-0:ManagedUtil@46] - Log4= j found with jmx enabled. > 2016-09-13 05:09:25,446 [myid:1] - INFO [Thread-1:ManagedUtil@46] - Log4= j found with jmx enabled. > 2016-09-13 05:09:25,552 [myid:1] - ERROR [Thread-1:ManagedUtil@114] - Pro= blems while registering log4j jmx beans! > javax.management.InstanceAlreadyExistsException: log4j:hiearchy=3Ddefault > =09at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithR= epository(DefaultMBeanServerInterceptor.java:1898) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynam= icMBean(DefaultMBeanServerInterceptor.java:966) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObjec= t(DefaultMBeanServerInterceptor.java:900) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean= (DefaultMBeanServerInterceptor.java:324) > =09at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer= .java:522) > =09at org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUti= l.java:75) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(Quo= rumPeerMain.java:131) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(= QuorumPeerMain.java:120) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.ru= n(QuorumPeerTestBase.java:245) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:25,552 [myid:1] - WARN [Thread-1:QuorumPeerMain@133] - = Unable to register log4j JMX control > javax.management.JMException: javax.management.InstanceAlreadyExistsExcep= tion: log4j:hiearchy=3Ddefault > =09at org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUti= l.java:115) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(Quo= rumPeerMain.java:131) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(= QuorumPeerMain.java:120) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.ru= n(QuorumPeerTestBase.java:245) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:25,553 [myid:1] - INFO [Thread-1:QuorumPeerMain@136] - = Starting quorum peer > 2016-09-13 05:09:25,553 [myid:2] - ERROR [Thread-2:HierarchyDynamicMBean@= 138] - Could not add loggerMBean for [root]. > javax.management.InstanceAlreadyExistsException: log4j:logger=3Droot > =09at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithR= epository(DefaultMBeanServerInterceptor.java:1898) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynam= icMBean(DefaultMBeanServerInterceptor.java:966) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObjec= t(DefaultMBeanServerInterceptor.java:900) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean= (DefaultMBeanServerInterceptor.java:324) > =09at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer= .java:522) > =09at org.apache.log4j.jmx.AbstractDynamicMBean.registerMBean(AbstractDyn= amicMBean.java:160) > =09at org.apache.log4j.jmx.HierarchyDynamicMBean.addLoggerMBean(Hierarchy= DynamicMBean.java:125) > =09at org.apache.log4j.jmx.HierarchyDynamicMBean.postRegister(HierarchyDy= namicMBean.java:263) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.postRegister(= DefaultMBeanServerInterceptor.java:1024) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynam= icMBean(DefaultMBeanServerInterceptor.java:974) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObjec= t(DefaultMBeanServerInterceptor.java:900) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean= (DefaultMBeanServerInterceptor.java:324) > =09at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer= .java:522) > =09at org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUti= l.java:75) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(Quo= rumPeerMain.java:131) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(= QuorumPeerMain.java:120) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.ru= n(QuorumPeerTestBase.java:245) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:25,559 [myid:0] - ERROR [Thread-0:ManagedUtil@114] - Pro= blems while registering log4j jmx beans! > javax.management.InstanceAlreadyExistsException: log4j:hiearchy=3Ddefault > =09at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithR= epository(DefaultMBeanServerInterceptor.java:1898) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynam= icMBean(DefaultMBeanServerInterceptor.java:966) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObjec= t(DefaultMBeanServerInterceptor.java:900) > =09at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean= (DefaultMBeanServerInterceptor.java:324) > =09at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer= .java:522) > =09at org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUti= l.java:75) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(Quo= rumPeerMain.java:131) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(= QuorumPeerMain.java:120) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.ru= n(QuorumPeerTestBase.java:245) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:25,560 [myid:0] - WARN [Thread-0:QuorumPeerMain@133] - = Unable to register log4j JMX control > javax.management.JMException: javax.management.InstanceAlreadyExistsExcep= tion: log4j:hiearchy=3Ddefault > =09at org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUti= l.java:115) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(Quo= rumPeerMain.java:131) > =09at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(= QuorumPeerMain.java:120) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.ru= n(QuorumPeerTestBase.java:245) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:25,560 [myid:0] - INFO [Thread-0:QuorumPeerMain@136] - = Starting quorum peer > 2016-09-13 05:09:25,562 [myid:2] - INFO [Thread-2:QuorumPeerMain@136] - = Starting quorum peer > 2016-09-13 05:09:25,581 [myid:0] - INFO [Thread-0:NIOServerCnxnFactory@6= 73] - Configuring NIO connection handler with 10s sessionless connection ti= meout, 1 selector thread(s), 8 worker threads, and 64 kB direct buffers. > 2016-09-13 05:09:25,581 [myid:2] - INFO [Thread-2:NIOServerCnxnFactory@6= 73] - Configuring NIO connection handler with 10s sessionless connection ti= meout, 1 selector thread(s), 8 worker threads, and 64 kB direct buffers. > 2016-09-13 05:09:25,585 [myid:1] - INFO [Thread-1:NIOServerCnxnFactory@6= 73] - Configuring NIO connection handler with 10s sessionless connection ti= meout, 1 selector thread(s), 8 worker threads, and 64 kB direct buffers. > 2016-09-13 05:09:25,591 [myid:0] - INFO [Thread-0:NIOServerCnxnFactory@6= 86] - binding to port /127.0.0.1:13915 > 2016-09-13 05:09:25,592 [myid:1] - INFO [Thread-1:NIOServerCnxnFactory@6= 86] - binding to port /127.0.0.1:13918 > 2016-09-13 05:09:25,593 [myid:2] - INFO [Thread-2:NIOServerCnxnFactory@6= 86] - binding to port /127.0.0.1:13921 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1327] - Loc= al sessions disabled > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1338] - Loc= al session upgrading disabled > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1305] - tic= kTime set to 4000 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1349] - min= SessionTimeout set to 8000 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1360] - max= SessionTimeout set to 80000 > 2016-09-13 05:09:25,622 [myid:1] - INFO [Thread-1:QuorumPeer@1327] - Loc= al sessions disabled > 2016-09-13 05:09:25,622 [myid:1] - INFO [Thread-1:QuorumPeer@1338] - Loc= al session upgrading disabled > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1305] - tic= kTime set to 4000 > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1349] - min= SessionTimeout set to 8000 > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1360] - max= SessionTimeout set to 80000 > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1375] - ini= tLimit set to 10 > 2016-09-13 05:09:25,622 [myid:0] - INFO [Thread-0:QuorumPeer@1327] - Loc= al sessions disabled > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1338] - Loc= al session upgrading disabled > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1305] - tic= kTime set to 4000 > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1349] - min= SessionTimeout set to 8000 > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1360] - max= SessionTimeout set to 80000 > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1375] - ini= tLimit set to 10 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1375] - ini= tLimit set to 10 > 2016-09-13 05:09:25,666 [myid:0] - INFO [Thread-0:QuorumPeer@776] - curr= entEpoch not found! Creating with a reasonable default of 0. This should on= ly happen when you are upgrading your installation > 2016-09-13 05:09:25,668 [myid:1] - INFO [Thread-1:QuorumPeer@776] - curr= entEpoch not found! Creating with a reasonable default of 0. This should on= ly happen when you are upgrading your installation > 2016-09-13 05:09:25,668 [myid:2] - INFO [Thread-2:QuorumPeer@776] - curr= entEpoch not found! Creating with a reasonable default of 0. This should on= ly happen when you are upgrading your installation > 2016-09-13 05:09:25,669 [myid:0] - INFO [Thread-0:QuorumPeer@791] - acce= ptedEpoch not found! Creating with a reasonable default of 0. This should o= nly happen when you are upgrading your installation > 2016-09-13 05:09:25,672 [myid:1] - INFO [Thread-1:QuorumPeer@791] - acce= ptedEpoch not found! Creating with a reasonable default of 0. This should o= nly happen when you are upgrading your installation > 2016-09-13 05:09:25,677 [myid:2] - INFO [Thread-2:QuorumPeer@791] - acce= ptedEpoch not found! Creating with a reasonable default of 0. This should o= nly happen when you are upgrading your installation > 2016-09-13 05:09:25,689 [myid:] - INFO [main:FourLetterWordMain@85] - co= nnecting to 127.0.0.1 13915 > 2016-09-13 05:09:25,704 [myid:0] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket= connection from /127.0.0.1:38366 > 2016-09-13 05:09:25,758 [myid:0] - INFO [NIOWorkerThread-1:NIOServerCnxn= @485] - Processing stat command from /127.0.0.1:38366 > 2016-09-13 05:09:25,770 [myid:1] - INFO [QuorumPeerListener:QuorumCnxMan= ager$Listener@632] - My election bind port: /127.0.0.1:13920 > 2016-09-13 05:09:25,772 [myid:0] - INFO [NIOWorkerThread-1:NIOServerCnxn= @607] - Closed socket connection for client /127.0.0.1:38366 (no session es= tablished for client) > 2016-09-13 05:09:25,783 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):QuorumPeer@1033] - LOOKING > 2016-09-13 05:09:25,785 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):FastLeaderElection@894] - New election. = My id =3D 1, proposed zxid=3D0x0 > 2016-09-13 05:09:25,797 [myid:0] - INFO [QuorumPeerListener:QuorumCnxMan= ager$Listener@632] - My election bind port: /127.0.0.1:13917 > 2016-09-13 05:09:25,798 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):QuorumPeer@1033] - LOOKING > 2016-09-13 05:09:25,798 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):FastLeaderElection@894] - New election. = My id =3D 0, proposed zxid=3D0x0 > 2016-09-13 05:09:25,799 [myid:0] - INFO [/127.0.0.1:13917:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:53023 > 2016-09-13 05:09:25,806 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):QuorumPeer@1033] - LOOKING > 2016-09-13 05:09:25,806 [myid:2] - INFO [QuorumPeerListener:QuorumCnxMan= ager$Listener@632] - My election bind port: /127.0.0.1:13923 > 2016-09-13 05:09:25,806 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):FastLeaderElection@894] - New election. = My id =3D 2, proposed zxid=3D0x0 > 2016-09-13 05:09:25,825 [myid:2] - INFO [/127.0.0.1:13923:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:58679 > 2016-09-13 05:09:25,826 [myid:0] - INFO [WorkerSender[myid=3D0]:QuorumCn= xManager@276] - Have smaller server identifier, so dropping the connection:= (2, 0) > 2016-09-13 05:09:25,825 [myid:1] - INFO [WorkerSender[myid=3D1]:QuorumCn= xManager@276] - Have smaller server identifier, so dropping the connection:= (2, 1) > 2016-09-13 05:09:25,827 [myid:0] - INFO [/127.0.0.1:13917:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:53026 > 2016-09-13 05:09:25,827 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection@688] - Notification: 2 (message format version), 0 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,827 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection@688] - Notification: 2 (message format version), 1 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,848 [myid:1] - INFO [/127.0.0.1:13920:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:46423 > 2016-09-13 05:09:25,848 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection@688] - Notification: 2 (message format version), 0 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,857 [myid:2] - INFO [/127.0.0.1:13923:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:58680 > 2016-09-13 05:09:25,857 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection@688] - Notification: 2 (message format version), 1 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,858 [myid:2] - WARN [RecvWorker:0:QuorumCnxManager$R= ecvWorker@915] - Connection broken for id 0, my id =3D 2, error =3D=20 > java.net.SocketException: Socket closed > =09at java.net.SocketInputStream.socketRead0(Native Method) > =09at java.net.SocketInputStream.read(SocketInputStream.java:152) > =09at java.net.SocketInputStream.read(SocketInputStream.java:122) > =09at java.net.SocketInputStream.read(SocketInputStream.java:210) > =09at java.io.DataInputStream.readInt(DataInputStream.java:387) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(= QuorumCnxManager.java:900) > 2016-09-13 05:09:25,858 [myid:2] - WARN [RecvWorker:0:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,862 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection@688] - Notification: 2 (message format version), 1 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,863 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection@688] - Notification: 2 (message format version), 1 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,865 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$S= endWorker@837] - Exception when using channel: for id 2 my id =3D 0 error = =3D java.net.SocketException: Broken pipe > 2016-09-13 05:09:25,867 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,898 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$S= endWorker@832] - Interrupted while waiting for message on queue > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.awaitNanos(AbstractQueuedSynchronizer.java:2095) > =09at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.jav= a:389) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(Q= uorumCnxManager.java:982) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(Quor= umCnxManager.java:63) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(= QuorumCnxManager.java:820) > 2016-09-13 05:09:25,898 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,898 [myid:2] - INFO [WorkerReceiver[myid=3D2]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,899 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 2 my id =3D 0 > 2016-09-13 05:09:25,899 [myid:2] - INFO [WorkerReceiver[myid=3D2]:FastLe= aderElection@688] - Notification: 2 (message format version), 1 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,900 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,901 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,901 [myid:0] - INFO [/127.0.0.1:13917:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:53028 > 2016-09-13 05:09:25,898 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 0 my id =3D 2 > 2016-09-13 05:09:25,901 [myid:2] - INFO [WorkerReceiver[myid=3D2]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,902 [myid:0] - INFO [WorkerSender[myid=3D0]:QuorumCn= xManager@276] - Have smaller server identifier, so dropping the connection:= (2, 0) > 2016-09-13 05:09:25,903 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,903 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,904 [myid:2] - INFO [/127.0.0.1:13923:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:58684 > 2016-09-13 05:09:25,905 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$S= endWorker@832] - Interrupted while waiting for message on queue > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.awaitNanos(AbstractQueuedSynchronizer.java:2095) > =09at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.jav= a:389) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(Q= uorumCnxManager.java:982) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(Quor= umCnxManager.java:63) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(= QuorumCnxManager.java:820) > 2016-09-13 05:09:25,905 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 0 my id =3D 2 > 2016-09-13 05:09:25,905 [myid:2] - WARN [RecvWorker:0:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,907 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$S= endWorker@837] - Exception when using channel: for id 2 my id =3D 0 error = =3D java.net.SocketException: Broken pipe > 2016-09-13 05:09:25,907 [myid:0] - INFO [/127.0.0.1:13917:QuorumCnxManag= er$Listener@638] - Received connection request /127.0.0.1:53030 > 2016-09-13 05:09:25,908 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 2 my id =3D 0 > 2016-09-13 05:09:25,908 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,909 [myid:2] - INFO [WorkerReceiver[myid=3D2]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:25,910 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection@688] - Notification: 2 (message format version), 2 (n.leader),= 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoc= h), LOOKING (my state)0 (n.config version) > 2016-09-13 05:09:26,022 [myid:] - INFO [main:FourLetterWordMain@85] - co= nnecting to 127.0.0.1 13915 > 2016-09-13 05:09:26,023 [myid:0] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket= connection from /127.0.0.1:38382 > 2016-09-13 05:09:26,032 [myid:0] - INFO [NIOWorkerThread-2:NIOServerCnxn= @485] - Processing stat command from /127.0.0.1:38382 > 2016-09-13 05:09:26,033 [myid:0] - INFO [NIOWorkerThread-2:NIOServerCnxn= @607] - Closed socket connection for client /127.0.0.1:38382 (no session es= tablished for client) > 2016-09-13 05:09:26,103 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1=3Dreplica.1,n= ame2=3DLeaderElection] > 2016-09-13 05:09:26,104 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):QuorumPeer@1109] - FOLLOWING > 2016-09-13 05:09:26,109 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1=3Dreplica.2,n= ame2=3DLeaderElection] > 2016-09-13 05:09:26,110 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):Learner@88] - TCP NoDelay set to: true > 2016-09-13 05:09:26,110 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):QuorumPeer@1121] - LEADING > 2016-09-13 05:09:26,111 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1=3Dreplica.0,n= ame2=3DLeaderElection] > 2016-09-13 05:09:26,111 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):QuorumPeer@1109] - FOLLOWING > 2016-09-13 05:09:26,113 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):Leader@63] - TCP NoDelay set to: true > 2016-09-13 05:09:26,113 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):Leader@83] - zookeeper.leader.maxConcurr= entSnapshots =3D 10 > 2016-09-13 05:09:26,113 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):Leader@85] - zookeeper.leader.maxConcurr= entSnapshotTimeout =3D 5 > 2016-09-13 05:09:26,122 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:zo= okeeper.version=3D3.6.0-SNAPSHOT--1, built on 09/13/2016 05:08 GMT > 2016-09-13 05:09:26,122 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ho= st.name=3Djenkins-test-5f3 > 2016-09-13 05:09:26,123 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.version=3D1.7.0_101 > 2016-09-13 05:09:26,123 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.vendor=3DOracle Corporation > 2016-09-13 05:09:26,123 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.home=3D/usr/lib/jvm/java-7-openjdk-amd64/jre > 2016-09-13 05:09:26,123 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.class.path=3D/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openj= dk7/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trun= k-openjdk7/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/works= pace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr4-runtime-4.5.1-1.jar:/ho= me/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/= checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-o= penjdk7/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-sl= ave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-cli-1.3.1.jar= :/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/= lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/Zoo= Keeper-trunk-openjdk7/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/je= nkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-loggi= ng-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7= /build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKee= per-trunk-openjdk7/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenki= ns-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/junit-4.12.jar:/= home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/li= b/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-tru= nk-openjdk7/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-t= runk-openjdk7/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib= /ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/bui= ld/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-= trunk-openjdk7/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-= slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jackson-mapper-asl-1.9.1= 1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/= lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjd= k7/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/worksp= ace/ZooKeeper-trunk-openjdk7/build/lib/jetty-http-9.2.18.v20160721.jar:/hom= e/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-= io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-tru= nk-openjdk7/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/jen= kins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-server-9.2.18= .v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjd= k7/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave= /workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-util-9.2.18.v20160721.j= ar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib= /jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openj= dk7/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKee= per-trunk-openjdk7/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-s= lave/workspace/ZooKeeper-trunk-openjdk7/build/lib/slf4j-api-1.7.5.jar:/home= /jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/slf4j-l= og4j12-1.7.5.jar:/usr/local/asfpackages/ant/apache-ant-1.9.7/lib/ant-launch= er.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools= /ant/latest/lib/ant-junit4.jar > 2016-09-13 05:09:26,123 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.library.path=3D/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jn= i:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/li= b > 2016-09-13 05:09:26,123 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.io.tmpdir=3D/tmp > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:ja= va.compiler=3D > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:os= .name=3DLinux > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:os= .arch=3Damd64 > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:os= .version=3D3.13.0-30-generic > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:us= er.name=3Djenkins > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:us= er.home=3D/home/jenkins > 2016-09-13 05:09:26,124 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:us= er.dir=3D/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/bui= ld/test > 2016-09-13 05:09:26,125 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:os= .memory.free=3D49MB > 2016-09-13 05:09:26,125 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:os= .memory.max=3D455MB > 2016-09-13 05:09:26,125 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Environment@109] - Server environment:os= .memory.total=3D60MB > 2016-09-13 05:09:26,126 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):ZooKeeperServer@889] - minSessionTimeout= set to 8000 > 2016-09-13 05:09:26,127 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):ZooKeeperServer@898] - maxSessionTimeout= set to 80000 > 2016-09-13 05:09:26,127 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):ZooKeeperServer@159] - Created server wi= th tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /ho= me/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/= test5455612786130415623.junit.dir/data/version-2 snapdir /home/jenkins/jenk= ins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test54556127861= 30415623.junit.dir/data/version-2 > 2016-09-13 05:09:26,126 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):ZooKeeperServer@889] - minSessionTimeout= set to 8000 > 2016-09-13 05:09:26,129 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):ZooKeeperServer@898] - maxSessionTimeout= set to 80000 > 2016-09-13 05:09:26,129 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):ZooKeeperServer@159] - Created server wi= th tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /ho= me/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/= test8397079557861207505.junit.dir/data/version-2 snapdir /home/jenkins/jenk= ins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test83970795578= 61207505.junit.dir/data/version-2 > 2016-09-13 05:09:26,129 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Follower@66] - FOLLOWING - LEADER ELECTI= ON TOOK - 18 MS > 2016-09-13 05:09:26,126 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):ZooKeeperServer@889] - minSessionTimeout= set to 8000 > 2016-09-13 05:09:26,129 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):Leader@412] - LEADING - LEADER ELECTION = TOOK - 20 MS > 2016-09-13 05:09:26,140 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):FileTxnSnapLog@298] - Snapshotting: 0x0 = to /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/tes= t/tmp/test5455612786130415623.junit.dir/data/version-2/snapshot.0 > 2016-09-13 05:09:26,137 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):ZooKeeperServer@898] - maxSessionTimeout= set to 80000 > 2016-09-13 05:09:26,141 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):ZooKeeperServer@159] - Created server wi= th tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /ho= me/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/= test1768888919429940621.junit.dir/data/version-2 snapdir /home/jenkins/jenk= ins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test17688889194= 29940621.junit.dir/data/version-2 > 2016-09-13 05:09:26,141 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):Follower@66] - FOLLOWING - LEADER ELECTI= ON TOOK - 37 MS > 2016-09-13 05:09:26,185 [myid:2] - INFO [LearnerHandler-/127.0.0.1:39078= :LearnerHandler@382] - Follower sid: 0 : info : 127.0.0.1:13916:13917:parti= cipant;127.0.0.1:13915 > 2016-09-13 05:09:26,191 [myid:2] - INFO [LearnerHandler-/127.0.0.1:39079= :LearnerHandler@382] - Follower sid: 1 : info : 127.0.0.1:13919:13920:parti= cipant;127.0.0.1:13918 > 2016-09-13 05:09:26,198 [myid:2] - INFO [LearnerHandler-/127.0.0.1:39079= :LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog= =3D0x0 minCommittedLog=3D0x0 lastProcessedZxid=3D0x0 peerLastZxid=3D0x0 > 2016-09-13 05:09:26,198 [myid:2] - INFO [LearnerHandler-/127.0.0.1:39079= :LearnerHandler@727] - Sending DIFF zxid=3D0x0 for peer sid: 1 > 2016-09-13 05:09:26,198 [myid:2] - INFO [LearnerHandler-/127.0.0.1:39078= :LearnerHandler@683] - Synchronizing with Follower sid: 0 maxCommittedLog= =3D0x0 minCommittedLog=3D0x0 lastProcessedZxid=3D0x0 peerLastZxid=3D0x0 > 2016-09-13 05:09:26,199 [myid:2] - INFO [LearnerHandler-/127.0.0.1:39078= :LearnerHandler@727] - Sending DIFF zxid=3D0x0 for peer sid: 0 > 2016-09-13 05:09:26,201 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):Learner@366] - Getting a diff from the l= eader 0x0 > 2016-09-13 05:09:26,206 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):Learner@509] - Learner received NEWLEADE= R message > 2016-09-13 05:09:26,209 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):FileTxnSnapLog@298] - Snapshotting: 0x0 = to /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/tes= t/tmp/test1768888919429940621.junit.dir/data/version-2/snapshot.0 > 2016-09-13 05:09:26,210 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Learner@366] - Getting a diff from the l= eader 0x0 > 2016-09-13 05:09:26,211 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Learner@509] - Learner received NEWLEADE= R message > 2016-09-13 05:09:26,213 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):Leader@1255] - Have quorum of supporters= , sids: [ [1, 2],[1, 2] ]; starting up and setting last processed zxid: 0x1= 00000000 > 2016-09-13 05:09:26,215 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):FileTxnSnapLog@298] - Snapshotting: 0x0 = to /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/tes= t/tmp/test8397079557861207505.junit.dir/data/version-2/snapshot.0 > 2016-09-13 05:09:26,238 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):CommitProcessor@318] - Configuring Commi= tProcessor with 4 worker threads. > 2016-09-13 05:09:26,252 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):ContainerManager@64] - Using checkInterv= alMs=3D60000 maxPerMinute=3D10000 > 2016-09-13 05:09:26,254 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Learner@493] - Learner received UPTODATE= message > 2016-09-13 05:09:26,254 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):Learner@493] - Learner received UPTODATE= message > 2016-09-13 05:09:26,266 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):CommitProcessor@318] - Configuring Commi= tProcessor with 4 worker threads. > 2016-09-13 05:09:26,272 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):CommitProcessor@318] - Configuring Commi= tProcessor with 4 worker threads. > 2016-09-13 05:09:26,283 [myid:] - INFO [main:FourLetterWordMain@85] - co= nnecting to 127.0.0.1 13915 > 2016-09-13 05:09:26,284 [myid:0] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket= connection from /127.0.0.1:38385 > 2016-09-13 05:09:26,285 [myid:0] - INFO [NIOWorkerThread-3:NIOServerCnxn= @485] - Processing stat command from /127.0.0.1:38385 > 2016-09-13 05:09:26,286 [myid:0] - INFO [NIOWorkerThread-3:StatCommand@4= 9] - Stat command output > 2016-09-13 05:09:26,287 [myid:0] - INFO [NIOWorkerThread-3:NIOServerCnxn= @607] - Closed socket connection for client /127.0.0.1:38385 (no session es= tablished for client) > 2016-09-13 05:09:26,288 [myid:] - INFO [main:FourLetterWordMain@85] - co= nnecting to 127.0.0.1 13918 > 2016-09-13 05:09:26,288 [myid:1] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13918:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket= connection from /127.0.0.1:55309 > 2016-09-13 05:09:26,291 [myid:1] - INFO [NIOWorkerThread-1:NIOServerCnxn= @485] - Processing stat command from /127.0.0.1:55309 > 2016-09-13 05:09:26,291 [myid:1] - INFO [NIOWorkerThread-1:StatCommand@4= 9] - Stat command output > 2016-09-13 05:09:26,292 [myid:1] - INFO [NIOWorkerThread-1:NIOServerCnxn= @607] - Closed socket connection for client /127.0.0.1:55309 (no session es= tablished for client) > 2016-09-13 05:09:26,292 [myid:] - INFO [main:FourLetterWordMain@85] - co= nnecting to 127.0.0.1 13921 > 2016-09-13 05:09:26,293 [myid:2] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13921:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket= connection from /127.0.0.1:45002 > 2016-09-13 05:09:26,297 [myid:2] - INFO [NIOWorkerThread-1:NIOServerCnxn= @485] - Processing stat command from /127.0.0.1:45002 > 2016-09-13 05:09:26,297 [myid:2] - INFO [NIOWorkerThread-1:StatCommand@4= 9] - Stat command output > 2016-09-13 05:09:26,298 [myid:2] - INFO [NIOWorkerThread-1:NIOServerCnxn= @607] - Closed socket connection for client /127.0.0.1:45002 (no session es= tablished for client) > 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client e= nvironment:zookeeper.version=3D3.6.0-SNAPSHOT--1, built on 09/13/2016 05:08= GMT > 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client e= nvironment:host.name=3Djenkins-test-5f3 > 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client e= nvironment:java.version=3D1.7.0_101 > 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client e= nvironment:java.vendor=3DOracle Corporation > 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client e= nvironment:java.home=3D/usr/lib/jvm/java-7-openjdk-amd64/jre > 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client e= nvironment:java.class.path=3D/home/jenkins/jenkins-slave/workspace/ZooKeepe= r-trunk-openjdk7/build/test/classes:/home/jenkins/jenkins-slave/workspace/Z= ooKeeper-trunk-openjdk7/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkin= s-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr4-runtime-4.= 5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/bu= ild/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooK= eeper-trunk-openjdk7/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenki= ns/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-= cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk= 7/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/= workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-lang3-3.4.jar:/ho= me/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/= commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-t= runk-openjdk7/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/wor= kspace/ZooKeeper-trunk-openjdk7/build/test/lib/hamcrest-core-1.3.jar:/home/= jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/jun= it-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/= build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/= ZooKeeper-trunk-openjdk7/build/classes:/home/jenkins/jenkins-slave/workspac= e/ZooKeeper-trunk-openjdk7/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/a= nt/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk= -openjdk7/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspa= ce/ZooKeeper-trunk-openjdk7/build/lib/jackson-core-asl-1.9.11.jar:/home/jen= kins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jackson-map= per-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-op= enjdk7/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper= -trunk-openjdk7/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins= -slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-http-9.2.18.v2016= 0721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/bui= ld/lib/jetty-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/= ZooKeeper-trunk-openjdk7/build/lib/jetty-security-9.2.18.v20160721.jar:/hom= e/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-= server-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper= -trunk-openjdk7/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/= jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-util-9.2.1= 8.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openj= dk7/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeepe= r-trunk-openjdk7/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/wor= kspace/ZooKeeper-trunk-openjdk7/build/lib/netty-3.10.5.Final. > ...[truncated 31909 chars]... > 3] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@915] - Connection br= oken for id 1, my id =3D 3, error =3D=20 > java.io.EOFException > =09at java.io.DataInputStream.readInt(DataInputStream.java:392) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(= QuorumCnxManager.java:900) > 2016-09-13 05:09:26,894 [myid:3] - WARN [RecvWorker:1:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,894 [myid:3] - WARN [SendWorker:1:QuorumCnxManager$S= endWorker@832] - Interrupted while waiting for message on queue > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.awaitNanos(AbstractQueuedSynchronizer.java:2095) > =09at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.jav= a:389) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(Q= uorumCnxManager.java:982) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(Quor= umCnxManager.java:63) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(= QuorumCnxManager.java:820) > 2016-09-13 05:09:26,894 [myid:3] - WARN [SendWorker:1:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 1 my id =3D 3 > 2016-09-13 05:09:26,895 [myid:1] - WARN [RecvWorker:3:QuorumCnxManager$R= ecvWorker@915] - Connection broken for id 3, my id =3D 1, error =3D=20 > java.net.SocketException: Socket closed > =09at java.net.SocketInputStream.socketRead0(Native Method) > =09at java.net.SocketInputStream.read(SocketInputStream.java:152) > =09at java.net.SocketInputStream.read(SocketInputStream.java:122) > =09at java.net.SocketInputStream.read(SocketInputStream.java:210) > =09at java.io.DataInputStream.readInt(DataInputStream.java:387) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(= QuorumCnxManager.java:900) > 2016-09-13 05:09:26,895 [myid:1] - WARN [RecvWorker:3:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,895 [myid:1] - WARN [SendWorker:3:QuorumCnxManager$S= endWorker@832] - Interrupted while waiting for message on queue > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.awaitNanos(AbstractQueuedSynchronizer.java:2095) > =09at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.jav= a:389) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(Q= uorumCnxManager.java:982) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(Quor= umCnxManager.java:63) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(= QuorumCnxManager.java:820) > 2016-09-13 05:09:26,896 [myid:1] - WARN [SendWorker:3:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 3 my id =3D 1 > 2016-09-13 05:09:26,905 [myid:0] - WARN [SendWorker:1:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 1 my id =3D 0 > 2016-09-13 05:09:26,905 [myid:0] - WARN [RecvWorker:3:QuorumCnxManager$R= ecvWorker@915] - Connection broken for id 3, my id =3D 0, error =3D=20 > java.net.SocketException: Socket closed > =09at java.net.SocketInputStream.socketRead0(Native Method) > =09at java.net.SocketInputStream.read(SocketInputStream.java:152) > =09at java.net.SocketInputStream.read(SocketInputStream.java:122) > =09at java.net.SocketInputStream.read(SocketInputStream.java:210) > =09at java.io.DataInputStream.readInt(DataInputStream.java:387) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(= QuorumCnxManager.java:900) > 2016-09-13 05:09:26,906 [myid:0] - WARN [RecvWorker:3:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,905 [myid:3] - WARN [RecvWorker:0:QuorumCnxManager$R= ecvWorker@915] - Connection broken for id 0, my id =3D 3, error =3D=20 > java.io.EOFException > =09at java.io.DataInputStream.readInt(DataInputStream.java:392) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(= QuorumCnxManager.java:900) > 2016-09-13 05:09:26,906 [myid:3] - WARN [RecvWorker:0:QuorumCnxManager$R= ecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,905 [myid:0] - WARN [SendWorker:3:QuorumCnxManager$S= endWorker@832] - Interrupted while waiting for message on queue > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.awaitNanos(AbstractQueuedSynchronizer.java:2095) > =09at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.jav= a:389) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(Q= uorumCnxManager.java:982) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(Quor= umCnxManager.java:63) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(= QuorumCnxManager.java:820) > 2016-09-13 05:09:26,913 [myid:3] - WARN [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):Learner@417] - Got zxid 0x10000000= 2 expected 0x1 > 2016-09-13 05:09:26,917 [myid:3] - WARN [SendWorker:0:QuorumCnxManager$S= endWorker@832] - Interrupted while waiting for message on queue > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObje= ct.awaitNanos(AbstractQueuedSynchronizer.java:2095) > =09at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.jav= a:389) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(Q= uorumCnxManager.java:982) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(Quor= umCnxManager.java:63) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(= QuorumCnxManager.java:820) > 2016-09-13 05:09:26,918 [myid:3] - WARN [SendWorker:0:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 0 my id =3D 3 > 2016-09-13 05:09:26,917 [myid:0] - WARN [SendWorker:3:QuorumCnxManager$S= endWorker@841] - Send worker leaving thread id 3 my id =3D 0 > 2016-09-13 05:09:26,917 [myid:1] - INFO [QuorumPeerListener:QuorumCnxMan= ager$Listener@632] - My election bind port: /127.0.0.1:13920 > 2016-09-13 05:09:26,919 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):QuorumPeer@1481] - writeToDisk =3D= =3D true but configFilename =3D=3D null > 2016-09-13 05:09:26,920 [myid:3] - WARN [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):QuorumPeer@1417] - Restarting Lead= er Election > 2016-09-13 05:09:26,920 [myid:3] - INFO [/127.0.0.1:13926:QuorumCnxManag= er$Listener@661] - Leaving listener > 2016-09-13 05:09:26,922 [myid:0] - INFO [QuorumPeerListener:QuorumCnxMan= ager$Listener@632] - My election bind port: /127.0.0.1:13917 > 2016-09-13 05:09:26,936 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):Learner@493] - Learner received UP= TODATE message > 2016-09-13 05:09:26,936 [myid:3] - INFO [QuorumPeerListener:QuorumCnxMan= ager$Listener@632] - My election bind port: /127.0.0.1:13926 > 2016-09-13 05:09:27,036 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):CommitProcessor@318] - Configuring= CommitProcessor with 4 worker threads. > 2016-09-13 05:09:27,061 [myid:3] - INFO [SyncThread:3:FileTxnLog@204] - = Creating new log file: log.100000002 > 2016-09-13 05:09:28,635 [myid:127.0.0.1:13924] - INFO [main-SendThread(1= 27.0.0.1:13924):ClientCnxn$SendThread@1113] - Opening socket connection to = server 127.0.0.1/127.0.0.1:13924. Will not attempt to authenticate using SA= SL (unknown error) > 2016-09-13 05:09:28,635 [myid:127.0.0.1:13924] - INFO [main-SendThread(1= 27.0.0.1:13924):ClientCnxn$SendThread@948] - Socket connection established,= initiating session, client: /127.0.0.1:50397, server: 127.0.0.1/127.0.0.1:= 13924 > 2016-09-13 05:09:28,636 [myid:3] - INFO [NIOServerCxnFactory.AcceptThrea= d:0.0.0.0/0.0.0.0:13924:NIOServerCnxnFactory$AcceptThread@296] - Accepted s= ocket connection from /127.0.0.1:50397 > 2016-09-13 05:09:28,651 [myid:3] - INFO [NIOWorkerThread-2:ZooKeeperServ= er@995] - Client attempting to establish new session at /127.0.0.1:50397 > 2016-09-13 05:09:28,652 [myid:3] - WARN [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):Follower@122] - Got zxid 0x1000000= 03 expected 0x1 > 2016-09-13 05:09:28,654 [myid:3] - INFO [CommitProcWorkThread-1:ZooKeepe= rServer@709] - Established session 0x3000048422c0000 with negotiated timeou= t 30000 for client /127.0.0.1:50397 > 2016-09-13 05:09:28,661 [myid:127.0.0.1:13924] - INFO [main-SendThread(1= 27.0.0.1:13924):ClientCnxn$SendThread@1381] - Session establishment complet= e on server 127.0.0.1/127.0.0.1:13924, sessionid =3D 0x3000048422c0000, neg= otiated timeout =3D 30000 > 2016-09-13 05:09:28,690 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedIn= vokeMethod@98] - TEST METHOD FAILED testDuringLeaderSync > java.lang.AssertionError: zoo.cfg.dynamic.next is not deleted. > =09at org.junit.Assert.fail(Assert.java:88) > =09at org.junit.Assert.assertTrue(Assert.java:41) > =09at org.junit.Assert.assertFalse(Assert.java:64) > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tes= tDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155) > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImp= l.java:57) > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcc= essorImpl.java:43) > =09at java.lang.reflect.Method.invoke(Method.java:606) > =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framewo= rkMethod.java:50) > =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveC= allable.java:12) > =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(Framework= Method.java:47) > =09at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeM= ethod.java:17) > =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate= (JUnit4ZKTestRunner.java:79) > =09at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.= java:27) > =09at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > =09at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:78) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:57) > =09at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > =09at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > =09at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > =09at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > =09at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > =09at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > =09at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JU= nitTestRunner.java:535) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch= (JUnitTestRunner.java:1182) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(J= UnitTestRunner.java:1033) > 2016-09-13 05:09:28,692 [myid:] - INFO [main:QuorumBase@394] - Shutting = down quorum peer QuorumPeer[myid=3D0](plain=3D/127.0.0.1:13915)(secure=3Ddi= sabled) > 2016-09-13 05:09:28,692 [myid:] - INFO [main:Follower@198] - shutdown ca= lled > java.lang.Exception: shutdown Follower > =09at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:= 198) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.j= ava:1184) > =09at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.sh= utdown(QuorumPeerTestBase.java:60) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.sh= utdown(QuorumPeerTestBase.java:257) > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tea= rDown(ReconfigDuringLeaderSyncTest.java:189) > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImp= l.java:57) > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcc= essorImpl.java:43) > =09at java.lang.reflect.Method.invoke(Method.java:606) > =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framewo= rkMethod.java:50) > =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveC= allable.java:12) > =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(Framework= Method.java:47) > =09at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.= java:33) > =09at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > =09at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:78) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:57) > =09at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > =09at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > =09at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > =09at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > =09at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > =09at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > =09at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JU= nitTestRunner.java:535) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch= (JUnitTestRunner.java:1182) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(J= UnitTestRunner.java:1033) > 2016-09-13 05:09:28,693 [myid:] - INFO [main:MBeanRegistry@128] - Unregi= ster MBean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1= =3Dreplica.0,name2=3DFollower,name3=3DConnections,name4=3D127.0.0.1,name5= =3D0x483fd50000] > 2016-09-13 05:09:28,694 [myid:] - INFO [main:NIOServerCnxn@607] - Closed= socket connection for client /127.0.0.1:38389 which had sessionid 0x483fd5= 0000 > 2016-09-13 05:09:28,694 [myid:] - INFO [main:LearnerZooKeeperServer@165]= - Shutting down > 2016-09-13 05:09:28,694 [myid:] - INFO [main:ZooKeeperServer@529] - shut= ting down > 2016-09-13 05:09:28,694 [myid:] - INFO [main:FollowerRequestProcessor@13= 8] - Shutting down > 2016-09-13 05:09:28,695 [myid:127.0.0.1:13915] - INFO [main-SendThread(1= 27.0.0.1:13915):ClientCnxn$SendThread@1231] - Unable to read additional dat= a from server sessionid 0x483fd50000, likely server has closed socket, clos= ing socket connection and attempting reconnect > 2016-09-13 05:09:28,695 [myid:] - INFO [main:CommitProcessor@414] - Shut= ting down > 2016-09-13 05:09:28,695 [myid:0] - INFO [FollowerRequestProcessor:0:Foll= owerRequestProcessor@109] - FollowerRequestProcessor exited loop! > 2016-09-13 05:09:28,696 [myid:0] - INFO [CommitProcessor:0:CommitProcess= or@299] - CommitProcessor exited loop! > 2016-09-13 05:09:28,696 [myid:] - INFO [main:FinalRequestProcessor@479] = - shutdown of request processor complete > 2016-09-13 05:09:28,697 [myid:] - INFO [main:MBeanRegistry@128] - Unregi= ster MBean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1= =3Dreplica.0,name2=3DFollower,name3=3DInMemoryDataTree] > 2016-09-13 05:09:28,697 [myid:] - INFO [main:SyncRequestProcessor@191] -= Shutting down > 2016-09-13 05:09:28,697 [myid:0] - INFO [SyncThread:0:SyncRequestProcess= or@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:28,698 [myid:0] - INFO [ConnnectionExpirer:NIOServerCnx= nFactory$ConnectionExpirerThread@583] - ConnnectionExpirerThread interrupte= d > 2016-09-13 05:09:28,698 [myid:0] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@219] - accept thread e= xitted run method > 2016-09-13 05:09:28,699 [myid:0] - INFO [NIOServerCxnFactory.SelectorThr= ead-0:NIOServerCnxnFactory$SelectorThread@420] - selector thread exitted ru= n method > 2016-09-13 05:09:28,699 [myid:0] - INFO [/127.0.0.1:13917:QuorumCnxManag= er$Listener@661] - Leaving listener > 2016-09-13 05:09:28,700 [myid:] - INFO [main:QuorumBase@398] - Shutting = down leader election QuorumPeer[myid=3D0](plain=3D/127.0.0.1:13915)(secure= =3Ddisabled) > 2016-09-13 05:09:28,700 [myid:] - INFO [main:QuorumBase@403] - Waiting f= or QuorumPeer[myid=3D0](plain=3D/127.0.0.1:13915)(secure=3Ddisabled) to exi= t thread > 2016-09-13 05:09:29,738 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection$Messenger$WorkerReceiver@440] - WorkerReceiver is down > 2016-09-13 05:09:29,738 [myid:0] - INFO [WorkerSender[myid=3D0]:FastLead= erElection$Messenger$WorkerSender@470] - WorkerSender is down > 2016-09-13 05:09:29,776 [myid:1] - INFO [WorkerReceiver[myid=3D1]:FastLe= aderElection$Messenger$WorkerReceiver@440] - WorkerReceiver is down > 2016-09-13 05:09:29,785 [myid:3] - INFO [WorkerSender[myid=3D3]:FastLead= erElection$Messenger$WorkerSender@470] - WorkerSender is down > 2016-09-13 05:09:29,785 [myid:1] - INFO [WorkerSender[myid=3D1]:FastLead= erElection$Messenger$WorkerSender@470] - WorkerSender is down > 2016-09-13 05:09:29,789 [myid:2] - INFO [WorkerReceiver[myid=3D2]:FastLe= aderElection$Messenger$WorkerReceiver@440] - WorkerReceiver is down > 2016-09-13 05:09:29,790 [myid:2] - INFO [WorkerSender[myid=3D2]:FastLead= erElection$Messenger$WorkerSender@470] - WorkerSender is down > 2016-09-13 05:09:29,792 [myid:3] - INFO [WorkerReceiver[myid=3D3]:FastLe= aderElection$Messenger$WorkerReceiver@440] - WorkerReceiver is down > 2016-09-13 05:09:29,922 [myid:0] - INFO [WorkerSender[myid=3D0]:FastLead= erElection$Messenger$WorkerSender@470] - WorkerSender is down > 2016-09-13 05:09:29,923 [myid:0] - INFO [WorkerReceiver[myid=3D0]:FastLe= aderElection$Messenger$WorkerReceiver@440] - WorkerReceiver is down > 2016-09-13 05:09:30,255 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1=3Dreplica.0,n= ame2=3DFollower] > 2016-09-13 05:09:30,256 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):Follower@198] - shutdown called > java.lang.Exception: shutdown Follower > =09at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:= 198) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1= 115) > 2016-09-13 05:09:30,256 [myid:0] - WARN [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):QuorumPeer@1158] - PeerState set to LOOK= ING > 2016-09-13 05:09:30,256 [myid:0] - WARN [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):QuorumPeer@1140] - QuorumPeer main threa= d exited > 2016-09-13 05:09:30,256 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0] > 2016-09-13 05:09:30,256 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1=3Dreplica.0] > 2016-09-13 05:09:30,256 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1=3Dreplica.1] > 2016-09-13 05:09:30,257 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1=3Dreplica.2] > 2016-09-13 05:09:30,257 [myid:0] - INFO [QuorumPeer[myid=3D0](plain=3D/1= 27.0.0.1:13915)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id0,name1=3Dreplica.3] > 2016-09-13 05:09:30,258 [myid:] - INFO [main:QuorumBase@394] - Shutting = down quorum peer QuorumPeer[myid=3D1](plain=3D/127.0.0.1:13918)(secure=3Ddi= sabled) > 2016-09-13 05:09:30,258 [myid:] - INFO [main:Follower@198] - shutdown ca= lled > java.lang.Exception: shutdown Follower > =09at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:= 198) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.j= ava:1184) > =09at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.sh= utdown(QuorumPeerTestBase.java:60) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.sh= utdown(QuorumPeerTestBase.java:257) > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tea= rDown(ReconfigDuringLeaderSyncTest.java:189) > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImp= l.java:57) > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcc= essorImpl.java:43) > =09at java.lang.reflect.Method.invoke(Method.java:606) > =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framewo= rkMethod.java:50) > =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveC= allable.java:12) > =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(Framework= Method.java:47) > =09at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.= java:33) > =09at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > =09at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:78) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:57) > =09at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > =09at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > =09at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > =09at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > =09at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > =09at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > =09at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JU= nitTestRunner.java:535) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch= (JUnitTestRunner.java:1182) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(J= UnitTestRunner.java:1033) > 2016-09-13 05:09:30,259 [myid:] - INFO [main:LearnerZooKeeperServer@165]= - Shutting down > 2016-09-13 05:09:30,259 [myid:] - INFO [main:ZooKeeperServer@529] - shut= ting down > 2016-09-13 05:09:30,259 [myid:] - INFO [main:FollowerRequestProcessor@13= 8] - Shutting down > 2016-09-13 05:09:30,259 [myid:] - INFO [main:CommitProcessor@414] - Shut= ting down > 2016-09-13 05:09:30,259 [myid:1] - INFO [FollowerRequestProcessor:1:Foll= owerRequestProcessor@109] - FollowerRequestProcessor exited loop! > 2016-09-13 05:09:30,259 [myid:] - INFO [main:FinalRequestProcessor@479] = - shutdown of request processor complete > 2016-09-13 05:09:30,259 [myid:1] - INFO [CommitProcessor:1:CommitProcess= or@299] - CommitProcessor exited loop! > 2016-09-13 05:09:30,260 [myid:] - INFO [main:MBeanRegistry@128] - Unregi= ster MBean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1= =3Dreplica.1,name2=3DFollower,name3=3DInMemoryDataTree] > 2016-09-13 05:09:30,260 [myid:] - INFO [main:SyncRequestProcessor@191] -= Shutting down > 2016-09-13 05:09:30,260 [myid:1] - INFO [SyncThread:1:SyncRequestProcess= or@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:30,261 [myid:1] - INFO [ConnnectionExpirer:NIOServerCnx= nFactory$ConnectionExpirerThread@583] - ConnnectionExpirerThread interrupte= d > 2016-09-13 05:09:30,261 [myid:1] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13918:NIOServerCnxnFactory$AcceptThread@219] - accept thread e= xitted run method > 2016-09-13 05:09:30,261 [myid:1] - INFO [NIOServerCxnFactory.SelectorThr= ead-0:NIOServerCnxnFactory$SelectorThread@420] - selector thread exitted ru= n method > 2016-09-13 05:09:30,261 [myid:1] - INFO [/127.0.0.1:13920:QuorumCnxManag= er$Listener@661] - Leaving listener > 2016-09-13 05:09:30,261 [myid:] - INFO [main:QuorumBase@398] - Shutting = down leader election QuorumPeer[myid=3D1](plain=3D/127.0.0.1:13918)(secure= =3Ddisabled) > 2016-09-13 05:09:30,262 [myid:] - INFO [main:QuorumBase@403] - Waiting f= or QuorumPeer[myid=3D1](plain=3D/127.0.0.1:13918)(secure=3Ddisabled) to exi= t thread > 2016-09-13 05:09:30,624 [myid:127.0.0.1:13915] - INFO [main-SendThread(1= 27.0.0.1:13915):ClientCnxn$SendThread@1113] - Opening socket connection to = server 127.0.0.1/127.0.0.1:13915. Will not attempt to authenticate using SA= SL (unknown error) > 2016-09-13 05:09:30,624 [myid:127.0.0.1:13915] - WARN [main-SendThread(1= 27.0.0.1:13915):ClientCnxn$SendThread@1235] - Session 0x483fd50000 for serv= er 127.0.0.1/127.0.0.1:13915, unexpected error, closing socket connection a= nd attempting reconnect > java.net.ConnectException: Connection refused > =09at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > =09at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:7= 44) > =09at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSock= etNIO.java:357) > =09at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1214= ) > 2016-09-13 05:09:31,733 [myid:127.0.0.1:13915] - INFO [main-SendThread(1= 27.0.0.1:13915):ClientCnxn$SendThread@1113] - Opening socket connection to = server 127.0.0.1/127.0.0.1:13915. Will not attempt to authenticate using SA= SL (unknown error) > 2016-09-13 05:09:31,734 [myid:127.0.0.1:13915] - WARN [main-SendThread(1= 27.0.0.1:13915):ClientCnxn$SendThread@1235] - Session 0x483fd50000 for serv= er 127.0.0.1/127.0.0.1:13915, unexpected error, closing socket connection a= nd attempting reconnect > java.net.ConnectException: Connection refused > =09at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > =09at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:7= 44) > =09at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSock= etNIO.java:357) > =09at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1214= ) > 2016-09-13 05:09:32,255 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1=3Dreplica.1,n= ame2=3DFollower] > 2016-09-13 05:09:32,256 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):Follower@198] - shutdown called > java.lang.Exception: shutdown Follower > =09at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:= 198) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1= 115) > 2016-09-13 05:09:32,256 [myid:1] - WARN [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):QuorumPeer@1158] - PeerState set to LOOK= ING > 2016-09-13 05:09:32,256 [myid:1] - WARN [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):QuorumPeer@1140] - QuorumPeer main threa= d exited > 2016-09-13 05:09:32,256 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1] > 2016-09-13 05:09:32,257 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1=3Dreplica.1] > 2016-09-13 05:09:32,257 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1=3Dreplica.0] > 2016-09-13 05:09:32,257 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1=3Dreplica.2] > 2016-09-13 05:09:32,257 [myid:1] - INFO [QuorumPeer[myid=3D1](plain=3D/1= 27.0.0.1:13918)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id1,name1=3Dreplica.3] > 2016-09-13 05:09:32,257 [myid:] - INFO [main:QuorumBase@394] - Shutting = down quorum peer QuorumPeer[myid=3D2](plain=3D/127.0.0.1:13921)(secure=3Ddi= sabled) > 2016-09-13 05:09:32,258 [myid:] - INFO [main:Leader@623] - Shutting down > 2016-09-13 05:09:32,258 [myid:] - INFO [main:Leader@629] - Shutdown call= ed > java.lang.Exception: shutdown Leader! reason: quorum Peer shutdown > =09at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:629) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.j= ava:1181) > =09at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.sh= utdown(QuorumPeerTestBase.java:60) > =09at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.sh= utdown(QuorumPeerTestBase.java:257) > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tea= rDown(ReconfigDuringLeaderSyncTest.java:189) > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImp= l.java:57) > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcc= essorImpl.java:43) > =09at java.lang.reflect.Method.invoke(Method.java:606) > =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framewo= rkMethod.java:50) > =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveC= allable.java:12) > =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(Framework= Method.java:47) > =09at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.= java:33) > =09at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > =09at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:78) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:57) > =09at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > =09at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > =09at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > =09at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > =09at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > =09at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > =09at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JU= nitTestRunner.java:535) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch= (JUnitTestRunner.java:1182) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(J= UnitTestRunner.java:1033) > 2016-09-13 05:09:32,259 [myid:] - INFO [main:ZooKeeperServer@529] - shut= ting down > 2016-09-13 05:09:32,259 [myid:] - INFO [main:SessionTrackerImpl@232] - S= hutting down > 2016-09-13 05:09:32,259 [myid:] - INFO [main:LeaderRequestProcessor@77] = - Shutting down > 2016-09-13 05:09:32,259 [myid:] - INFO [main:PrepRequestProcessor@965] -= Shutting down > 2016-09-13 05:09:32,259 [myid:] - INFO [main:ProposalRequestProcessor@88= ] - Shutting down > 2016-09-13 05:09:32,259 [myid:2] - INFO [ProcessThread(sid:2 cport:-1)::= PrepRequestProcessor@154] - PrepRequestProcessor exited loop! > 2016-09-13 05:09:32,259 [myid:] - INFO [main:CommitProcessor@414] - Shut= ting down > 2016-09-13 05:09:32,260 [myid:2] - INFO [CommitProcessor:2:CommitProcess= or@299] - CommitProcessor exited loop! > 2016-09-13 05:09:32,260 [myid:] - INFO [main:Leader$ToBeAppliedRequestPr= ocessor@924] - Shutting down > 2016-09-13 05:09:32,260 [myid:] - INFO [main:FinalRequestProcessor@479] = - shutdown of request processor complete > 2016-09-13 05:09:32,261 [myid:] - INFO [main:SyncRequestProcessor@191] -= Shutting down > 2016-09-13 05:09:32,262 [myid:2] - INFO [SyncThread:2:SyncRequestProcess= or@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:32,262 [myid:2] - INFO [LearnerCnxAcceptor-/127.0.0.1:1= 3922:Leader$LearnerCnxAcceptor@373] - exception while shutting down accepto= r: java.net.SocketException: Socket closed > 2016-09-13 05:09:32,263 [myid:] - INFO [main:MBeanRegistry@128] - Unregi= ster MBean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1= =3Dreplica.2,name2=3DLeader,name3=3DInMemoryDataTree] > 2016-09-13 05:09:32,264 [myid:2] - WARN [LearnerHandler-/127.0.0.1:39078= :LearnerHandler@619] - ******* GOODBYE /127.0.0.1:39078 ******** > 2016-09-13 05:09:32,265 [myid:3] - WARN [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):Follower@93] - Exception when foll= owing the leader > java.io.EOFException > =09at java.io.DataInputStream.readInt(DataInputStream.java:392) > =09at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:= 63) > =09at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumP= acket.java:83) > =09at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.ja= va:99) > =09at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:= 155) > =09at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.j= ava:89) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1= 111) > 2016-09-13 05:09:32,265 [myid:2] - WARN [LearnerHandler-/127.0.0.1:39079= :LearnerHandler@619] - ******* GOODBYE /127.0.0.1:39079 ******** > 2016-09-13 05:09:32,265 [myid:2] - WARN [LearnerHandler-/127.0.0.1:39104= :LearnerHandler@619] - ******* GOODBYE /127.0.0.1:39104 ******** > 2016-09-13 05:09:32,265 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.3,name2=3DFollower] > 2016-09-13 05:09:32,265 [myid:2] - WARN [LearnerHandler-/127.0.0.1:39104= :LearnerHandler@903] - Ignoring unexpected exception > java.lang.InterruptedException > =09at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterr= uptibly(AbstractQueuedSynchronizer.java:1219) > =09at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(Reentran= tLock.java:340) > =09at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.ja= va:338) > =09at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerH= andler.java:901) > =09at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandle= r.java:622) > 2016-09-13 05:09:32,265 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):Follower@198] - shutdown called > java.lang.Exception: shutdown Follower > =09at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:= 198) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1= 115) > 2016-09-13 05:09:32,266 [myid:2] - INFO [NIOServerCxnFactory.AcceptThrea= d:/127.0.0.1:13921:NIOServerCnxnFactory$AcceptThread@219] - accept thread e= xitted run method > 2016-09-13 05:09:32,266 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.3,name2=3DFollower,name3=3DConnections,name4=3D127.0.0.1,name5=3D0x30000= 48422c0000] > 2016-09-13 05:09:32,266 [myid:2] - INFO [NIOServerCxnFactory.SelectorThr= ead-0:NIOServerCnxnFactory$SelectorThread@420] - selector thread exitted ru= n method > 2016-09-13 05:09:32,266 [myid:2] - INFO [ConnnectionExpirer:NIOServerCnx= nFactory$ConnectionExpirerThread@583] - ConnnectionExpirerThread interrupte= d > 2016-09-13 05:09:32,266 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):NIOServerCnxn@607] - Closed socket= connection for client /127.0.0.1:50397 which had sessionid 0x3000048422c00= 00 > 2016-09-13 05:09:32,267 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):LearnerZooKeeperServer@165] - Shut= ting down > 2016-09-13 05:09:32,267 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):ZooKeeperServer@529] - shutting do= wn > 2016-09-13 05:09:32,267 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):FollowerRequestProcessor@138] - Sh= utting down > 2016-09-13 05:09:32,267 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):CommitProcessor@414] - Shutting do= wn > 2016-09-13 05:09:32,267 [myid:127.0.0.1:13924] - INFO [main-SendThread(1= 27.0.0.1:13924):ClientCnxn$SendThread@1231] - Unable to read additional dat= a from server sessionid 0x3000048422c0000, likely server has closed socket,= closing socket connection and attempting reconnect > 2016-09-13 05:09:32,268 [myid:3] - INFO [FollowerRequestProcessor:3:Foll= owerRequestProcessor@109] - FollowerRequestProcessor exited loop! > 2016-09-13 05:09:32,268 [myid:3] - INFO [CommitProcessor:3:CommitProcess= or@299] - CommitProcessor exited loop! > 2016-09-13 05:09:32,268 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):FinalRequestProcessor@479] - shutd= own of request processor complete > 2016-09-13 05:09:32,269 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.3,name2=3DFollower,name3=3DInMemoryDataTree] > 2016-09-13 05:09:32,269 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):SyncRequestProcessor@191] - Shutti= ng down > 2016-09-13 05:09:32,269 [myid:3] - INFO [SyncThread:3:SyncRequestProcess= or@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:32,269 [myid:3] - WARN [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):QuorumPeer@1158] - PeerState set t= o LOOKING > 2016-09-13 05:09:32,269 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):QuorumPeer@1033] - LOOKING > 2016-09-13 05:09:32,270 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):FileSnap@83] - Reading snapshot /h= ome/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp= /test1465497725988500626.junit.dir/data/version-2/snapshot.100000001 > 2016-09-13 05:09:32,271 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1=3Dreplica.2,n= ame2=3DLeader] > 2016-09-13 05:09:32,272 [myid:2] - WARN [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):QuorumPeer@1127] - Unexpected exception > java.lang.InterruptedException > =09at java.lang.Object.wait(Native Method) > =09at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:561) > =09at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1= 124) > 2016-09-13 05:09:32,272 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):Leader@623] - Shutting down > 2016-09-13 05:09:32,272 [myid:2] - WARN [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):QuorumPeer@1158] - PeerState set to LOOK= ING > 2016-09-13 05:09:32,272 [myid:2] - WARN [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):QuorumPeer@1140] - QuorumPeer main threa= d exited > 2016-09-13 05:09:32,272 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2] > 2016-09-13 05:09:32,272 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1=3Dreplica.2] > 2016-09-13 05:09:32,272 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1=3Dreplica.0] > 2016-09-13 05:09:32,273 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1=3Dreplica.1] > 2016-09-13 05:09:32,273 [myid:2] - INFO [QuorumPeer[myid=3D2](plain=3D/1= 27.0.0.1:13921)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MBean [o= rg.apache.ZooKeeperService:name0=3DReplicatedServer_id2,name1=3Dreplica.3] > 2016-09-13 05:09:32,274 [myid:2] - INFO [/127.0.0.1:13923:QuorumCnxManag= er$Listener@661] - Leaving listener > 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@398] - Shutting = down leader election QuorumPeer[myid=3D2](plain=3D/127.0.0.1:13921)(secure= =3Ddisabled) > 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@403] - Waiting f= or QuorumPeer[myid=3D2](plain=3D/127.0.0.1:13921)(secure=3Ddisabled) to exi= t thread > 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@394] - Shutting = down quorum peer QuorumPeer[myid=3D3](plain=3D/0:0:0:0:0:0:0:0:13924)(secur= e=3Ddisabled) > 2016-09-13 05:09:32,275 [myid:3] - INFO [ConnnectionExpirer:NIOServerCnx= nFactory$ConnectionExpirerThread@583] - ConnnectionExpirerThread interrupte= d > 2016-09-13 05:09:32,275 [myid:3] - INFO [NIOServerCxnFactory.AcceptThrea= d:0.0.0.0/0.0.0.0:13924:NIOServerCnxnFactory$AcceptThread@219] - accept thr= ead exitted run method > 2016-09-13 05:09:32,276 [myid:3] - INFO [NIOServerCxnFactory.SelectorThr= ead-0:NIOServerCnxnFactory$SelectorThread@420] - selector thread exitted ru= n method > 2016-09-13 05:09:32,276 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):FastLeaderElection@894] - New elec= tion. My id =3D 3, proposed zxid=3D0x100000004 > 2016-09-13 05:09:32,277 [myid:3] - WARN [WorkerSender[myid=3D3]:QuorumCn= xManager@455] - Cannot open channel to 0 at election address /127.0.0.1:139= 17 > java.net.ConnectException: Connection refused > =09at java.net.PlainSocketImpl.socketConnect(Native Method) > =09at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.= java:339) > =09at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSock= etImpl.java:200) > =09at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.ja= va:182) > =09at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > =09at java.net.Socket.connect(Socket.java:579) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:441) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:482) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCn= xManager.java:419) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.process(FastLeaderElection.java:486) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.run(FastLeaderElection.java:465) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,277 [myid:3] - INFO [/127.0.0.1:13926:QuorumCnxManag= er$Listener@661] - Leaving listener > 2016-09-13 05:09:32,277 [myid:3] - WARN [WorkerSender[myid=3D3]:QuorumCn= xManager@455] - Cannot open channel to 0 at election address /127.0.0.1:139= 17 > java.net.ConnectException: Connection refused > =09at java.net.PlainSocketImpl.socketConnect(Native Method) > =09at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.= java:339) > =09at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSock= etImpl.java:200) > =09at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.ja= va:182) > =09at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > =09at java.net.Socket.connect(Socket.java:579) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:441) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:489) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCn= xManager.java:419) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.process(FastLeaderElection.java:486) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.run(FastLeaderElection.java:465) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,278 [myid:3] - WARN [WorkerSender[myid=3D3]:QuorumCn= xManager@455] - Cannot open channel to 1 at election address /127.0.0.1:139= 20 > java.net.ConnectException: Connection refused > =09at java.net.PlainSocketImpl.socketConnect(Native Method) > =09at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.= java:339) > =09at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSock= etImpl.java:200) > =09at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.ja= va:182) > =09at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > =09at java.net.Socket.connect(Socket.java:579) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:441) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:482) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCn= xManager.java:419) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.process(FastLeaderElection.java:486) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.run(FastLeaderElection.java:465) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,278 [myid:] - INFO [main:QuorumBase@398] - Shutting = down leader election QuorumPeer[myid=3D3](plain=3D/0:0:0:0:0:0:0:0:13924)(s= ecure=3Ddisabled) > 2016-09-13 05:09:32,279 [myid:] - INFO [main:QuorumBase@403] - Waiting f= or QuorumPeer[myid=3D3](plain=3D/0:0:0:0:0:0:0:0:13924)(secure=3Ddisabled) = to exit thread > 2016-09-13 05:09:32,279 [myid:3] - WARN [WorkerSender[myid=3D3]:QuorumCn= xManager@455] - Cannot open channel to 1 at election address /127.0.0.1:139= 20 > java.net.ConnectException: Connection refused > =09at java.net.PlainSocketImpl.socketConnect(Native Method) > =09at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.= java:339) > =09at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSock= etImpl.java:200) > =09at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.ja= va:182) > =09at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > =09at java.net.Socket.connect(Socket.java:579) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:441) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(Quor= umCnxManager.java:489) > =09at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCn= xManager.java:419) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.process(FastLeaderElection.java:486) > =09at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$Wor= kerSender.run(FastLeaderElection.java:465) > =09at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,280 [myid:3] - INFO [WorkerSender[myid=3D3]:FastLead= erElection$Messenger$WorkerSender@470] - WorkerSender is down > 2016-09-13 05:09:32,280 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.3,name2=3DLeaderElection] > 2016-09-13 05:09:32,280 [myid:3] - WARN [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):QuorumPeer@1140] - QuorumPeer main= thread exited > 2016-09-13 05:09:32,280 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3] > 2016-09-13 05:09:32,280 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.3] > 2016-09-13 05:09:32,281 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.0] > 2016-09-13 05:09:32,281 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.1] > 2016-09-13 05:09:32,281 [myid:3] - INFO [QuorumPeer[myid=3D3](plain=3D/0= :0:0:0:0:0:0:0:13924)(secure=3Ddisabled):MBeanRegistry@128] - Unregister MB= ean [org.apache.ZooKeeperService:name0=3DReplicatedServer_id3,name1=3Drepli= ca.2] > 2016-09-13 05:09:32,283 [myid:] - INFO [main:ZKTestCase$1@70] - FAILED t= estDuringLeaderSync > java.lang.AssertionError: zoo.cfg.dynamic.next is not deleted. > =09at org.junit.Assert.fail(Assert.java:88) > =09at org.junit.Assert.assertTrue(Assert.java:41) > =09at org.junit.Assert.assertFalse(Assert.java:64) > =09at org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tes= tDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155) > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImp= l.java:57) > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcc= essorImpl.java:43) > =09at java.lang.reflect.Method.invoke(Method.java:606) > =09at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(Framewo= rkMethod.java:50) > =09at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveC= allable.java:12) > =09at org.junit.runners.model.FrameworkMethod.invokeExplosively(Framework= Method.java:47) > =09at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeM= ethod.java:17) > =09at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate= (JUnit4ZKTestRunner.java:79) > =09at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.= java:27) > =09at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > =09at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:78) > =09at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassR= unner.java:57) > =09at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > =09at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > =09at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > =09at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > =09at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > =09at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > =09at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JU= nitTestRunner.java:535) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch= (JUnitTestRunner.java:1182) > =09at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(J= UnitTestRunner.java:1033) > 2016-09-13 05:09:32,284 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED= testDuringLeaderSync > {noformat} -- This message was sent by Atlassian JIRA (v6.4.14#64029)