[ZOOKEEPER-2577] Flaky Test: org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync

• Type: Test
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 3.5.2
• Fix Version/s: 3.5.4, 3.6.0
• Component/s: tests
• Labels: flaky flaky-test
• Assignee: Michael Han
• Reporter: Michael Han
• Created: 13/Sep/16 18:33
• Updated: 27/Jul/17 21:45
• Resolved: 27/Jul/17 21:14

Description

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

Issue Links

• relates to: ZOOKEEPER-2135 fix trunk build
• links to: GitHub Pull Request #315