[ https://issues.apache.org/jira/browse/ZOOKEEPER-2577?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16102525#comment-16102525 ]
Hadoop QA commented on ZOOKEEPER-2577: -------------------------------------- +1 overall. GitHub Pull Request Build +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 3 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac 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-build/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.ReconfigDuringLeaderSyncTest.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. > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155) > at > 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$LoggedInvokeMethod@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] - Assigned > port 13915 from range 13914 - 16606. > 2016-09-13 05:09:25,380 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13916 from range 13914 - 16606. > 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13917 from range 13914 - 16606. > 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13918 from range 13914 - 16606. > 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13919 from range 13914 - 16606. > 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13920 from range 13914 - 16606. > 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13921 from range 13914 - 16606. > 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13922 from range 13914 - 16606. > 2016-09-13 05:09:25,383 [myid:] - INFO [main:PortAssignment@85] - Assigned > port 13923 from range 13914 - 16606. > 2016-09-13 05:09:25,406 [myid:] - INFO > [main:QuorumPeerTestBase$MainThread@131] - id = 0 tmpDir = > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir > clientPort = 13915 adminServerPort = 8080 > 2016-09-13 05:09:25,416 [myid:] - INFO > [main:QuorumPeerTestBase$MainThread@131] - id = 1 tmpDir = > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir > clientPort = 13918 adminServerPort = 8080 > 2016-09-13 05:09:25,420 [myid:] - INFO > [main:QuorumPeerTestBase$MainThread@131] - id = 2 tmpDir = > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir > clientPort = 13921 adminServerPort = 8080 > 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-0:QuorumPeerConfig@116] - > Reading configuration from: > /home/jenkins/jenkins-slave/workspace/ZooKeeper-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/ZooKeeper-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/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/zoo.cfg > 2016-09-13 05:09:25,424 [myid:] - INFO [main:FourLetterWordMain@85] - > connecting 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 > 127.0.0.1:13915 not up > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at > java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) > at > java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) > at > java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > at java.net.Socket.connect(Socket.java:579) > at > org.apache.zookeeper.client.FourLetterWordMain.send4LetterWord(FourLetterWordMain.java:99) > at > org.apache.zookeeper.client.FourLetterWordMain.send4LetterWord(FourLetterWordMain.java:69) > at > org.apache.zookeeper.test.ClientBase.waitForServerUp(ClientBase.java:241) > at > org.apache.zookeeper.test.ClientBase.waitForServerUp(ClientBase.java:232) > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:85) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at > org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) > at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.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] - Log4j > found with jmx enabled. > 2016-09-13 05:09:25,447 [myid:0] - INFO [Thread-0:ManagedUtil@46] - Log4j > found with jmx enabled. > 2016-09-13 05:09:25,446 [myid:1] - INFO [Thread-1:ManagedUtil@46] - Log4j > found with jmx enabled. > 2016-09-13 05:09:25,552 [myid:1] - ERROR [Thread-1:ManagedUtil@114] - > Problems while registering log4j jmx beans! > javax.management.InstanceAlreadyExistsException: log4j:hiearchy=default > at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) > at > com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) > at > org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:75) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245) > at 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.InstanceAlreadyExistsException: log4j:hiearchy=default > at > org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:115) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245) > at 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=root > at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) > at > com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) > at > org.apache.log4j.jmx.AbstractDynamicMBean.registerMBean(AbstractDynamicMBean.java:160) > at > org.apache.log4j.jmx.HierarchyDynamicMBean.addLoggerMBean(HierarchyDynamicMBean.java:125) > at > org.apache.log4j.jmx.HierarchyDynamicMBean.postRegister(HierarchyDynamicMBean.java:263) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.postRegister(DefaultMBeanServerInterceptor.java:1024) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:974) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) > at > com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) > at > org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:75) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245) > at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:25,559 [myid:0] - ERROR [Thread-0:ManagedUtil@114] - > Problems while registering log4j jmx beans! > javax.management.InstanceAlreadyExistsException: log4j:hiearchy=default > at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900) > at > com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324) > at > com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) > at > org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:75) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245) > at 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.InstanceAlreadyExistsException: log4j:hiearchy=default > at > org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:115) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131) > at > org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245) > at 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@673] > - Configuring NIO connection handler with 10s sessionless connection timeout, > 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@673] > - Configuring NIO connection handler with 10s sessionless connection timeout, > 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@673] > - Configuring NIO connection handler with 10s sessionless connection timeout, > 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@686] > - binding to port /127.0.0.1:13915 > 2016-09-13 05:09:25,592 [myid:1] - INFO [Thread-1:NIOServerCnxnFactory@686] > - binding to port /127.0.0.1:13918 > 2016-09-13 05:09:25,593 [myid:2] - INFO [Thread-2:NIOServerCnxnFactory@686] > - binding to port /127.0.0.1:13921 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1327] - Local > sessions disabled > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1338] - Local > session upgrading disabled > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1305] - > tickTime set to 4000 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1349] - > minSessionTimeout set to 8000 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1360] - > maxSessionTimeout set to 80000 > 2016-09-13 05:09:25,622 [myid:1] - INFO [Thread-1:QuorumPeer@1327] - Local > sessions disabled > 2016-09-13 05:09:25,622 [myid:1] - INFO [Thread-1:QuorumPeer@1338] - Local > session upgrading disabled > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1305] - > tickTime set to 4000 > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1349] - > minSessionTimeout set to 8000 > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1360] - > maxSessionTimeout set to 80000 > 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1375] - > initLimit set to 10 > 2016-09-13 05:09:25,622 [myid:0] - INFO [Thread-0:QuorumPeer@1327] - Local > sessions disabled > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1338] - Local > session upgrading disabled > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1305] - > tickTime set to 4000 > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1349] - > minSessionTimeout set to 8000 > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1360] - > maxSessionTimeout set to 80000 > 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1375] - > initLimit set to 10 > 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1375] - > initLimit set to 10 > 2016-09-13 05:09:25,666 [myid:0] - INFO [Thread-0:QuorumPeer@776] - > currentEpoch not found! Creating with a reasonable default of 0. This should > only happen when you are upgrading your installation > 2016-09-13 05:09:25,668 [myid:1] - INFO [Thread-1:QuorumPeer@776] - > currentEpoch not found! Creating with a reasonable default of 0. This should > only happen when you are upgrading your installation > 2016-09-13 05:09:25,668 [myid:2] - INFO [Thread-2:QuorumPeer@776] - > currentEpoch not found! Creating with a reasonable default of 0. This should > only happen when you are upgrading your installation > 2016-09-13 05:09:25,669 [myid:0] - INFO [Thread-0:QuorumPeer@791] - > acceptedEpoch not found! Creating with a reasonable default of 0. This should > only happen when you are upgrading your installation > 2016-09-13 05:09:25,672 [myid:1] - INFO [Thread-1:QuorumPeer@791] - > acceptedEpoch not found! Creating with a reasonable default of 0. This should > only happen when you are upgrading your installation > 2016-09-13 05:09:25,677 [myid:2] - INFO [Thread-2:QuorumPeer@791] - > acceptedEpoch not found! Creating with a reasonable default of 0. This should > only happen when you are upgrading your installation > 2016-09-13 05:09:25,689 [myid:] - INFO [main:FourLetterWordMain@85] - > connecting to 127.0.0.1 13915 > 2016-09-13 05:09:25,704 [myid:0] - INFO > [NIOServerCxnFactory.AcceptThread:/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:QuorumCnxManager$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 established for client) > 2016-09-13 05:09:25,783 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1033] > - LOOKING > 2016-09-13 05:09:25,785 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):FastLeaderElection@894] > - New election. My id = 1, proposed zxid=0x0 > 2016-09-13 05:09:25,797 [myid:0] - INFO > [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: > /127.0.0.1:13917 > 2016-09-13 05:09:25,798 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1033] > - LOOKING > 2016-09-13 05:09:25,798 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):FastLeaderElection@894] > - New election. My id = 0, proposed zxid=0x0 > 2016-09-13 05:09:25,799 [myid:0] - INFO > [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:53023 > 2016-09-13 05:09:25,806 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1033] > - LOOKING > 2016-09-13 05:09:25,806 [myid:2] - INFO > [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: > /127.0.0.1:13923 > 2016-09-13 05:09:25,806 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):FastLeaderElection@894] > - New election. My id = 2, proposed zxid=0x0 > 2016-09-13 05:09:25,825 [myid:2] - INFO > [/127.0.0.1:13923:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:58679 > 2016-09-13 05:09:25,826 [myid:0] - INFO > [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier, > so dropping the connection: (2, 0) > 2016-09-13 05:09:25,825 [myid:1] - INFO > [WorkerSender[myid=1]:QuorumCnxManager@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:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:53026 > 2016-09-13 05:09:25,827 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message > format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,827 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message > format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,848 [myid:1] - INFO > [/127.0.0.1:13920:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:46423 > 2016-09-13 05:09:25,848 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message > format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,857 [myid:2] - INFO > [/127.0.0.1:13923:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:58680 > 2016-09-13 05:09:25,857 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message > format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,858 [myid:2] - WARN > [RecvWorker:0:QuorumCnxManager$RecvWorker@915] - Connection broken for id 0, > my id = 2, error = > java.net.SocketException: Socket closed > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.read(SocketInputStream.java:152) > at java.net.SocketInputStream.read(SocketInputStream.java:122) > at java.net.SocketInputStream.read(SocketInputStream.java:210) > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900) > 2016-09-13 05:09:25,858 [myid:2] - WARN > [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,862 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message > format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,863 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message > format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,865 [myid:0] - WARN > [SendWorker:2:QuorumCnxManager$SendWorker@837] - Exception when using > channel: for id 2 my id = 0 error = java.net.SocketException: Broken pipe > 2016-09-13 05:09:25,867 [myid:0] - WARN > [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,898 [myid:2] - WARN > [SendWorker:0:QuorumCnxManager$SendWorker@832] - Interrupted while waiting > for message on queue > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820) > 2016-09-13 05:09:25,898 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,898 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,899 [myid:0] - WARN > [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 2 my id = 0 > 2016-09-13 05:09:25,899 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message > format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,900 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,901 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,901 [myid:0] - INFO > [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:53028 > 2016-09-13 05:09:25,898 [myid:2] - WARN > [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 0 my id = 2 > 2016-09-13 05:09:25,901 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,902 [myid:0] - INFO > [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier, > so dropping the connection: (2, 0) > 2016-09-13 05:09:25,903 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,903 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,904 [myid:2] - INFO > [/127.0.0.1:13923:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:58684 > 2016-09-13 05:09:25,905 [myid:2] - WARN > [SendWorker:0:QuorumCnxManager$SendWorker@832] - Interrupted while waiting > for message on queue > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820) > 2016-09-13 05:09:25,905 [myid:2] - WARN > [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 0 my id = 2 > 2016-09-13 05:09:25,905 [myid:2] - WARN > [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,907 [myid:0] - WARN > [SendWorker:2:QuorumCnxManager$SendWorker@837] - Exception when using > channel: for id 2 my id = 0 error = java.net.SocketException: Broken pipe > 2016-09-13 05:09:25,907 [myid:0] - INFO > [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection > request /127.0.0.1:53030 > 2016-09-13 05:09:25,908 [myid:0] - WARN > [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 2 my id = 0 > 2016-09-13 05:09:25,908 [myid:0] - WARN > [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:25,909 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:25,910 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message > format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING > (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config > version) > 2016-09-13 05:09:26,022 [myid:] - INFO [main:FourLetterWordMain@85] - > connecting to 127.0.0.1 13915 > 2016-09-13 05:09:26,023 [myid:0] - INFO > [NIOServerCxnFactory.AcceptThread:/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 established for client) > 2016-09-13 05:09:26,103 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection] > 2016-09-13 05:09:26,104 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1109] > - FOLLOWING > 2016-09-13 05:09:26,109 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=LeaderElection] > 2016-09-13 05:09:26,110 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@88] - > TCP NoDelay set to: true > 2016-09-13 05:09:26,110 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1121] > - LEADING > 2016-09-13 05:09:26,111 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=LeaderElection] > 2016-09-13 05:09:26,111 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1109] > - FOLLOWING > 2016-09-13 05:09:26,113 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@63] - TCP > NoDelay set to: true > 2016-09-13 05:09:26,113 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@83] - > zookeeper.leader.maxConcurrentSnapshots = 10 > 2016-09-13 05:09:26,113 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@85] - > zookeeper.leader.maxConcurrentSnapshotTimeout = 5 > 2016-09-13 05:09:26,122 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:zookeeper.version=3.6.0-SNAPSHOT--1, built on 09/13/2016 > 05:08 GMT > 2016-09-13 05:09:26,122 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:host.name=jenkins-test-5f3 > 2016-09-13 05:09:26,123 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:java.version=1.7.0_101 > 2016-09-13 05:09:26,123 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:java.vendor=Oracle Corporation > 2016-09-13 05:09:26,123 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre > 2016-09-13 05:09:26,123 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server > environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/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/ZooKeeper-trunk-openjdk7/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/junit-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/workspace/ZooKeeper-trunk-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/build/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.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/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.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/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:/home/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.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/slf4j-log4j12-1.7.5.jar:/usr/local/asfpackages/ant/apache-ant-1.9.7/lib/ant-launcher.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=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server > environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib > 2016-09-13 05:09:26,123 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:java.io.tmpdir=/tmp > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:java.compiler=<NA> > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:os.name=Linux > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:os.arch=amd64 > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:os.version=3.13.0-30-generic > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:user.name=jenkins > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:user.home=/home/jenkins > 2016-09-13 05:09:26,124 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server > environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test > 2016-09-13 05:09:26,125 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:os.memory.free=49MB > 2016-09-13 05:09:26,125 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:os.memory.max=455MB > 2016-09-13 05:09:26,125 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109] > - Server environment:os.memory.total=60MB > 2016-09-13 05:09:26,126 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ZooKeeperServer@889] > - minSessionTimeout set to 8000 > 2016-09-13 05:09:26,127 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ZooKeeperServer@898] > - maxSessionTimeout set to 80000 > 2016-09-13 05:09:26,127 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ZooKeeperServer@159] > - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout > 80000 datadir > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/data/version-2 > snapdir > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/data/version-2 > 2016-09-13 05:09:26,126 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):ZooKeeperServer@889] > - minSessionTimeout set to 8000 > 2016-09-13 05:09:26,129 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):ZooKeeperServer@898] > - maxSessionTimeout set to 80000 > 2016-09-13 05:09:26,129 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):ZooKeeperServer@159] > - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout > 80000 datadir > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/data/version-2 > snapdir > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/data/version-2 > 2016-09-13 05:09:26,129 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Follower@66] - > FOLLOWING - LEADER ELECTION TOOK - 18 MS > 2016-09-13 05:09:26,126 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):ZooKeeperServer@889] > - minSessionTimeout set to 8000 > 2016-09-13 05:09:26,129 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@412] - > LEADING - LEADER ELECTION TOOK - 20 MS > 2016-09-13 05:09:26,140 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):FileTxnSnapLog@298] > - Snapshotting: 0x0 to > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/data/version-2/snapshot.0 > 2016-09-13 05:09:26,137 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):ZooKeeperServer@898] > - maxSessionTimeout set to 80000 > 2016-09-13 05:09:26,141 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):ZooKeeperServer@159] > - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout > 80000 datadir > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/data/version-2 > snapdir > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/data/version-2 > 2016-09-13 05:09:26,141 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Follower@66] - > FOLLOWING - LEADER ELECTION 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:participant;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:participant;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=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0 > peerLastZxid=0x0 > 2016-09-13 05:09:26,198 [myid:2] - INFO > [LearnerHandler-/127.0.0.1:39079:LearnerHandler@727] - Sending DIFF zxid=0x0 > 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=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0 > peerLastZxid=0x0 > 2016-09-13 05:09:26,199 [myid:2] - INFO > [LearnerHandler-/127.0.0.1:39078:LearnerHandler@727] - Sending DIFF zxid=0x0 > for peer sid: 0 > 2016-09-13 05:09:26,201 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@366] - > Getting a diff from the leader 0x0 > 2016-09-13 05:09:26,206 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@509] - > Learner received NEWLEADER message > 2016-09-13 05:09:26,209 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):FileTxnSnapLog@298] > - Snapshotting: 0x0 to > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/data/version-2/snapshot.0 > 2016-09-13 05:09:26,210 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Learner@366] - > Getting a diff from the leader 0x0 > 2016-09-13 05:09:26,211 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Learner@509] - > Learner received NEWLEADER message > 2016-09-13 05:09:26,213 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@1255] - > Have quorum of supporters, sids: [ [1, 2],[1, 2] ]; starting up and setting > last processed zxid: 0x100000000 > 2016-09-13 05:09:26,215 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):FileTxnSnapLog@298] > - Snapshotting: 0x0 to > /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/data/version-2/snapshot.0 > 2016-09-13 05:09:26,238 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):CommitProcessor@318] > - Configuring CommitProcessor with 4 worker threads. > 2016-09-13 05:09:26,252 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ContainerManager@64] > - Using checkIntervalMs=60000 maxPerMinute=10000 > 2016-09-13 05:09:26,254 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Learner@493] - > Learner received UPTODATE message > 2016-09-13 05:09:26,254 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@493] - > Learner received UPTODATE message > 2016-09-13 05:09:26,266 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):CommitProcessor@318] > - Configuring CommitProcessor with 4 worker threads. > 2016-09-13 05:09:26,272 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):CommitProcessor@318] > - Configuring CommitProcessor with 4 worker threads. > 2016-09-13 05:09:26,283 [myid:] - INFO [main:FourLetterWordMain@85] - > connecting to 127.0.0.1 13915 > 2016-09-13 05:09:26,284 [myid:0] - INFO > [NIOServerCxnFactory.AcceptThread:/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@49] - > 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 established for client) > 2016-09-13 05:09:26,288 [myid:] - INFO [main:FourLetterWordMain@85] - > connecting to 127.0.0.1 13918 > 2016-09-13 05:09:26,288 [myid:1] - INFO > [NIOServerCxnFactory.AcceptThread:/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@49] - > 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 established for client) > 2016-09-13 05:09:26,292 [myid:] - INFO [main:FourLetterWordMain@85] - > connecting to 127.0.0.1 13921 > 2016-09-13 05:09:26,293 [myid:2] - INFO > [NIOServerCxnFactory.AcceptThread:/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@49] - > 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 established for client) > 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client > environment:zookeeper.version=3.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 > environment:host.name=jenkins-test-5f3 > 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client > environment:java.version=1.7.0_101 > 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client > environment:java.vendor=Oracle Corporation > 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client > environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre > 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client > environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/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/ZooKeeper-trunk-openjdk7/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/junit-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/workspace/ZooKeeper-trunk-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/build/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.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/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.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/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:/home/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.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/netty-3.10.5.Final. > ...[truncated 31909 chars]... > 3] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@915] - Connection broken > for id 1, my id = 3, error = > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:392) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900) > 2016-09-13 05:09:26,894 [myid:3] - WARN > [RecvWorker:1:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,894 [myid:3] - WARN > [SendWorker:1:QuorumCnxManager$SendWorker@832] - Interrupted while waiting > for message on queue > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820) > 2016-09-13 05:09:26,894 [myid:3] - WARN > [SendWorker:1:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 1 my id = 3 > 2016-09-13 05:09:26,895 [myid:1] - WARN > [RecvWorker:3:QuorumCnxManager$RecvWorker@915] - Connection broken for id 3, > my id = 1, error = > java.net.SocketException: Socket closed > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.read(SocketInputStream.java:152) > at java.net.SocketInputStream.read(SocketInputStream.java:122) > at java.net.SocketInputStream.read(SocketInputStream.java:210) > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900) > 2016-09-13 05:09:26,895 [myid:1] - WARN > [RecvWorker:3:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,895 [myid:1] - WARN > [SendWorker:3:QuorumCnxManager$SendWorker@832] - Interrupted while waiting > for message on queue > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820) > 2016-09-13 05:09:26,896 [myid:1] - WARN > [SendWorker:3:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 3 my id = 1 > 2016-09-13 05:09:26,905 [myid:0] - WARN > [SendWorker:1:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 1 my id = 0 > 2016-09-13 05:09:26,905 [myid:0] - WARN > [RecvWorker:3:QuorumCnxManager$RecvWorker@915] - Connection broken for id 3, > my id = 0, error = > java.net.SocketException: Socket closed > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.read(SocketInputStream.java:152) > at java.net.SocketInputStream.read(SocketInputStream.java:122) > at java.net.SocketInputStream.read(SocketInputStream.java:210) > at java.io.DataInputStream.readInt(DataInputStream.java:387) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900) > 2016-09-13 05:09:26,906 [myid:0] - WARN > [RecvWorker:3:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,905 [myid:3] - WARN > [RecvWorker:0:QuorumCnxManager$RecvWorker@915] - Connection broken for id 0, > my id = 3, error = > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:392) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900) > 2016-09-13 05:09:26,906 [myid:3] - WARN > [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker > 2016-09-13 05:09:26,905 [myid:0] - WARN > [SendWorker:3:QuorumCnxManager$SendWorker@832] - Interrupted while waiting > for message on queue > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820) > 2016-09-13 05:09:26,913 [myid:3] - WARN > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Learner@417] > - Got zxid 0x100000002 expected 0x1 > 2016-09-13 05:09:26,917 [myid:3] - WARN > [SendWorker:0:QuorumCnxManager$SendWorker@832] - Interrupted while waiting > for message on queue > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) > at > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) > at > java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820) > 2016-09-13 05:09:26,918 [myid:3] - WARN > [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 0 my id = 3 > 2016-09-13 05:09:26,917 [myid:0] - WARN > [SendWorker:3:QuorumCnxManager$SendWorker@841] - Send worker leaving thread > id 3 my id = 0 > 2016-09-13 05:09:26,917 [myid:1] - INFO > [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: > /127.0.0.1:13920 > 2016-09-13 05:09:26,919 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1481] > - writeToDisk == true but configFilename == null > 2016-09-13 05:09:26,920 [myid:3] - WARN > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1417] > - Restarting Leader Election > 2016-09-13 05:09:26,920 [myid:3] - INFO > [/127.0.0.1:13926:QuorumCnxManager$Listener@661] - Leaving listener > 2016-09-13 05:09:26,922 [myid:0] - INFO > [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: > /127.0.0.1:13917 > 2016-09-13 05:09:26,936 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Learner@493] > - Learner received UPTODATE message > 2016-09-13 05:09:26,936 [myid:3] - INFO > [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: > /127.0.0.1:13926 > 2016-09-13 05:09:27,036 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):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(127.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 SASL (unknown error) > 2016-09-13 05:09:28,635 [myid:127.0.0.1:13924] - INFO > [main-SendThread(127.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.AcceptThread:0.0.0.0/0.0.0.0:13924:NIOServerCnxnFactory$AcceptThread@296] > - Accepted socket connection from /127.0.0.1:50397 > 2016-09-13 05:09:28,651 [myid:3] - INFO > [NIOWorkerThread-2:ZooKeeperServer@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=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Follower@122] > - Got zxid 0x100000003 expected 0x1 > 2016-09-13 05:09:28,654 [myid:3] - INFO > [CommitProcWorkThread-1:ZooKeeperServer@709] - Established session > 0x3000048422c0000 with negotiated timeout 30000 for client /127.0.0.1:50397 > 2016-09-13 05:09:28,661 [myid:127.0.0.1:13924] - INFO > [main-SendThread(127.0.0.1:13924):ClientCnxn$SendThread@1381] - Session > establishment complete on server 127.0.0.1/127.0.0.1:13924, sessionid = > 0x3000048422c0000, negotiated timeout = 30000 > 2016-09-13 05:09:28,690 [myid:] - INFO > [main:JUnit4ZKTestRunner$LoggedInvokeMethod@98] - TEST METHOD FAILED > testDuringLeaderSync > java.lang.AssertionError: zoo.cfg.dynamic.next is not deleted. > at org.junit.Assert.fail(Assert.java:88) > at org.junit.Assert.assertTrue(Assert.java:41) > at org.junit.Assert.assertFalse(Assert.java:64) > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at > org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) > at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033) > 2016-09-13 05:09:28,692 [myid:] - INFO [main:QuorumBase@394] - Shutting down > quorum peer QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled) > 2016-09-13 05:09:28,692 [myid:] - INFO [main:Follower@198] - shutdown called > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198) > at > org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:1184) > at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.shutdown(QuorumPeerTestBase.java:60) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.shutdown(QuorumPeerTestBase.java:257) > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tearDown(ReconfigDuringLeaderSyncTest.java:189) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33) > at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033) > 2016-09-13 05:09:28,693 [myid:] - INFO [main:MBeanRegistry@128] - Unregister > MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=Follower,name3=Connections,name4=127.0.0.1,name5=0x483fd50000] > 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 0x483fd50000 > 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] - shutting > down > 2016-09-13 05:09:28,694 [myid:] - INFO [main:FollowerRequestProcessor@138] - > Shutting down > 2016-09-13 05:09:28,695 [myid:127.0.0.1:13915] - INFO > [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1231] - Unable to > read additional data from server sessionid 0x483fd50000, likely server has > closed socket, closing socket connection and attempting reconnect > 2016-09-13 05:09:28,695 [myid:] - INFO [main:CommitProcessor@414] - Shutting > down > 2016-09-13 05:09:28,695 [myid:0] - INFO > [FollowerRequestProcessor:0:FollowerRequestProcessor@109] - > FollowerRequestProcessor exited loop! > 2016-09-13 05:09:28,696 [myid:0] - INFO > [CommitProcessor:0:CommitProcessor@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] - Unregister > MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=Follower,name3=InMemoryDataTree] > 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:SyncRequestProcessor@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:28,698 [myid:0] - INFO > [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - > ConnnectionExpirerThread interrupted > 2016-09-13 05:09:28,698 [myid:0] - INFO > [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@219] > - accept thread exitted run method > 2016-09-13 05:09:28,699 [myid:0] - INFO > [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420] > - selector thread exitted run method > 2016-09-13 05:09:28,699 [myid:0] - INFO > [/127.0.0.1:13917:QuorumCnxManager$Listener@661] - Leaving listener > 2016-09-13 05:09:28,700 [myid:] - INFO [main:QuorumBase@398] - Shutting down > leader election QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled) > 2016-09-13 05:09:28,700 [myid:] - INFO [main:QuorumBase@403] - Waiting for > QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled) to exit thread > 2016-09-13 05:09:29,738 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection$Messenger$WorkerReceiver@440] - > WorkerReceiver is down > 2016-09-13 05:09:29,738 [myid:0] - INFO > [WorkerSender[myid=0]:FastLeaderElection$Messenger$WorkerSender@470] - > WorkerSender is down > 2016-09-13 05:09:29,776 [myid:1] - INFO > [WorkerReceiver[myid=1]:FastLeaderElection$Messenger$WorkerReceiver@440] - > WorkerReceiver is down > 2016-09-13 05:09:29,785 [myid:3] - INFO > [WorkerSender[myid=3]:FastLeaderElection$Messenger$WorkerSender@470] - > WorkerSender is down > 2016-09-13 05:09:29,785 [myid:1] - INFO > [WorkerSender[myid=1]:FastLeaderElection$Messenger$WorkerSender@470] - > WorkerSender is down > 2016-09-13 05:09:29,789 [myid:2] - INFO > [WorkerReceiver[myid=2]:FastLeaderElection$Messenger$WorkerReceiver@440] - > WorkerReceiver is down > 2016-09-13 05:09:29,790 [myid:2] - INFO > [WorkerSender[myid=2]:FastLeaderElection$Messenger$WorkerSender@470] - > WorkerSender is down > 2016-09-13 05:09:29,792 [myid:3] - INFO > [WorkerReceiver[myid=3]:FastLeaderElection$Messenger$WorkerReceiver@440] - > WorkerReceiver is down > 2016-09-13 05:09:29,922 [myid:0] - INFO > [WorkerSender[myid=0]:FastLeaderElection$Messenger$WorkerSender@470] - > WorkerSender is down > 2016-09-13 05:09:29,923 [myid:0] - INFO > [WorkerReceiver[myid=0]:FastLeaderElection$Messenger$WorkerReceiver@440] - > WorkerReceiver is down > 2016-09-13 05:09:30,255 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=Follower] > 2016-09-13 05:09:30,256 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Follower@198] - > shutdown called > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115) > 2016-09-13 05:09:30,256 [myid:0] - WARN > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1158] > - PeerState set to LOOKING > 2016-09-13 05:09:30,256 [myid:0] - WARN > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1140] > - QuorumPeer main thread exited > 2016-09-13 05:09:30,256 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id0] > 2016-09-13 05:09:30,256 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0] > 2016-09-13 05:09:30,256 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.1] > 2016-09-13 05:09:30,257 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.2] > 2016-09-13 05:09:30,257 [myid:0] - INFO > [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.3] > 2016-09-13 05:09:30,258 [myid:] - INFO [main:QuorumBase@394] - Shutting down > quorum peer QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled) > 2016-09-13 05:09:30,258 [myid:] - INFO [main:Follower@198] - shutdown called > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198) > at > org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:1184) > at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.shutdown(QuorumPeerTestBase.java:60) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.shutdown(QuorumPeerTestBase.java:257) > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tearDown(ReconfigDuringLeaderSyncTest.java:189) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33) > at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.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] - shutting > down > 2016-09-13 05:09:30,259 [myid:] - INFO [main:FollowerRequestProcessor@138] - > Shutting down > 2016-09-13 05:09:30,259 [myid:] - INFO [main:CommitProcessor@414] - Shutting > down > 2016-09-13 05:09:30,259 [myid:1] - INFO > [FollowerRequestProcessor:1:FollowerRequestProcessor@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:CommitProcessor@299] - CommitProcessor exited loop! > 2016-09-13 05:09:30,260 [myid:] - INFO [main:MBeanRegistry@128] - Unregister > MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower,name3=InMemoryDataTree] > 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:SyncRequestProcessor@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:30,261 [myid:1] - INFO > [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - > ConnnectionExpirerThread interrupted > 2016-09-13 05:09:30,261 [myid:1] - INFO > [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13918:NIOServerCnxnFactory$AcceptThread@219] > - accept thread exitted run method > 2016-09-13 05:09:30,261 [myid:1] - INFO > [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420] > - selector thread exitted run method > 2016-09-13 05:09:30,261 [myid:1] - INFO > [/127.0.0.1:13920:QuorumCnxManager$Listener@661] - Leaving listener > 2016-09-13 05:09:30,261 [myid:] - INFO [main:QuorumBase@398] - Shutting down > leader election QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled) > 2016-09-13 05:09:30,262 [myid:] - INFO [main:QuorumBase@403] - Waiting for > QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled) to exit thread > 2016-09-13 05:09:30,624 [myid:127.0.0.1:13915] - INFO > [main-SendThread(127.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 SASL (unknown error) > 2016-09-13 05:09:30,624 [myid:127.0.0.1:13915] - WARN > [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1235] - Session > 0x483fd50000 for server 127.0.0.1/127.0.0.1:13915, unexpected error, closing > socket connection and attempting reconnect > java.net.ConnectException: Connection refused > at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > at > sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744) > at > org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:357) > at 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(127.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 SASL (unknown error) > 2016-09-13 05:09:31,734 [myid:127.0.0.1:13915] - WARN > [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1235] - Session > 0x483fd50000 for server 127.0.0.1/127.0.0.1:13915, unexpected error, closing > socket connection and attempting reconnect > java.net.ConnectException: Connection refused > at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > at > sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744) > at > org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:357) > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1214) > 2016-09-13 05:09:32,255 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower] > 2016-09-13 05:09:32,256 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Follower@198] - > shutdown called > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115) > 2016-09-13 05:09:32,256 [myid:1] - WARN > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1158] > - PeerState set to LOOKING > 2016-09-13 05:09:32,256 [myid:1] - WARN > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1140] > - QuorumPeer main thread exited > 2016-09-13 05:09:32,256 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1] > 2016-09-13 05:09:32,257 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1] > 2016-09-13 05:09:32,257 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.0] > 2016-09-13 05:09:32,257 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.2] > 2016-09-13 05:09:32,257 [myid:1] - INFO > [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.3] > 2016-09-13 05:09:32,257 [myid:] - INFO [main:QuorumBase@394] - Shutting down > quorum peer QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled) > 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 called > java.lang.Exception: shutdown Leader! reason: quorum Peer shutdown > at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:629) > at > org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:1181) > at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.shutdown(QuorumPeerTestBase.java:60) > at > org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.shutdown(QuorumPeerTestBase.java:257) > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tearDown(ReconfigDuringLeaderSyncTest.java:189) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33) > at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033) > 2016-09-13 05:09:32,259 [myid:] - INFO [main:ZooKeeperServer@529] - shutting > down > 2016-09-13 05:09:32,259 [myid:] - INFO [main:SessionTrackerImpl@232] - > Shutting 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] - Shutting > down > 2016-09-13 05:09:32,260 [myid:2] - INFO > [CommitProcessor:2:CommitProcessor@299] - CommitProcessor exited loop! > 2016-09-13 05:09:32,260 [myid:] - INFO > [main:Leader$ToBeAppliedRequestProcessor@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:SyncRequestProcessor@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:32,262 [myid:2] - INFO > [LearnerCnxAcceptor-/127.0.0.1:13922:Leader$LearnerCnxAcceptor@373] - > exception while shutting down acceptor: java.net.SocketException: Socket > closed > 2016-09-13 05:09:32,263 [myid:] - INFO [main:MBeanRegistry@128] - Unregister > MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=InMemoryDataTree] > 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=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Follower@93] > - Exception when following the leader > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:392) > at > org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63) > at > org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83) > at > org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99) > at > org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155) > at > org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:89) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111) > 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=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower] > 2016-09-13 05:09:32,265 [myid:2] - WARN > [LearnerHandler-/127.0.0.1:39104:LearnerHandler@903] - Ignoring unexpected > exception > java.lang.InterruptedException > at > java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1219) > at > java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340) > at > java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:338) > at > org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:901) > at > org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:622) > 2016-09-13 05:09:32,265 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Follower@198] > - shutdown called > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115) > 2016-09-13 05:09:32,266 [myid:2] - INFO > [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13921:NIOServerCnxnFactory$AcceptThread@219] > - accept thread exitted run method > 2016-09-13 05:09:32,266 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower,name3=Connections,name4=127.0.0.1,name5=0x3000048422c0000] > 2016-09-13 05:09:32,266 [myid:2] - INFO > [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420] > - selector thread exitted run method > 2016-09-13 05:09:32,266 [myid:2] - INFO > [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - > ConnnectionExpirerThread interrupted > 2016-09-13 05:09:32,266 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):NIOServerCnxn@607] > - Closed socket connection for client /127.0.0.1:50397 which had sessionid > 0x3000048422c0000 > 2016-09-13 05:09:32,267 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):LearnerZooKeeperServer@165] > - Shutting down > 2016-09-13 05:09:32,267 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):ZooKeeperServer@529] > - shutting down > 2016-09-13 05:09:32,267 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FollowerRequestProcessor@138] > - Shutting down > 2016-09-13 05:09:32,267 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):CommitProcessor@414] > - Shutting down > 2016-09-13 05:09:32,267 [myid:127.0.0.1:13924] - INFO > [main-SendThread(127.0.0.1:13924):ClientCnxn$SendThread@1231] - Unable to > read additional data 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:FollowerRequestProcessor@109] - > FollowerRequestProcessor exited loop! > 2016-09-13 05:09:32,268 [myid:3] - INFO > [CommitProcessor:3:CommitProcessor@299] - CommitProcessor exited loop! > 2016-09-13 05:09:32,268 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FinalRequestProcessor@479] > - shutdown of request processor complete > 2016-09-13 05:09:32,269 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower,name3=InMemoryDataTree] > 2016-09-13 05:09:32,269 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):SyncRequestProcessor@191] > - Shutting down > 2016-09-13 05:09:32,269 [myid:3] - INFO > [SyncThread:3:SyncRequestProcessor@169] - SyncRequestProcessor exited! > 2016-09-13 05:09:32,269 [myid:3] - WARN > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1158] > - PeerState set to LOOKING > 2016-09-13 05:09:32,269 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1033] > - LOOKING > 2016-09-13 05:09:32,270 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FileSnap@83] > - Reading snapshot > /home/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=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader] > 2016-09-13 05:09:32,272 [myid:2] - WARN > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1127] > - Unexpected exception > java.lang.InterruptedException > at java.lang.Object.wait(Native Method) > at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:561) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1124) > 2016-09-13 05:09:32,272 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@623] - > Shutting down > 2016-09-13 05:09:32,272 [myid:2] - WARN > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1158] > - PeerState set to LOOKING > 2016-09-13 05:09:32,272 [myid:2] - WARN > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1140] > - QuorumPeer main thread exited > 2016-09-13 05:09:32,272 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id2] > 2016-09-13 05:09:32,272 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2] > 2016-09-13 05:09:32,272 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.0] > 2016-09-13 05:09:32,273 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.1] > 2016-09-13 05:09:32,273 [myid:2] - INFO > [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.3] > 2016-09-13 05:09:32,274 [myid:2] - INFO > [/127.0.0.1:13923:QuorumCnxManager$Listener@661] - Leaving listener > 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@398] - Shutting down > leader election QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled) > 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@403] - Waiting for > QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled) to exit thread > 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@394] - Shutting down > quorum peer QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled) > 2016-09-13 05:09:32,275 [myid:3] - INFO > [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - > ConnnectionExpirerThread interrupted > 2016-09-13 05:09:32,275 [myid:3] - INFO > [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:13924:NIOServerCnxnFactory$AcceptThread@219] > - accept thread exitted run method > 2016-09-13 05:09:32,276 [myid:3] - INFO > [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420] > - selector thread exitted run method > 2016-09-13 05:09:32,276 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FastLeaderElection@894] > - New election. My id = 3, proposed zxid=0x100000004 > 2016-09-13 05:09:32,277 [myid:3] - WARN > [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 0 at > election address /127.0.0.1:13917 > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at > java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) > at > java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) > at > java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > at java.net.Socket.connect(Socket.java:579) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:482) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465) > at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,277 [myid:3] - INFO > [/127.0.0.1:13926:QuorumCnxManager$Listener@661] - Leaving listener > 2016-09-13 05:09:32,277 [myid:3] - WARN > [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 0 at > election address /127.0.0.1:13917 > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at > java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) > at > java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) > at > java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > at java.net.Socket.connect(Socket.java:579) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:489) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465) > at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,278 [myid:3] - WARN > [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 1 at > election address /127.0.0.1:13920 > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at > java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) > at > java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) > at > java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > at java.net.Socket.connect(Socket.java:579) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:482) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465) > at 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=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled) > 2016-09-13 05:09:32,279 [myid:] - INFO [main:QuorumBase@403] - Waiting for > QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled) to exit > thread > 2016-09-13 05:09:32,279 [myid:3] - WARN > [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 1 at > election address /127.0.0.1:13920 > java.net.ConnectException: Connection refused > at java.net.PlainSocketImpl.socketConnect(Native Method) > at > java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) > at > java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) > at > java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) > at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) > at java.net.Socket.connect(Socket.java:579) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:489) > at > org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486) > at > org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465) > at java.lang.Thread.run(Thread.java:745) > 2016-09-13 05:09:32,280 [myid:3] - INFO > [WorkerSender[myid=3]:FastLeaderElection$Messenger$WorkerSender@470] - > WorkerSender is down > 2016-09-13 05:09:32,280 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=LeaderElection] > 2016-09-13 05:09:32,280 [myid:3] - WARN > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1140] > - QuorumPeer main thread exited > 2016-09-13 05:09:32,280 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id3] > 2016-09-13 05:09:32,280 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3] > 2016-09-13 05:09:32,281 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.0] > 2016-09-13 05:09:32,281 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.1] > 2016-09-13 05:09:32,281 [myid:3] - INFO > [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128] > - Unregister MBean > [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.2] > 2016-09-13 05:09:32,283 [myid:] - INFO [main:ZKTestCase$1@70] - FAILED > testDuringLeaderSync > java.lang.AssertionError: zoo.cfg.dynamic.next is not deleted. > at org.junit.Assert.fail(Assert.java:88) > at org.junit.Assert.assertTrue(Assert.java:41) > at org.junit.Assert.assertFalse(Assert.java:64) > at > org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at > org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79) > at > org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) > at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182) > at > org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.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)