[
https://issues.apache.org/jira/browse/ZOOKEEPER-2577?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Michael Han updated ZOOKEEPER-2577:
-----------------------------------
Issue Type: Test (was: Bug)
> Flaky Test:
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync
> ------------------------------------------------------------------------------------------------
>
> Key: ZOOKEEPER-2577
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2577
> Project: ZooKeeper
> Issue Type: Test
> Components: tests
> Affects Versions: 3.5.2
> Reporter: Michael Han
> Labels: flaky, flaky-test
> Fix For: 3.6.0
>
>
> This failure is new and consistent on jdk7/8 with trunk branch - happened
> after build 3070 recently. Not sure if this is caused by svn - git migration
> or not.
> {noformat}
> Error Message
> zoo.cfg.dynamic.next is not deleted.
> Stacktrace
> junit.framework.AssertionFailedError: zoo.cfg.dynamic.next is not deleted.
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155)
> at
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> Standard Output
> 2016-09-13 05:09:25,247 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No
> test.method specified. using default methods.
> 2016-09-13 05:09:25,349 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No
> test.method specified. using default methods.
> 2016-09-13 05:09:25,370 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING
> testDuringLeaderSync
> 2016-09-13 05:09:25,372 [myid:] - INFO
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD
> testDuringLeaderSync
> 2016-09-13 05:09:25,375 [myid:] - INFO [main:PortAssignment@151] - Test
> process 2/8 using ports from 13914 - 16606.
> 2016-09-13 05:09:25,380 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13915 from range 13914 - 16606.
> 2016-09-13 05:09:25,380 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13916 from range 13914 - 16606.
> 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13917 from range 13914 - 16606.
> 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13918 from range 13914 - 16606.
> 2016-09-13 05:09:25,381 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13919 from range 13914 - 16606.
> 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13920 from range 13914 - 16606.
> 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13921 from range 13914 - 16606.
> 2016-09-13 05:09:25,382 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13922 from range 13914 - 16606.
> 2016-09-13 05:09:25,383 [myid:] - INFO [main:PortAssignment@85] - Assigned
> port 13923 from range 13914 - 16606.
> 2016-09-13 05:09:25,406 [myid:] - INFO
> [main:QuorumPeerTestBase$MainThread@131] - id = 0 tmpDir =
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir
> clientPort = 13915 adminServerPort = 8080
> 2016-09-13 05:09:25,416 [myid:] - INFO
> [main:QuorumPeerTestBase$MainThread@131] - id = 1 tmpDir =
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir
> clientPort = 13918 adminServerPort = 8080
> 2016-09-13 05:09:25,420 [myid:] - INFO
> [main:QuorumPeerTestBase$MainThread@131] - id = 2 tmpDir =
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir
> clientPort = 13921 adminServerPort = 8080
> 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-0:QuorumPeerConfig@116] -
> Reading configuration from:
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/zoo.cfg
> 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-2:QuorumPeerConfig@116] -
> Reading configuration from:
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/zoo.cfg
> 2016-09-13 05:09:25,422 [myid:] - INFO [Thread-1:QuorumPeerConfig@116] -
> Reading configuration from:
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/zoo.cfg
> 2016-09-13 05:09:25,424 [myid:] - INFO [main:FourLetterWordMain@85] -
> connecting to 127.0.0.1 13915
> 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-0:QuorumPeerConfig@318] -
> clientPortAddress is 0.0.0.0/0.0.0.0:13915
> 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-0:QuorumPeerConfig@322] -
> secureClientPort is not set
> 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-1:QuorumPeerConfig@318] -
> clientPortAddress is 0.0.0.0/0.0.0.0:13918
> 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-1:QuorumPeerConfig@322] -
> secureClientPort is not set
> 2016-09-13 05:09:25,425 [myid:] - INFO [Thread-2:QuorumPeerConfig@318] -
> clientPortAddress is 0.0.0.0/0.0.0.0:13921
> 2016-09-13 05:09:25,426 [myid:] - INFO [Thread-2:QuorumPeerConfig@322] -
> secureClientPort is not set
> 2016-09-13 05:09:25,430 [myid:] - INFO [main:ClientBase@248] - server
> 127.0.0.1:13915 not up
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
> at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
> at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:579)
> at
> org.apache.zookeeper.client.FourLetterWordMain.send4LetterWord(FourLetterWordMain.java:99)
> at
> org.apache.zookeeper.client.FourLetterWordMain.send4LetterWord(FourLetterWordMain.java:69)
> at
> org.apache.zookeeper.test.ClientBase.waitForServerUp(ClientBase.java:241)
> at
> org.apache.zookeeper.test.ClientBase.waitForServerUp(ClientBase.java:232)
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:85)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)
> 2016-09-13 05:09:25,444 [myid:1] - INFO [Thread-1:DatadirCleanupManager@78]
> - autopurge.snapRetainCount set to 3
> 2016-09-13 05:09:25,445 [myid:2] - INFO [Thread-2:DatadirCleanupManager@78]
> - autopurge.snapRetainCount set to 3
> 2016-09-13 05:09:25,445 [myid:2] - INFO [Thread-2:DatadirCleanupManager@79]
> - autopurge.purgeInterval set to 0
> 2016-09-13 05:09:25,444 [myid:0] - INFO [Thread-0:DatadirCleanupManager@78]
> - autopurge.snapRetainCount set to 3
> 2016-09-13 05:09:25,445 [myid:2] - INFO [Thread-2:DatadirCleanupManager@101]
> - Purge task is not scheduled.
> 2016-09-13 05:09:25,445 [myid:1] - INFO [Thread-1:DatadirCleanupManager@79]
> - autopurge.purgeInterval set to 0
> 2016-09-13 05:09:25,446 [myid:1] - INFO [Thread-1:DatadirCleanupManager@101]
> - Purge task is not scheduled.
> 2016-09-13 05:09:25,445 [myid:0] - INFO [Thread-0:DatadirCleanupManager@79]
> - autopurge.purgeInterval set to 0
> 2016-09-13 05:09:25,446 [myid:0] - INFO [Thread-0:DatadirCleanupManager@101]
> - Purge task is not scheduled.
> 2016-09-13 05:09:25,446 [myid:2] - INFO [Thread-2:ManagedUtil@46] - Log4j
> found with jmx enabled.
> 2016-09-13 05:09:25,447 [myid:0] - INFO [Thread-0:ManagedUtil@46] - Log4j
> found with jmx enabled.
> 2016-09-13 05:09:25,446 [myid:1] - INFO [Thread-1:ManagedUtil@46] - Log4j
> found with jmx enabled.
> 2016-09-13 05:09:25,552 [myid:1] - ERROR [Thread-1:ManagedUtil@114] -
> Problems while registering log4j jmx beans!
> javax.management.InstanceAlreadyExistsException: log4j:hiearchy=default
> at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
> at
> com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
> at
> org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:75)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:25,552 [myid:1] - WARN [Thread-1:QuorumPeerMain@133] -
> Unable to register log4j JMX control
> javax.management.JMException:
> javax.management.InstanceAlreadyExistsException: log4j:hiearchy=default
> at
> org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:115)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:25,553 [myid:1] - INFO [Thread-1:QuorumPeerMain@136] -
> Starting quorum peer
> 2016-09-13 05:09:25,553 [myid:2] - ERROR [Thread-2:HierarchyDynamicMBean@138]
> - Could not add loggerMBean for [root].
> javax.management.InstanceAlreadyExistsException: log4j:logger=root
> at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
> at
> com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
> at
> org.apache.log4j.jmx.AbstractDynamicMBean.registerMBean(AbstractDynamicMBean.java:160)
> at
> org.apache.log4j.jmx.HierarchyDynamicMBean.addLoggerMBean(HierarchyDynamicMBean.java:125)
> at
> org.apache.log4j.jmx.HierarchyDynamicMBean.postRegister(HierarchyDynamicMBean.java:263)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.postRegister(DefaultMBeanServerInterceptor.java:1024)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:974)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
> at
> com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
> at
> org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:75)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:25,559 [myid:0] - ERROR [Thread-0:ManagedUtil@114] -
> Problems while registering log4j jmx beans!
> javax.management.InstanceAlreadyExistsException: log4j:hiearchy=default
> at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
> at
> com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
> at
> com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
> at
> org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:75)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:25,560 [myid:0] - WARN [Thread-0:QuorumPeerMain@133] -
> Unable to register log4j JMX control
> javax.management.JMException:
> javax.management.InstanceAlreadyExistsException: log4j:hiearchy=default
> at
> org.apache.zookeeper.jmx.ManagedUtil.registerLog4jMBeans(ManagedUtil.java:115)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runFromConfig(QuorumPeerMain.java:131)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:120)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:25,560 [myid:0] - INFO [Thread-0:QuorumPeerMain@136] -
> Starting quorum peer
> 2016-09-13 05:09:25,562 [myid:2] - INFO [Thread-2:QuorumPeerMain@136] -
> Starting quorum peer
> 2016-09-13 05:09:25,581 [myid:0] - INFO [Thread-0:NIOServerCnxnFactory@673]
> - Configuring NIO connection handler with 10s sessionless connection timeout,
> 1 selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-09-13 05:09:25,581 [myid:2] - INFO [Thread-2:NIOServerCnxnFactory@673]
> - Configuring NIO connection handler with 10s sessionless connection timeout,
> 1 selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-09-13 05:09:25,585 [myid:1] - INFO [Thread-1:NIOServerCnxnFactory@673]
> - Configuring NIO connection handler with 10s sessionless connection timeout,
> 1 selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-09-13 05:09:25,591 [myid:0] - INFO [Thread-0:NIOServerCnxnFactory@686]
> - binding to port /127.0.0.1:13915
> 2016-09-13 05:09:25,592 [myid:1] - INFO [Thread-1:NIOServerCnxnFactory@686]
> - binding to port /127.0.0.1:13918
> 2016-09-13 05:09:25,593 [myid:2] - INFO [Thread-2:NIOServerCnxnFactory@686]
> - binding to port /127.0.0.1:13921
> 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1327] - Local
> sessions disabled
> 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1338] - Local
> session upgrading disabled
> 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1305] -
> tickTime set to 4000
> 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1349] -
> minSessionTimeout set to 8000
> 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1360] -
> maxSessionTimeout set to 80000
> 2016-09-13 05:09:25,622 [myid:1] - INFO [Thread-1:QuorumPeer@1327] - Local
> sessions disabled
> 2016-09-13 05:09:25,622 [myid:1] - INFO [Thread-1:QuorumPeer@1338] - Local
> session upgrading disabled
> 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1305] -
> tickTime set to 4000
> 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1349] -
> minSessionTimeout set to 8000
> 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1360] -
> maxSessionTimeout set to 80000
> 2016-09-13 05:09:25,623 [myid:1] - INFO [Thread-1:QuorumPeer@1375] -
> initLimit set to 10
> 2016-09-13 05:09:25,622 [myid:0] - INFO [Thread-0:QuorumPeer@1327] - Local
> sessions disabled
> 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1338] - Local
> session upgrading disabled
> 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1305] -
> tickTime set to 4000
> 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1349] -
> minSessionTimeout set to 8000
> 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1360] -
> maxSessionTimeout set to 80000
> 2016-09-13 05:09:25,625 [myid:0] - INFO [Thread-0:QuorumPeer@1375] -
> initLimit set to 10
> 2016-09-13 05:09:25,622 [myid:2] - INFO [Thread-2:QuorumPeer@1375] -
> initLimit set to 10
> 2016-09-13 05:09:25,666 [myid:0] - INFO [Thread-0:QuorumPeer@776] -
> currentEpoch not found! Creating with a reasonable default of 0. This should
> only happen when you are upgrading your installation
> 2016-09-13 05:09:25,668 [myid:1] - INFO [Thread-1:QuorumPeer@776] -
> currentEpoch not found! Creating with a reasonable default of 0. This should
> only happen when you are upgrading your installation
> 2016-09-13 05:09:25,668 [myid:2] - INFO [Thread-2:QuorumPeer@776] -
> currentEpoch not found! Creating with a reasonable default of 0. This should
> only happen when you are upgrading your installation
> 2016-09-13 05:09:25,669 [myid:0] - INFO [Thread-0:QuorumPeer@791] -
> acceptedEpoch not found! Creating with a reasonable default of 0. This should
> only happen when you are upgrading your installation
> 2016-09-13 05:09:25,672 [myid:1] - INFO [Thread-1:QuorumPeer@791] -
> acceptedEpoch not found! Creating with a reasonable default of 0. This should
> only happen when you are upgrading your installation
> 2016-09-13 05:09:25,677 [myid:2] - INFO [Thread-2:QuorumPeer@791] -
> acceptedEpoch not found! Creating with a reasonable default of 0. This should
> only happen when you are upgrading your installation
> 2016-09-13 05:09:25,689 [myid:] - INFO [main:FourLetterWordMain@85] -
> connecting to 127.0.0.1 13915
> 2016-09-13 05:09:25,704 [myid:0] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from /127.0.0.1:38366
> 2016-09-13 05:09:25,758 [myid:0] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing stat command from
> /127.0.0.1:38366
> 2016-09-13 05:09:25,770 [myid:1] - INFO
> [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port:
> /127.0.0.1:13920
> 2016-09-13 05:09:25,772 [myid:0] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@607] - Closed socket connection for client
> /127.0.0.1:38366 (no session established for client)
> 2016-09-13 05:09:25,783 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1033]
> - LOOKING
> 2016-09-13 05:09:25,785 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):FastLeaderElection@894]
> - New election. My id = 1, proposed zxid=0x0
> 2016-09-13 05:09:25,797 [myid:0] - INFO
> [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port:
> /127.0.0.1:13917
> 2016-09-13 05:09:25,798 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1033]
> - LOOKING
> 2016-09-13 05:09:25,798 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):FastLeaderElection@894]
> - New election. My id = 0, proposed zxid=0x0
> 2016-09-13 05:09:25,799 [myid:0] - INFO
> [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:53023
> 2016-09-13 05:09:25,806 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1033]
> - LOOKING
> 2016-09-13 05:09:25,806 [myid:2] - INFO
> [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port:
> /127.0.0.1:13923
> 2016-09-13 05:09:25,806 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):FastLeaderElection@894]
> - New election. My id = 2, proposed zxid=0x0
> 2016-09-13 05:09:25,825 [myid:2] - INFO
> [/127.0.0.1:13923:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:58679
> 2016-09-13 05:09:25,826 [myid:0] - INFO
> [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier,
> so dropping the connection: (2, 0)
> 2016-09-13 05:09:25,825 [myid:1] - INFO
> [WorkerSender[myid=1]:QuorumCnxManager@276] - Have smaller server identifier,
> so dropping the connection: (2, 1)
> 2016-09-13 05:09:25,827 [myid:0] - INFO
> [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:53026
> 2016-09-13 05:09:25,827 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message
> format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,827 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message
> format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,848 [myid:1] - INFO
> [/127.0.0.1:13920:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:46423
> 2016-09-13 05:09:25,848 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message
> format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,857 [myid:2] - INFO
> [/127.0.0.1:13923:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:58680
> 2016-09-13 05:09:25,857 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message
> format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,858 [myid:2] - WARN
> [RecvWorker:0:QuorumCnxManager$RecvWorker@915] - Connection broken for id 0,
> my id = 2, error =
> java.net.SocketException: Socket closed
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:152)
> at java.net.SocketInputStream.read(SocketInputStream.java:122)
> at java.net.SocketInputStream.read(SocketInputStream.java:210)
> at java.io.DataInputStream.readInt(DataInputStream.java:387)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900)
> 2016-09-13 05:09:25,858 [myid:2] - WARN
> [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:25,862 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message
> format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,863 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message
> format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,865 [myid:0] - WARN
> [SendWorker:2:QuorumCnxManager$SendWorker@837] - Exception when using
> channel: for id 2 my id = 0 error = java.net.SocketException: Broken pipe
> 2016-09-13 05:09:25,867 [myid:0] - WARN
> [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:25,898 [myid:2] - WARN
> [SendWorker:0:QuorumCnxManager$SendWorker@832] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820)
> 2016-09-13 05:09:25,898 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,898 [myid:2] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,899 [myid:0] - WARN
> [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 2 my id = 0
> 2016-09-13 05:09:25,899 [myid:2] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
> format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,900 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,901 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,901 [myid:0] - INFO
> [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:53028
> 2016-09-13 05:09:25,898 [myid:2] - WARN
> [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 0 my id = 2
> 2016-09-13 05:09:25,901 [myid:2] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 1 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,902 [myid:0] - INFO
> [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier,
> so dropping the connection: (2, 0)
> 2016-09-13 05:09:25,903 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,903 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,904 [myid:2] - INFO
> [/127.0.0.1:13923:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:58684
> 2016-09-13 05:09:25,905 [myid:2] - WARN
> [SendWorker:0:QuorumCnxManager$SendWorker@832] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820)
> 2016-09-13 05:09:25,905 [myid:2] - WARN
> [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 0 my id = 2
> 2016-09-13 05:09:25,905 [myid:2] - WARN
> [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:25,907 [myid:0] - WARN
> [SendWorker:2:QuorumCnxManager$SendWorker@837] - Exception when using
> channel: for id 2 my id = 0 error = java.net.SocketException: Broken pipe
> 2016-09-13 05:09:25,907 [myid:0] - INFO
> [/127.0.0.1:13917:QuorumCnxManager$Listener@638] - Received connection
> request /127.0.0.1:53030
> 2016-09-13 05:09:25,908 [myid:0] - WARN
> [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 2 my id = 0
> 2016-09-13 05:09:25,908 [myid:0] - WARN
> [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:25,909 [myid:2] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:25,910 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection@688] - Notification: 2 (message
> format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING
> (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config
> version)
> 2016-09-13 05:09:26,022 [myid:] - INFO [main:FourLetterWordMain@85] -
> connecting to 127.0.0.1 13915
> 2016-09-13 05:09:26,023 [myid:0] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from /127.0.0.1:38382
> 2016-09-13 05:09:26,032 [myid:0] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@485] - Processing stat command from
> /127.0.0.1:38382
> 2016-09-13 05:09:26,033 [myid:0] - INFO
> [NIOWorkerThread-2:NIOServerCnxn@607] - Closed socket connection for client
> /127.0.0.1:38382 (no session established for client)
> 2016-09-13 05:09:26,103 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
> 2016-09-13 05:09:26,104 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1109]
> - FOLLOWING
> 2016-09-13 05:09:26,109 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=LeaderElection]
> 2016-09-13 05:09:26,110 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@88] -
> TCP NoDelay set to: true
> 2016-09-13 05:09:26,110 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1121]
> - LEADING
> 2016-09-13 05:09:26,111 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=LeaderElection]
> 2016-09-13 05:09:26,111 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1109]
> - FOLLOWING
> 2016-09-13 05:09:26,113 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@63] - TCP
> NoDelay set to: true
> 2016-09-13 05:09:26,113 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@83] -
> zookeeper.leader.maxConcurrentSnapshots = 10
> 2016-09-13 05:09:26,113 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@85] -
> zookeeper.leader.maxConcurrentSnapshotTimeout = 5
> 2016-09-13 05:09:26,122 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:zookeeper.version=3.6.0-SNAPSHOT--1, built on 09/13/2016
> 05:08 GMT
> 2016-09-13 05:09:26,122 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:host.name=jenkins-test-5f3
> 2016-09-13 05:09:26,123 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:java.version=1.7.0_101
> 2016-09-13 05:09:26,123 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:java.vendor=Oracle Corporation
> 2016-09-13 05:09:26,123 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre
> 2016-09-13 05:09:26,123 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server
> environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-http-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-server-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-util-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/slf4j-log4j12-1.7.5.jar:/usr/local/asfpackages/ant/apache-ant-1.9.7/lib/ant-launcher.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools/ant/latest/lib/ant-junit4.jar
> 2016-09-13 05:09:26,123 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> 2016-09-13 05:09:26,123 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:java.io.tmpdir=/tmp
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:java.compiler=<NA>
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:os.name=Linux
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:os.arch=amd64
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:os.version=3.13.0-30-generic
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:user.name=jenkins
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:user.home=/home/jenkins
> 2016-09-13 05:09:26,124 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test
> 2016-09-13 05:09:26,125 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:os.memory.free=49MB
> 2016-09-13 05:09:26,125 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:os.memory.max=455MB
> 2016-09-13 05:09:26,125 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Environment@109]
> - Server environment:os.memory.total=60MB
> 2016-09-13 05:09:26,126 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ZooKeeperServer@889]
> - minSessionTimeout set to 8000
> 2016-09-13 05:09:26,127 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ZooKeeperServer@898]
> - maxSessionTimeout set to 80000
> 2016-09-13 05:09:26,127 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ZooKeeperServer@159]
> - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout
> 80000 datadir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/data/version-2
> snapdir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/data/version-2
> 2016-09-13 05:09:26,126 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):ZooKeeperServer@889]
> - minSessionTimeout set to 8000
> 2016-09-13 05:09:26,129 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):ZooKeeperServer@898]
> - maxSessionTimeout set to 80000
> 2016-09-13 05:09:26,129 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):ZooKeeperServer@159]
> - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout
> 80000 datadir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/data/version-2
> snapdir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/data/version-2
> 2016-09-13 05:09:26,129 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Follower@66] -
> FOLLOWING - LEADER ELECTION TOOK - 18 MS
> 2016-09-13 05:09:26,126 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):ZooKeeperServer@889]
> - minSessionTimeout set to 8000
> 2016-09-13 05:09:26,129 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@412] -
> LEADING - LEADER ELECTION TOOK - 20 MS
> 2016-09-13 05:09:26,140 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):FileTxnSnapLog@298]
> - Snapshotting: 0x0 to
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test5455612786130415623.junit.dir/data/version-2/snapshot.0
> 2016-09-13 05:09:26,137 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):ZooKeeperServer@898]
> - maxSessionTimeout set to 80000
> 2016-09-13 05:09:26,141 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):ZooKeeperServer@159]
> - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout
> 80000 datadir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/data/version-2
> snapdir
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/data/version-2
> 2016-09-13 05:09:26,141 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Follower@66] -
> FOLLOWING - LEADER ELECTION TOOK - 37 MS
> 2016-09-13 05:09:26,185 [myid:2] - INFO
> [LearnerHandler-/127.0.0.1:39078:LearnerHandler@382] - Follower sid: 0 : info
> : 127.0.0.1:13916:13917:participant;127.0.0.1:13915
> 2016-09-13 05:09:26,191 [myid:2] - INFO
> [LearnerHandler-/127.0.0.1:39079:LearnerHandler@382] - Follower sid: 1 : info
> : 127.0.0.1:13919:13920:participant;127.0.0.1:13918
> 2016-09-13 05:09:26,198 [myid:2] - INFO
> [LearnerHandler-/127.0.0.1:39079:LearnerHandler@683] - Synchronizing with
> Follower sid: 1 maxCommittedLog=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0
> peerLastZxid=0x0
> 2016-09-13 05:09:26,198 [myid:2] - INFO
> [LearnerHandler-/127.0.0.1:39079:LearnerHandler@727] - Sending DIFF zxid=0x0
> for peer sid: 1
> 2016-09-13 05:09:26,198 [myid:2] - INFO
> [LearnerHandler-/127.0.0.1:39078:LearnerHandler@683] - Synchronizing with
> Follower sid: 0 maxCommittedLog=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0
> peerLastZxid=0x0
> 2016-09-13 05:09:26,199 [myid:2] - INFO
> [LearnerHandler-/127.0.0.1:39078:LearnerHandler@727] - Sending DIFF zxid=0x0
> for peer sid: 0
> 2016-09-13 05:09:26,201 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@366] -
> Getting a diff from the leader 0x0
> 2016-09-13 05:09:26,206 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@509] -
> Learner received NEWLEADER message
> 2016-09-13 05:09:26,209 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):FileTxnSnapLog@298]
> - Snapshotting: 0x0 to
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1768888919429940621.junit.dir/data/version-2/snapshot.0
> 2016-09-13 05:09:26,210 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Learner@366] -
> Getting a diff from the leader 0x0
> 2016-09-13 05:09:26,211 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Learner@509] -
> Learner received NEWLEADER message
> 2016-09-13 05:09:26,213 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@1255] -
> Have quorum of supporters, sids: [ [1, 2],[1, 2] ]; starting up and setting
> last processed zxid: 0x100000000
> 2016-09-13 05:09:26,215 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):FileTxnSnapLog@298]
> - Snapshotting: 0x0 to
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test8397079557861207505.junit.dir/data/version-2/snapshot.0
> 2016-09-13 05:09:26,238 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):CommitProcessor@318]
> - Configuring CommitProcessor with 4 worker threads.
> 2016-09-13 05:09:26,252 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):ContainerManager@64]
> - Using checkIntervalMs=60000 maxPerMinute=10000
> 2016-09-13 05:09:26,254 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Learner@493] -
> Learner received UPTODATE message
> 2016-09-13 05:09:26,254 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Learner@493] -
> Learner received UPTODATE message
> 2016-09-13 05:09:26,266 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):CommitProcessor@318]
> - Configuring CommitProcessor with 4 worker threads.
> 2016-09-13 05:09:26,272 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):CommitProcessor@318]
> - Configuring CommitProcessor with 4 worker threads.
> 2016-09-13 05:09:26,283 [myid:] - INFO [main:FourLetterWordMain@85] -
> connecting to 127.0.0.1 13915
> 2016-09-13 05:09:26,284 [myid:0] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from /127.0.0.1:38385
> 2016-09-13 05:09:26,285 [myid:0] - INFO
> [NIOWorkerThread-3:NIOServerCnxn@485] - Processing stat command from
> /127.0.0.1:38385
> 2016-09-13 05:09:26,286 [myid:0] - INFO [NIOWorkerThread-3:StatCommand@49] -
> Stat command output
> 2016-09-13 05:09:26,287 [myid:0] - INFO
> [NIOWorkerThread-3:NIOServerCnxn@607] - Closed socket connection for client
> /127.0.0.1:38385 (no session established for client)
> 2016-09-13 05:09:26,288 [myid:] - INFO [main:FourLetterWordMain@85] -
> connecting to 127.0.0.1 13918
> 2016-09-13 05:09:26,288 [myid:1] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13918:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from /127.0.0.1:55309
> 2016-09-13 05:09:26,291 [myid:1] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing stat command from
> /127.0.0.1:55309
> 2016-09-13 05:09:26,291 [myid:1] - INFO [NIOWorkerThread-1:StatCommand@49] -
> Stat command output
> 2016-09-13 05:09:26,292 [myid:1] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@607] - Closed socket connection for client
> /127.0.0.1:55309 (no session established for client)
> 2016-09-13 05:09:26,292 [myid:] - INFO [main:FourLetterWordMain@85] -
> connecting to 127.0.0.1 13921
> 2016-09-13 05:09:26,293 [myid:2] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13921:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from /127.0.0.1:45002
> 2016-09-13 05:09:26,297 [myid:2] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@485] - Processing stat command from
> /127.0.0.1:45002
> 2016-09-13 05:09:26,297 [myid:2] - INFO [NIOWorkerThread-1:StatCommand@49] -
> Stat command output
> 2016-09-13 05:09:26,298 [myid:2] - INFO
> [NIOWorkerThread-1:NIOServerCnxn@607] - Closed socket connection for client
> /127.0.0.1:45002 (no session established for client)
> 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client
> environment:zookeeper.version=3.6.0-SNAPSHOT--1, built on 09/13/2016 05:08 GMT
> 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client
> environment:host.name=jenkins-test-5f3
> 2016-09-13 05:09:26,304 [myid:] - INFO [main:Environment@109] - Client
> environment:java.version=1.7.0_101
> 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client
> environment:java.vendor=Oracle Corporation
> 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client
> environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre
> 2016-09-13 05:09:26,305 [myid:] - INFO [main:Environment@109] - Client
> environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-http-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-server-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jetty-util-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/lib/netty-3.10.5.Final.
> ...[truncated 31909 chars]...
> 3] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@915] - Connection broken
> for id 1, my id = 3, error =
> java.io.EOFException
> at java.io.DataInputStream.readInt(DataInputStream.java:392)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900)
> 2016-09-13 05:09:26,894 [myid:3] - WARN
> [RecvWorker:1:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:26,894 [myid:3] - WARN
> [SendWorker:1:QuorumCnxManager$SendWorker@832] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820)
> 2016-09-13 05:09:26,894 [myid:3] - WARN
> [SendWorker:1:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 1 my id = 3
> 2016-09-13 05:09:26,895 [myid:1] - WARN
> [RecvWorker:3:QuorumCnxManager$RecvWorker@915] - Connection broken for id 3,
> my id = 1, error =
> java.net.SocketException: Socket closed
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:152)
> at java.net.SocketInputStream.read(SocketInputStream.java:122)
> at java.net.SocketInputStream.read(SocketInputStream.java:210)
> at java.io.DataInputStream.readInt(DataInputStream.java:387)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900)
> 2016-09-13 05:09:26,895 [myid:1] - WARN
> [RecvWorker:3:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:26,895 [myid:1] - WARN
> [SendWorker:3:QuorumCnxManager$SendWorker@832] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820)
> 2016-09-13 05:09:26,896 [myid:1] - WARN
> [SendWorker:3:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 3 my id = 1
> 2016-09-13 05:09:26,905 [myid:0] - WARN
> [SendWorker:1:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 1 my id = 0
> 2016-09-13 05:09:26,905 [myid:0] - WARN
> [RecvWorker:3:QuorumCnxManager$RecvWorker@915] - Connection broken for id 3,
> my id = 0, error =
> java.net.SocketException: Socket closed
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:152)
> at java.net.SocketInputStream.read(SocketInputStream.java:122)
> at java.net.SocketInputStream.read(SocketInputStream.java:210)
> at java.io.DataInputStream.readInt(DataInputStream.java:387)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900)
> 2016-09-13 05:09:26,906 [myid:0] - WARN
> [RecvWorker:3:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:26,905 [myid:3] - WARN
> [RecvWorker:0:QuorumCnxManager$RecvWorker@915] - Connection broken for id 0,
> my id = 3, error =
> java.io.EOFException
> at java.io.DataInputStream.readInt(DataInputStream.java:392)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:900)
> 2016-09-13 05:09:26,906 [myid:3] - WARN
> [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
> 2016-09-13 05:09:26,905 [myid:0] - WARN
> [SendWorker:3:QuorumCnxManager$SendWorker@832] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820)
> 2016-09-13 05:09:26,913 [myid:3] - WARN
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Learner@417]
> - Got zxid 0x100000002 expected 0x1
> 2016-09-13 05:09:26,917 [myid:3] - WARN
> [SendWorker:0:QuorumCnxManager$SendWorker@832] - Interrupted while waiting
> for message on queue
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095)
> at
> java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:982)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:820)
> 2016-09-13 05:09:26,918 [myid:3] - WARN
> [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 0 my id = 3
> 2016-09-13 05:09:26,917 [myid:0] - WARN
> [SendWorker:3:QuorumCnxManager$SendWorker@841] - Send worker leaving thread
> id 3 my id = 0
> 2016-09-13 05:09:26,917 [myid:1] - INFO
> [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port:
> /127.0.0.1:13920
> 2016-09-13 05:09:26,919 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1481]
> - writeToDisk == true but configFilename == null
> 2016-09-13 05:09:26,920 [myid:3] - WARN
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1417]
> - Restarting Leader Election
> 2016-09-13 05:09:26,920 [myid:3] - INFO
> [/127.0.0.1:13926:QuorumCnxManager$Listener@661] - Leaving listener
> 2016-09-13 05:09:26,922 [myid:0] - INFO
> [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port:
> /127.0.0.1:13917
> 2016-09-13 05:09:26,936 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Learner@493]
> - Learner received UPTODATE message
> 2016-09-13 05:09:26,936 [myid:3] - INFO
> [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port:
> /127.0.0.1:13926
> 2016-09-13 05:09:27,036 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):CommitProcessor@318]
> - Configuring CommitProcessor with 4 worker threads.
> 2016-09-13 05:09:27,061 [myid:3] - INFO [SyncThread:3:FileTxnLog@204] -
> Creating new log file: log.100000002
> 2016-09-13 05:09:28,635 [myid:127.0.0.1:13924] - INFO
> [main-SendThread(127.0.0.1:13924):ClientCnxn$SendThread@1113] - Opening
> socket connection to server 127.0.0.1/127.0.0.1:13924. Will not attempt to
> authenticate using SASL (unknown error)
> 2016-09-13 05:09:28,635 [myid:127.0.0.1:13924] - INFO
> [main-SendThread(127.0.0.1:13924):ClientCnxn$SendThread@948] - Socket
> connection established, initiating session, client: /127.0.0.1:50397, server:
> 127.0.0.1/127.0.0.1:13924
> 2016-09-13 05:09:28,636 [myid:3] - INFO
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:13924:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from /127.0.0.1:50397
> 2016-09-13 05:09:28,651 [myid:3] - INFO
> [NIOWorkerThread-2:ZooKeeperServer@995] - Client attempting to establish new
> session at /127.0.0.1:50397
> 2016-09-13 05:09:28,652 [myid:3] - WARN
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Follower@122]
> - Got zxid 0x100000003 expected 0x1
> 2016-09-13 05:09:28,654 [myid:3] - INFO
> [CommitProcWorkThread-1:ZooKeeperServer@709] - Established session
> 0x3000048422c0000 with negotiated timeout 30000 for client /127.0.0.1:50397
> 2016-09-13 05:09:28,661 [myid:127.0.0.1:13924] - INFO
> [main-SendThread(127.0.0.1:13924):ClientCnxn$SendThread@1381] - Session
> establishment complete on server 127.0.0.1/127.0.0.1:13924, sessionid =
> 0x3000048422c0000, negotiated timeout = 30000
> 2016-09-13 05:09:28,690 [myid:] - INFO
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@98] - TEST METHOD FAILED
> testDuringLeaderSync
> java.lang.AssertionError: zoo.cfg.dynamic.next is not deleted.
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.assertTrue(Assert.java:41)
> at org.junit.Assert.assertFalse(Assert.java:64)
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)
> 2016-09-13 05:09:28,692 [myid:] - INFO [main:QuorumBase@394] - Shutting down
> quorum peer QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled)
> 2016-09-13 05:09:28,692 [myid:] - INFO [main:Follower@198] - shutdown called
> java.lang.Exception: shutdown Follower
> at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:1184)
> at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.shutdown(QuorumPeerTestBase.java:60)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.shutdown(QuorumPeerTestBase.java:257)
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tearDown(ReconfigDuringLeaderSyncTest.java:189)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
> at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)
> 2016-09-13 05:09:28,693 [myid:] - INFO [main:MBeanRegistry@128] - Unregister
> MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=Follower,name3=Connections,name4=127.0.0.1,name5=0x483fd50000]
> 2016-09-13 05:09:28,694 [myid:] - INFO [main:NIOServerCnxn@607] - Closed
> socket connection for client /127.0.0.1:38389 which had sessionid 0x483fd50000
> 2016-09-13 05:09:28,694 [myid:] - INFO [main:LearnerZooKeeperServer@165] -
> Shutting down
> 2016-09-13 05:09:28,694 [myid:] - INFO [main:ZooKeeperServer@529] - shutting
> down
> 2016-09-13 05:09:28,694 [myid:] - INFO [main:FollowerRequestProcessor@138] -
> Shutting down
> 2016-09-13 05:09:28,695 [myid:127.0.0.1:13915] - INFO
> [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1231] - Unable to
> read additional data from server sessionid 0x483fd50000, likely server has
> closed socket, closing socket connection and attempting reconnect
> 2016-09-13 05:09:28,695 [myid:] - INFO [main:CommitProcessor@414] - Shutting
> down
> 2016-09-13 05:09:28,695 [myid:0] - INFO
> [FollowerRequestProcessor:0:FollowerRequestProcessor@109] -
> FollowerRequestProcessor exited loop!
> 2016-09-13 05:09:28,696 [myid:0] - INFO
> [CommitProcessor:0:CommitProcessor@299] - CommitProcessor exited loop!
> 2016-09-13 05:09:28,696 [myid:] - INFO [main:FinalRequestProcessor@479] -
> shutdown of request processor complete
> 2016-09-13 05:09:28,697 [myid:] - INFO [main:MBeanRegistry@128] - Unregister
> MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=Follower,name3=InMemoryDataTree]
> 2016-09-13 05:09:28,697 [myid:] - INFO [main:SyncRequestProcessor@191] -
> Shutting down
> 2016-09-13 05:09:28,697 [myid:0] - INFO
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-09-13 05:09:28,698 [myid:0] - INFO
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] -
> ConnnectionExpirerThread interrupted
> 2016-09-13 05:09:28,698 [myid:0] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13915:NIOServerCnxnFactory$AcceptThread@219]
> - accept thread exitted run method
> 2016-09-13 05:09:28,699 [myid:0] - INFO
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
> - selector thread exitted run method
> 2016-09-13 05:09:28,699 [myid:0] - INFO
> [/127.0.0.1:13917:QuorumCnxManager$Listener@661] - Leaving listener
> 2016-09-13 05:09:28,700 [myid:] - INFO [main:QuorumBase@398] - Shutting down
> leader election QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled)
> 2016-09-13 05:09:28,700 [myid:] - INFO [main:QuorumBase@403] - Waiting for
> QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled) to exit thread
> 2016-09-13 05:09:29,738 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection$Messenger$WorkerReceiver@440] -
> WorkerReceiver is down
> 2016-09-13 05:09:29,738 [myid:0] - INFO
> [WorkerSender[myid=0]:FastLeaderElection$Messenger$WorkerSender@470] -
> WorkerSender is down
> 2016-09-13 05:09:29,776 [myid:1] - INFO
> [WorkerReceiver[myid=1]:FastLeaderElection$Messenger$WorkerReceiver@440] -
> WorkerReceiver is down
> 2016-09-13 05:09:29,785 [myid:3] - INFO
> [WorkerSender[myid=3]:FastLeaderElection$Messenger$WorkerSender@470] -
> WorkerSender is down
> 2016-09-13 05:09:29,785 [myid:1] - INFO
> [WorkerSender[myid=1]:FastLeaderElection$Messenger$WorkerSender@470] -
> WorkerSender is down
> 2016-09-13 05:09:29,789 [myid:2] - INFO
> [WorkerReceiver[myid=2]:FastLeaderElection$Messenger$WorkerReceiver@440] -
> WorkerReceiver is down
> 2016-09-13 05:09:29,790 [myid:2] - INFO
> [WorkerSender[myid=2]:FastLeaderElection$Messenger$WorkerSender@470] -
> WorkerSender is down
> 2016-09-13 05:09:29,792 [myid:3] - INFO
> [WorkerReceiver[myid=3]:FastLeaderElection$Messenger$WorkerReceiver@440] -
> WorkerReceiver is down
> 2016-09-13 05:09:29,922 [myid:0] - INFO
> [WorkerSender[myid=0]:FastLeaderElection$Messenger$WorkerSender@470] -
> WorkerSender is down
> 2016-09-13 05:09:29,923 [myid:0] - INFO
> [WorkerReceiver[myid=0]:FastLeaderElection$Messenger$WorkerReceiver@440] -
> WorkerReceiver is down
> 2016-09-13 05:09:30,255 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=Follower]
> 2016-09-13 05:09:30,256 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):Follower@198] -
> shutdown called
> java.lang.Exception: shutdown Follower
> at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
> 2016-09-13 05:09:30,256 [myid:0] - WARN
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1158]
> - PeerState set to LOOKING
> 2016-09-13 05:09:30,256 [myid:0] - WARN
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):QuorumPeer@1140]
> - QuorumPeer main thread exited
> 2016-09-13 05:09:30,256 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id0]
> 2016-09-13 05:09:30,256 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0]
> 2016-09-13 05:09:30,256 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.1]
> 2016-09-13 05:09:30,257 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.2]
> 2016-09-13 05:09:30,257 [myid:0] - INFO
> [QuorumPeer[myid=0](plain=/127.0.0.1:13915)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.3]
> 2016-09-13 05:09:30,258 [myid:] - INFO [main:QuorumBase@394] - Shutting down
> quorum peer QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled)
> 2016-09-13 05:09:30,258 [myid:] - INFO [main:Follower@198] - shutdown called
> java.lang.Exception: shutdown Follower
> at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:1184)
> at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.shutdown(QuorumPeerTestBase.java:60)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.shutdown(QuorumPeerTestBase.java:257)
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tearDown(ReconfigDuringLeaderSyncTest.java:189)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
> at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)
> 2016-09-13 05:09:30,259 [myid:] - INFO [main:LearnerZooKeeperServer@165] -
> Shutting down
> 2016-09-13 05:09:30,259 [myid:] - INFO [main:ZooKeeperServer@529] - shutting
> down
> 2016-09-13 05:09:30,259 [myid:] - INFO [main:FollowerRequestProcessor@138] -
> Shutting down
> 2016-09-13 05:09:30,259 [myid:] - INFO [main:CommitProcessor@414] - Shutting
> down
> 2016-09-13 05:09:30,259 [myid:1] - INFO
> [FollowerRequestProcessor:1:FollowerRequestProcessor@109] -
> FollowerRequestProcessor exited loop!
> 2016-09-13 05:09:30,259 [myid:] - INFO [main:FinalRequestProcessor@479] -
> shutdown of request processor complete
> 2016-09-13 05:09:30,259 [myid:1] - INFO
> [CommitProcessor:1:CommitProcessor@299] - CommitProcessor exited loop!
> 2016-09-13 05:09:30,260 [myid:] - INFO [main:MBeanRegistry@128] - Unregister
> MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower,name3=InMemoryDataTree]
> 2016-09-13 05:09:30,260 [myid:] - INFO [main:SyncRequestProcessor@191] -
> Shutting down
> 2016-09-13 05:09:30,260 [myid:1] - INFO
> [SyncThread:1:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-09-13 05:09:30,261 [myid:1] - INFO
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] -
> ConnnectionExpirerThread interrupted
> 2016-09-13 05:09:30,261 [myid:1] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13918:NIOServerCnxnFactory$AcceptThread@219]
> - accept thread exitted run method
> 2016-09-13 05:09:30,261 [myid:1] - INFO
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
> - selector thread exitted run method
> 2016-09-13 05:09:30,261 [myid:1] - INFO
> [/127.0.0.1:13920:QuorumCnxManager$Listener@661] - Leaving listener
> 2016-09-13 05:09:30,261 [myid:] - INFO [main:QuorumBase@398] - Shutting down
> leader election QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled)
> 2016-09-13 05:09:30,262 [myid:] - INFO [main:QuorumBase@403] - Waiting for
> QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled) to exit thread
> 2016-09-13 05:09:30,624 [myid:127.0.0.1:13915] - INFO
> [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1113] - Opening
> socket connection to server 127.0.0.1/127.0.0.1:13915. Will not attempt to
> authenticate using SASL (unknown error)
> 2016-09-13 05:09:30,624 [myid:127.0.0.1:13915] - WARN
> [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1235] - Session
> 0x483fd50000 for server 127.0.0.1/127.0.0.1:13915, unexpected error, closing
> socket connection and attempting reconnect
> java.net.ConnectException: Connection refused
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744)
> at
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:357)
> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1214)
> 2016-09-13 05:09:31,733 [myid:127.0.0.1:13915] - INFO
> [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1113] - Opening
> socket connection to server 127.0.0.1/127.0.0.1:13915. Will not attempt to
> authenticate using SASL (unknown error)
> 2016-09-13 05:09:31,734 [myid:127.0.0.1:13915] - WARN
> [main-SendThread(127.0.0.1:13915):ClientCnxn$SendThread@1235] - Session
> 0x483fd50000 for server 127.0.0.1/127.0.0.1:13915, unexpected error, closing
> socket connection and attempting reconnect
> java.net.ConnectException: Connection refused
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744)
> at
> org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:357)
> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1214)
> 2016-09-13 05:09:32,255 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=Follower]
> 2016-09-13 05:09:32,256 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):Follower@198] -
> shutdown called
> java.lang.Exception: shutdown Follower
> at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
> 2016-09-13 05:09:32,256 [myid:1] - WARN
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1158]
> - PeerState set to LOOKING
> 2016-09-13 05:09:32,256 [myid:1] - WARN
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):QuorumPeer@1140]
> - QuorumPeer main thread exited
> 2016-09-13 05:09:32,256 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1]
> 2016-09-13 05:09:32,257 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1]
> 2016-09-13 05:09:32,257 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.0]
> 2016-09-13 05:09:32,257 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.2]
> 2016-09-13 05:09:32,257 [myid:1] - INFO
> [QuorumPeer[myid=1](plain=/127.0.0.1:13918)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.3]
> 2016-09-13 05:09:32,257 [myid:] - INFO [main:QuorumBase@394] - Shutting down
> quorum peer QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled)
> 2016-09-13 05:09:32,258 [myid:] - INFO [main:Leader@623] - Shutting down
> 2016-09-13 05:09:32,258 [myid:] - INFO [main:Leader@629] - Shutdown called
> java.lang.Exception: shutdown Leader! reason: quorum Peer shutdown
> at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:629)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:1181)
> at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:395)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$TestQPMain.shutdown(QuorumPeerTestBase.java:60)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.shutdown(QuorumPeerTestBase.java:257)
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.tearDown(ReconfigDuringLeaderSyncTest.java:189)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33)
> at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)
> 2016-09-13 05:09:32,259 [myid:] - INFO [main:ZooKeeperServer@529] - shutting
> down
> 2016-09-13 05:09:32,259 [myid:] - INFO [main:SessionTrackerImpl@232] -
> Shutting down
> 2016-09-13 05:09:32,259 [myid:] - INFO [main:LeaderRequestProcessor@77] -
> Shutting down
> 2016-09-13 05:09:32,259 [myid:] - INFO [main:PrepRequestProcessor@965] -
> Shutting down
> 2016-09-13 05:09:32,259 [myid:] - INFO [main:ProposalRequestProcessor@88] -
> Shutting down
> 2016-09-13 05:09:32,259 [myid:2] - INFO [ProcessThread(sid:2
> cport:-1)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-09-13 05:09:32,259 [myid:] - INFO [main:CommitProcessor@414] - Shutting
> down
> 2016-09-13 05:09:32,260 [myid:2] - INFO
> [CommitProcessor:2:CommitProcessor@299] - CommitProcessor exited loop!
> 2016-09-13 05:09:32,260 [myid:] - INFO
> [main:Leader$ToBeAppliedRequestProcessor@924] - Shutting down
> 2016-09-13 05:09:32,260 [myid:] - INFO [main:FinalRequestProcessor@479] -
> shutdown of request processor complete
> 2016-09-13 05:09:32,261 [myid:] - INFO [main:SyncRequestProcessor@191] -
> Shutting down
> 2016-09-13 05:09:32,262 [myid:2] - INFO
> [SyncThread:2:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-09-13 05:09:32,262 [myid:2] - INFO
> [LearnerCnxAcceptor-/127.0.0.1:13922:Leader$LearnerCnxAcceptor@373] -
> exception while shutting down acceptor: java.net.SocketException: Socket
> closed
> 2016-09-13 05:09:32,263 [myid:] - INFO [main:MBeanRegistry@128] - Unregister
> MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader,name3=InMemoryDataTree]
> 2016-09-13 05:09:32,264 [myid:2] - WARN
> [LearnerHandler-/127.0.0.1:39078:LearnerHandler@619] - ******* GOODBYE
> /127.0.0.1:39078 ********
> 2016-09-13 05:09:32,265 [myid:3] - WARN
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Follower@93]
> - Exception when following the leader
> java.io.EOFException
> at java.io.DataInputStream.readInt(DataInputStream.java:392)
> at
> org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
> at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
> at
> org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:155)
> at
> org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:89)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1111)
> 2016-09-13 05:09:32,265 [myid:2] - WARN
> [LearnerHandler-/127.0.0.1:39079:LearnerHandler@619] - ******* GOODBYE
> /127.0.0.1:39079 ********
> 2016-09-13 05:09:32,265 [myid:2] - WARN
> [LearnerHandler-/127.0.0.1:39104:LearnerHandler@619] - ******* GOODBYE
> /127.0.0.1:39104 ********
> 2016-09-13 05:09:32,265 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower]
> 2016-09-13 05:09:32,265 [myid:2] - WARN
> [LearnerHandler-/127.0.0.1:39104:LearnerHandler@903] - Ignoring unexpected
> exception
> java.lang.InterruptedException
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1219)
> at
> java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340)
> at
> java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:338)
> at
> org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:901)
> at
> org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:622)
> 2016-09-13 05:09:32,265 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):Follower@198]
> - shutdown called
> java.lang.Exception: shutdown Follower
> at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:198)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1115)
> 2016-09-13 05:09:32,266 [myid:2] - INFO
> [NIOServerCxnFactory.AcceptThread:/127.0.0.1:13921:NIOServerCnxnFactory$AcceptThread@219]
> - accept thread exitted run method
> 2016-09-13 05:09:32,266 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower,name3=Connections,name4=127.0.0.1,name5=0x3000048422c0000]
> 2016-09-13 05:09:32,266 [myid:2] - INFO
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
> - selector thread exitted run method
> 2016-09-13 05:09:32,266 [myid:2] - INFO
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] -
> ConnnectionExpirerThread interrupted
> 2016-09-13 05:09:32,266 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):NIOServerCnxn@607]
> - Closed socket connection for client /127.0.0.1:50397 which had sessionid
> 0x3000048422c0000
> 2016-09-13 05:09:32,267 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):LearnerZooKeeperServer@165]
> - Shutting down
> 2016-09-13 05:09:32,267 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):ZooKeeperServer@529]
> - shutting down
> 2016-09-13 05:09:32,267 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FollowerRequestProcessor@138]
> - Shutting down
> 2016-09-13 05:09:32,267 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):CommitProcessor@414]
> - Shutting down
> 2016-09-13 05:09:32,267 [myid:127.0.0.1:13924] - INFO
> [main-SendThread(127.0.0.1:13924):ClientCnxn$SendThread@1231] - Unable to
> read additional data from server sessionid 0x3000048422c0000, likely server
> has closed socket, closing socket connection and attempting reconnect
> 2016-09-13 05:09:32,268 [myid:3] - INFO
> [FollowerRequestProcessor:3:FollowerRequestProcessor@109] -
> FollowerRequestProcessor exited loop!
> 2016-09-13 05:09:32,268 [myid:3] - INFO
> [CommitProcessor:3:CommitProcessor@299] - CommitProcessor exited loop!
> 2016-09-13 05:09:32,268 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FinalRequestProcessor@479]
> - shutdown of request processor complete
> 2016-09-13 05:09:32,269 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=Follower,name3=InMemoryDataTree]
> 2016-09-13 05:09:32,269 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):SyncRequestProcessor@191]
> - Shutting down
> 2016-09-13 05:09:32,269 [myid:3] - INFO
> [SyncThread:3:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-09-13 05:09:32,269 [myid:3] - WARN
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1158]
> - PeerState set to LOOKING
> 2016-09-13 05:09:32,269 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1033]
> - LOOKING
> 2016-09-13 05:09:32,270 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FileSnap@83]
> - Reading snapshot
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/build/test/tmp/test1465497725988500626.junit.dir/data/version-2/snapshot.100000001
> 2016-09-13 05:09:32,271 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=Leader]
> 2016-09-13 05:09:32,272 [myid:2] - WARN
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1127]
> - Unexpected exception
> java.lang.InterruptedException
> at java.lang.Object.wait(Native Method)
> at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:561)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1124)
> 2016-09-13 05:09:32,272 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):Leader@623] -
> Shutting down
> 2016-09-13 05:09:32,272 [myid:2] - WARN
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1158]
> - PeerState set to LOOKING
> 2016-09-13 05:09:32,272 [myid:2] - WARN
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):QuorumPeer@1140]
> - QuorumPeer main thread exited
> 2016-09-13 05:09:32,272 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id2]
> 2016-09-13 05:09:32,272 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2]
> 2016-09-13 05:09:32,272 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.0]
> 2016-09-13 05:09:32,273 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.1]
> 2016-09-13 05:09:32,273 [myid:2] - INFO
> [QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.3]
> 2016-09-13 05:09:32,274 [myid:2] - INFO
> [/127.0.0.1:13923:QuorumCnxManager$Listener@661] - Leaving listener
> 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@398] - Shutting down
> leader election QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled)
> 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@403] - Waiting for
> QuorumPeer[myid=2](plain=/127.0.0.1:13921)(secure=disabled) to exit thread
> 2016-09-13 05:09:32,274 [myid:] - INFO [main:QuorumBase@394] - Shutting down
> quorum peer QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled)
> 2016-09-13 05:09:32,275 [myid:3] - INFO
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] -
> ConnnectionExpirerThread interrupted
> 2016-09-13 05:09:32,275 [myid:3] - INFO
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:13924:NIOServerCnxnFactory$AcceptThread@219]
> - accept thread exitted run method
> 2016-09-13 05:09:32,276 [myid:3] - INFO
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
> - selector thread exitted run method
> 2016-09-13 05:09:32,276 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):FastLeaderElection@894]
> - New election. My id = 3, proposed zxid=0x100000004
> 2016-09-13 05:09:32,277 [myid:3] - WARN
> [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 0 at
> election address /127.0.0.1:13917
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
> at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
> at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:579)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:482)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:32,277 [myid:3] - INFO
> [/127.0.0.1:13926:QuorumCnxManager$Listener@661] - Leaving listener
> 2016-09-13 05:09:32,277 [myid:3] - WARN
> [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 0 at
> election address /127.0.0.1:13917
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
> at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
> at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:579)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:489)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:32,278 [myid:3] - WARN
> [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 1 at
> election address /127.0.0.1:13920
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
> at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
> at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:579)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:482)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:32,278 [myid:] - INFO [main:QuorumBase@398] - Shutting down
> leader election
> QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled)
> 2016-09-13 05:09:32,279 [myid:] - INFO [main:QuorumBase@403] - Waiting for
> QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled) to exit
> thread
> 2016-09-13 05:09:32,279 [myid:3] - WARN
> [WorkerSender[myid=3]:QuorumCnxManager@455] - Cannot open channel to 1 at
> election address /127.0.0.1:13920
> java.net.ConnectException: Connection refused
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at
> java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
> at
> java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
> at
> java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:579)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:441)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:489)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:419)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:486)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:465)
> at java.lang.Thread.run(Thread.java:745)
> 2016-09-13 05:09:32,280 [myid:3] - INFO
> [WorkerSender[myid=3]:FastLeaderElection$Messenger$WorkerSender@470] -
> WorkerSender is down
> 2016-09-13 05:09:32,280 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=LeaderElection]
> 2016-09-13 05:09:32,280 [myid:3] - WARN
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):QuorumPeer@1140]
> - QuorumPeer main thread exited
> 2016-09-13 05:09:32,280 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id3]
> 2016-09-13 05:09:32,280 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3]
> 2016-09-13 05:09:32,281 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.0]
> 2016-09-13 05:09:32,281 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.1]
> 2016-09-13 05:09:32,281 [myid:3] - INFO
> [QuorumPeer[myid=3](plain=/0:0:0:0:0:0:0:0:13924)(secure=disabled):MBeanRegistry@128]
> - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.2]
> 2016-09-13 05:09:32,283 [myid:] - INFO [main:ZKTestCase$1@70] - FAILED
> testDuringLeaderSync
> java.lang.AssertionError: zoo.cfg.dynamic.next is not deleted.
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.assertTrue(Assert.java:41)
> at org.junit.Assert.assertFalse(Assert.java:64)
> at
> org.apache.zookeeper.server.quorum.ReconfigDuringLeaderSyncTest.testDuringLeaderSync(ReconfigDuringLeaderSyncTest.java:155)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:535)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1182)
> at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1033)
> 2016-09-13 05:09:32,284 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED
> testDuringLeaderSync
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
