java.net.ConnectException: Connection refused

Apache's JIRA Issue Tracker | Michael Han | 3 months ago
  1. 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}

    Apache's JIRA Issue Tracker | 3 months ago | Michael Han
    java.net.ConnectException: Connection refused
  2. 0

    {noformat} Regression org.apache.zookeeper.test.ReconfigTest.testQuorumSystemChange (from org.apache.zookeeper.test.NioNettySuiteTest) Failing for the past 1 build (Since Failed#3462 ) Took 2 min 10 sec. Error Message Waiting for server up Stacktrace junit.framework.AssertionFailedError: Waiting for server up at org.apache.zookeeper.test.QuorumUtil.restart(QuorumUtil.java:216) at org.apache.zookeeper.test.ReconfigTest.testQuorumSystemChange(ReconfigTest.java:861) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79) Standard Output 2016-10-04 01:04:03,140 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,170 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,179 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,182 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,186 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,190 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,200 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,204 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,208 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,276 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,279 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,282 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,284 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,285 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,286 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,286 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,291 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,292 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods. 2016-10-04 01:04:03,304 [myid:] - INFO [main:PortAssignment@151] - Test process 3/8 using ports from 16607 - 19299. 2016-10-04 01:04:03,308 [myid:] - INFO [main:PortAssignment@85] - Assigned port 16608 from range 16607 - 19299. 2016-10-04 01:04:03,316 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testAcls 2016-10-04 01:04:03,317 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testAcls 2016-10-04 01:04:03,337 [myid:] - INFO [main:Environment@109] - Server environment:zookeeper.version=3.6.0-SNAPSHOT--1, built on 10/04/2016 00:56 GMT 2016-10-04 01:04:03,337 [myid:] - INFO [main:Environment@109] - Server environment:host.name=asf905.gq1.ygridcore.net 2016-10-04 01:04:03,337 [myid:] - INFO [main:Environment@109] - Server environment:java.version=1.7.0_80 2016-10-04 01:04:03,337 [myid:] - INFO [main:Environment@109] - Server environment:java.vendor=Oracle Corporation 2016-10-04 01:04:03,337 [myid:] - INFO [main:Environment@109] - Server environment:java.home=/usr/local/asfpackages/java/jdk1.7.0_80/jre 2016-10-04 01:04:03,337 [myid:] - INFO [main:Environment@109] - Server environment:java.class.path=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/apache-rat-core-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/apache-rat-tasks-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-compress-1.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-io-2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-lang-2.6.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-http-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-server-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-util-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/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-10-04 01:04:03,338 [myid:] - INFO [main:Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2016-10-04 01:04:03,338 [myid:] - INFO [main:Environment@109] - Server environment:java.io.tmpdir=/tmp 2016-10-04 01:04:03,338 [myid:] - INFO [main:Environment@109] - Server environment:java.compiler=<NA> 2016-10-04 01:04:03,338 [myid:] - INFO [main:Environment@109] - Server environment:os.name=Linux 2016-10-04 01:04:03,339 [myid:] - INFO [main:Environment@109] - Server environment:os.arch=amd64 2016-10-04 01:04:03,339 [myid:] - INFO [main:Environment@109] - Server environment:os.version=3.13.0-95-generic 2016-10-04 01:04:03,339 [myid:] - INFO [main:Environment@109] - Server environment:user.name=jenkins 2016-10-04 01:04:03,339 [myid:] - INFO [main:Environment@109] - Server environment:user.home=/home/jenkins 2016-10-04 01:04:03,339 [myid:] - INFO [main:Environment@109] - Server environment:user.dir=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test 2016-10-04 01:04:03,339 [myid:] - INFO [main:Environment@109] - Server environment:os.memory.free=475MB 2016-10-04 01:04:03,340 [myid:] - INFO [main:Environment@109] - Server environment:os.memory.max=491MB 2016-10-04 01:04:03,340 [myid:] - INFO [main:Environment@109] - Server environment:os.memory.total=491MB 2016-10-04 01:04:03,357 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:04:03,357 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:04:03,357 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2 2016-10-04 01:04:03,469 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16608 2016-10-04 01:04:03,509 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2/snapshot.0 2016-10-04 01:04:03,614 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:03,615 [myid:] - INFO [main:ACLTest@108] - starting up the zookeeper server .. waiting 2016-10-04 01:04:03,617 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16608 2016-10-04 01:04:03,652 [myid:] - INFO [New I/O worker #1:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:52750 2016-10-04 01:04:03,660 [myid:] - INFO [New I/O worker #1:StatCommand@49] - Stat command output 2016-10-04 01:04:03,670 [myid:] - INFO [main:Environment@109] - Client environment:zookeeper.version=3.6.0-SNAPSHOT--1, built on 10/04/2016 00:56 GMT 2016-10-04 01:04:03,671 [myid:] - INFO [main:Environment@109] - Client environment:host.name=asf905.gq1.ygridcore.net 2016-10-04 01:04:03,671 [myid:] - INFO [main:Environment@109] - Client environment:java.version=1.7.0_80 2016-10-04 01:04:03,671 [myid:] - INFO [main:Environment@109] - Client environment:java.vendor=Oracle Corporation 2016-10-04 01:04:03,671 [myid:] - INFO [main:Environment@109] - Client environment:java.home=/usr/local/asfpackages/java/jdk1.7.0_80/jre 2016-10-04 01:04:03,671 [myid:] - INFO [main:Environment@109] - Client environment:java.class.path=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/apache-rat-core-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/apache-rat-tasks-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-compress-1.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-io-2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/commons-lang-2.6.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-http-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-io-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-security-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-server-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-servlet-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jetty-util-9.2.18.v20160721.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/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-10-04 01:04:03,672 [myid:] - INFO [main:Environment@109] - Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2016-10-04 01:04:03,672 [myid:] - INFO [main:Environment@109] - Client environment:java.io.tmpdir=/tmp 2016-10-04 01:04:03,672 [myid:] - INFO [main:Environment@109] - Client environment:java.compiler=<NA> 2016-10-04 01:04:03,672 [myid:] - INFO [main:Environment@109] - Client environment:os.name=Linux 2016-10-04 01:04:03,672 [myid:] - INFO [main:Environment@109] - Client environment:os.arch=amd64 2016-10-04 01:04:03,672 [myid:] - INFO [main:Environment@109] - Client environment:os.version=3.13.0-95-generic 2016-10-04 01:04:03,673 [myid:] - INFO [main:Environment@109] - Client environment:user.name=jenkins 2016-10-04 01:04:03,673 [myid:] - INFO [main:Environment@109] - Client environment:user.home=/home/jenkins 2016-10-04 01:04:03,673 [myid:] - INFO [main:Environment@109] - Client environment:user.dir=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test 2016-10-04 01:04:03,673 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.free=377MB 2016-10-04 01:04:03,673 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.max=491MB 2016-10-04 01:04:03,674 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.total=491MB 2016-10-04 01:04:03,676 [myid:] - INFO [main:ZooKeeper@853] - Initiating client connection, connectString=127.0.0.1:16608 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@40ae49d5 2016-10-04 01:04:03,693 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16608. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:04:03,694 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:52752, server: 127.0.0.1/127.0.0.1:16608 2016-10-04 01:04:03,698 [myid:] - INFO [New I/O worker #2:ZooKeeperServer@995] - Client attempting to establish new session at /127.0.0.1:52752 2016-10-04 01:04:03,702 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.1 2016-10-04 01:04:03,782 [myid:] - INFO [SyncThread:0:ZooKeeperServer@709] - Established session 0x10020f0235b0000 with negotiated timeout 30000 for client /127.0.0.1:52752 2016-10-04 01:04:03,782 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16608, sessionid = 0x10020f0235b0000, negotiated timeout = 30000 2016-10-04 01:04:03,785 [myid:] - INFO [main:ACLTest@112] - starting creating acls 2016-10-04 01:04:08,518 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16608 2016-10-04 01:04:08,519 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1231] - Unable to read additional data from server sessionid 0x10020f0235b0000, likely server has closed socket, closing socket connection and attempting reconnect 2016-10-04 01:04:08,521 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608,name1=Connections,name2=127.0.0.1,name3=0x10020f0235b0000] 2016-10-04 01:04:08,536 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:04:08,536 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:08,536 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:04:08,536 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:04:08,537 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:04:08,537 [myid:] - INFO [ProcessThread(sid:0 cport:16608)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:04:08,537 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited! 2016-10-04 01:04:08,537 [myid:] - INFO [main:FinalRequestProcessor@479] - shutdown of request processor complete 2016-10-04 01:04:08,538 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608,name1=InMemoryDataTree] 2016-10-04 01:04:08,538 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608] 2016-10-04 01:04:08,538 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16608 2016-10-04 01:04:08,539 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:04:08,539 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:04:08,540 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2 2016-10-04 01:04:08,565 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16608 2016-10-04 01:04:08,567 [myid:] - INFO [main:FileSnap@83] - Reading snapshot /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2/snapshot.0 2016-10-04 01:04:08,598 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0xc9 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test1469455732852767377.junit.dir/version-2/snapshot.c9 2016-10-04 01:04:08,609 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:08,609 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16608 2016-10-04 01:04:08,610 [myid:] - INFO [New I/O worker #34:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:52862 2016-10-04 01:04:08,610 [myid:] - INFO [New I/O worker #34:StatCommand@49] - Stat command output 2016-10-04 01:04:08,611 [myid:] - INFO [main:ZooKeeper@853] - Initiating client connection, connectString=127.0.0.1:16608 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@19450f1a 2016-10-04 01:04:08,612 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16608. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:04:08,613 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:52863, server: 127.0.0.1/127.0.0.1:16608 2016-10-04 01:04:08,614 [myid:] - INFO [New I/O worker #35:ZooKeeperServer@995] - Client attempting to establish new session at /127.0.0.1:52863 2016-10-04 01:04:08,615 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.ca 2016-10-04 01:04:08,637 [myid:] - INFO [SyncThread:0:ZooKeeperServer@709] - Established session 0x10020f0373e0000 with negotiated timeout 30000 for client /127.0.0.1:52863 2016-10-04 01:04:08,638 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16608, sessionid = 0x10020f0373e0000, negotiated timeout = 30000 2016-10-04 01:04:08,681 [myid:] - INFO [ProcessThread(sid:0 cport:16608)::PrepRequestProcessor@657] - Processed session termination for sessionid: 0x10020f0373e0000 2016-10-04 01:04:08,690 [myid:] - INFO [main:ZooKeeper@1311] - Session: 0x10020f0373e0000 closed 2016-10-04 01:04:08,690 [myid:] - INFO [SyncThread:0:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608,name1=Connections,name2=127.0.0.1,name3=0x10020f0373e0000] 2016-10-04 01:04:08,690 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for session: 0x10020f0373e0000 2016-10-04 01:04:08,691 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16608 2016-10-04 01:04:08,717 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:04:08,717 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:08,717 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:04:08,717 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:04:08,718 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:04:08,718 [myid:] - INFO [ProcessThread(sid:0 cport:16608)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:04:08,718 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited! 2016-10-04 01:04:08,718 [myid:] - INFO [main:FinalRequestProcessor@479] - shutdown of request processor complete 2016-10-04 01:04:08,719 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608,name1=InMemoryDataTree] 2016-10-04 01:04:08,719 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608] 2016-10-04 01:04:08,720 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16608 2016-10-04 01:04:08,721 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 39623 2016-10-04 01:04:08,721 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 9 2016-10-04 01:04:08,721 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testAcls 2016-10-04 01:04:08,721 [myid:] - INFO [main:ZKTestCase$1@65] - SUCCEEDED testAcls 2016-10-04 01:04:08,722 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testAcls 2016-10-04 01:04:08,723 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testIPAuthenticationIsValidCIDR 2016-10-04 01:04:08,723 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testIPAuthenticationIsValidCIDR 2016-10-04 01:04:08,724 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 39623 2016-10-04 01:04:08,724 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 9 2016-10-04 01:04:08,724 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testIPAuthenticationIsValidCIDR 2016-10-04 01:04:08,725 [myid:] - INFO [main:ZKTestCase$1@65] - SUCCEEDED testIPAuthenticationIsValidCIDR 2016-10-04 01:04:08,725 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testIPAuthenticationIsValidCIDR 2016-10-04 01:04:08,741 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testDisconnectedAddAuth 2016-10-04 01:04:08,741 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testDisconnectedAddAuth 2016-10-04 01:04:08,742 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:04:08,742 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:04:08,743 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test6791388306054347439.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test6791388306054347439.junit.dir/version-2 2016-10-04 01:04:08,751 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16608 2016-10-04 01:04:08,753 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test6791388306054347439.junit.dir/version-2/snapshot.0 2016-10-04 01:04:08,755 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:08,755 [myid:] - INFO [main:ACLTest@72] - starting up the zookeeper server .. waiting 2016-10-04 01:04:08,755 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16608 2016-10-04 01:04:08,757 [myid:] - INFO [New I/O worker #67:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:52865 2016-10-04 01:04:08,757 [myid:] - INFO [New I/O worker #67:StatCommand@49] - Stat command output 2016-10-04 01:04:08,758 [myid:] - INFO [main:ZooKeeper@853] - Initiating client connection, connectString=127.0.0.1:16608 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@68098843 2016-10-04 01:04:08,759 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16608. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:04:08,759 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:52866, server: 127.0.0.1/127.0.0.1:16608 2016-10-04 01:04:08,760 [myid:] - INFO [New I/O worker #68:ZooKeeperServer@995] - Client attempting to establish new session at /127.0.0.1:52866 2016-10-04 01:04:08,761 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.1 2016-10-04 01:04:08,800 [myid:] - INFO [SyncThread:0:ZooKeeperServer@709] - Established session 0x10020f037d10000 with negotiated timeout 30000 for client /127.0.0.1:52866 2016-10-04 01:04:08,801 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16608, sessionid = 0x10020f037d10000, negotiated timeout = 30000 2016-10-04 01:04:08,803 [myid:] - INFO [New I/O worker #68:ZooKeeperServer@1032] - got auth packet /127.0.0.1:52866 2016-10-04 01:04:08,803 [myid:] - INFO [New I/O worker #68:ZooKeeperServer@1050] - auth success /127.0.0.1:52866 2016-10-04 01:04:08,822 [myid:] - INFO [ProcessThread(sid:0 cport:16608)::PrepRequestProcessor@657] - Processed session termination for sessionid: 0x10020f037d10000 2016-10-04 01:04:08,830 [myid:] - INFO [SyncThread:0:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608,name1=Connections,name2=127.0.0.1,name3=0x10020f037d10000] 2016-10-04 01:04:08,830 [myid:] - INFO [main:ZooKeeper@1311] - Session: 0x10020f037d10000 closed 2016-10-04 01:04:08,830 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for session: 0x10020f037d10000 2016-10-04 01:04:08,830 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16608 2016-10-04 01:04:08,839 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:04:08,839 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:08,840 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:04:08,841 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:04:08,841 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:04:08,841 [myid:] - INFO [ProcessThread(sid:0 cport:16608)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:04:08,843 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited! 2016-10-04 01:04:08,844 [myid:] - INFO [main:FinalRequestProcessor@479] - shutdown of request processor complete 2016-10-04 01:04:08,844 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608,name1=InMemoryDataTree] 2016-10-04 01:04:08,844 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16608] 2016-10-04 01:04:08,845 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16608 2016-10-04 01:04:08,845 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 67299 2016-10-04 01:04:08,845 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 10 2016-10-04 01:04:08,846 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testDisconnectedAddAuth 2016-10-04 01:04:08,846 [myid:] - INFO [main:ZKTestCase$1@65] - SUCCEEDED testDisconnectedAddAuth 2016-10-04 01:04:08,846 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testDisconnectedAddAuth 2016-10-04 01:04:08,847 [myid:] - INFO [main:PortAssignment@85] - Assigned port 16609 from range 16607 - 19299. 2016-10-04 01:04:08,847 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testAsyncMulti 2016-10-04 01:04:08,848 [myid:] - INFO [main:ClientBase@448] - Initial fdcount is: 60 2016-10-04 01:04:08,995 [myid:] - INFO [main:ClientBase@466] - STARTING server 2016-10-04 01:04:08,996 [myid:] - INFO [main:ClientBase@386] - CREATING server instance 127.0.0.1:16609 2016-10-04 01:04:09,004 [myid:] - INFO [main:ClientBase@361] - STARTING server instance 127.0.0.1:16609 2016-10-04 01:04:09,005 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:04:09,005 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:04:09,005 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test484349696560279448.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test484349696560279448.junit.dir/version-2 2016-10-04 01:04:09,006 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16609 2016-10-04 01:04:09,007 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test484349696560279448.junit.dir/version-2/snapshot.0 2016-10-04 01:04:09,012 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:09,012 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16609 2016-10-04 01:04:09,013 [myid:] - INFO [New I/O worker #100:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:49194 2016-10-04 01:04:09,014 [myid:] - INFO [New I/O worker #100:StatCommand@49] - Stat command output 2016-10-04 01:04:09,014 [myid:] - INFO [main:JMXEnv@228] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-10-04 01:04:09,021 [myid:] - INFO [main:JMXEnv@245] - expect:InMemoryDataTree 2016-10-04 01:04:09,021 [myid:] - INFO [main:JMXEnv@249] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port16609,name1=InMemoryDataTree 2016-10-04 01:04:09,022 [myid:] - INFO [main:JMXEnv@245] - expect:StandaloneServer_port 2016-10-04 01:04:09,022 [myid:] - INFO [main:JMXEnv@249] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port16609 2016-10-04 01:04:09,022 [myid:] - INFO [main:ClientBase@462] - Client test setup finished 2016-10-04 01:04:09,022 [myid:] - INFO [main:AsyncOpsTest@50] - Creating client testAsyncMulti 2016-10-04 01:04:09,023 [myid:] - INFO [main:ZooKeeper@853] - Initiating client connection, connectString=127.0.0.1:16609 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@5a124d9f 2016-10-04 01:04:09,024 [myid:127.0.0.1:16609] - INFO [main-SendThread(127.0.0.1:16609):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16609. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:04:09,024 [myid:127.0.0.1:16609] - INFO [main-SendThread(127.0.0.1:16609):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:49195, server: 127.0.0.1/127.0.0.1:16609 2016-10-04 01:04:09,026 [myid:] - INFO [New I/O worker #101:ZooKeeperServer@995] - Client attempting to establish new session at /127.0.0.1:49195 2016-10-04 01:04:09,026 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.1 2016-10-04 01:04:09,070 [myid:] - INFO [SyncThread:0:ZooKeeperServer@709] - Established session 0x10020f038cf0000 with negotiated timeout 30000 for client /127.0.0.1:49195 2016-10-04 01:04:09,070 [myid:127.0.0.1:16609] - INFO [main-SendThread(127.0.0.1:16609):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16609, sessionid = 0x10020f038cf0000, negotiated timeout = 30000 2016-10-04 01:04:09,073 [myid:] - INFO [main:JMXEnv@117] - expect:0x10020f038cf0000 2016-10-04 01:04:09,073 [myid:] - INFO [main:JMXEnv@120] - found:0x10020f038cf0000 org.apache.ZooKeeperService:name0=StandaloneServer_port16609,name1=Connections,name2=127.0.0.1,name3=0x10020f038cf0000 2016-10-04 01:04:09,073 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testAsyncMulti 2016-10-04 01:04:09,074 [myid:] - INFO [New I/O worker #101:ZooKeeperServer@1032] - got auth packet /127.0.0.1:49195 2016-10-04 01:04:09,074 [myid:] - INFO [New I/O worker #101:ZooKeeperServer@1050] - auth success /127.0.0.1:49195 2016-10-04 01:04:09,102 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 33655 2016-10-04 01:04:09,102 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 55 2016-10-04 01:04:09,102 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testAsyncMulti 2016-10-04 01:04:09,103 [myid:] - INFO [ProcessThread(sid:0 cport:16609)::PrepRequestProcessor@657] - Processed session termination for sessionid: 0x10020f038cf0000 2016-10-04 01:04:09,116 [myid:] - INFO [SyncThread:0:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16609,name1=Connections,name2=127.0.0.1,name3=0x10020f038cf0000] 2016-10-04 01:04:09,118 [myid:] - WARN [New I/O worker #101:NettyServerCnxnFactory$CnxnChannelHandler@142] - Exception caught [id: 0xd523ab2f, /127.0.0.1:49195 :> /127.0.0.1:16609] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-10-04 01:04:09,216 [myid:] - INFO [main:ZooKeeper@1311] - Session: 0x10020f038cf0000 closed 2016-10-04 01:04:09,217 [myid:] - INFO [main:ClientBase@543] - tearDown starting 2016-10-04 01:04:09,217 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for session: 0x10020f038cf0000 2016-10-04 01:04:09,217 [myid:] - INFO [main:ClientBase@513] - STOPPING server 2016-10-04 01:04:09,218 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16609 2016-10-04 01:04:09,224 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:04:09,224 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:09,224 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:04:09,225 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:04:09,225 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:04:09,225 [myid:] - INFO [ProcessThread(sid:0 cport:16609)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:04:09,225 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited! 2016-10-04 01:04:09,226 [myid:] - INFO [main:FinalRequestProcessor@479] - shutdown of request processor complete 2016-10-04 01:04:09,226 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16609,name1=InMemoryDataTree] 2016-10-04 01:04:09,226 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16609] 2016-10-04 01:04:09,227 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16609 2016-10-04 01:04:09,228 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-10-04 01:04:09,232 [myid:] - INFO [main:ClientBase@568] - fdcount after test is: 59 at start it was 60 2016-10-04 01:04:09,233 [myid:] - INFO [main:AsyncOpsTest@63] - Test clients shutting down 2016-10-04 01:04:09,234 [myid:] - INFO [main:ZKTestCase$1@65] - SUCCEEDED testAsyncMulti 2016-10-04 01:04:09,234 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testAsyncMulti 2016-10-04 01:04:09,234 [myid:] - INFO [main:PortAssignment@85] - Assigned port 16610 from range 16607 - 19299. 2016-10-04 01:04:09,235 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testAsyncMultiSequential_NoSideEffect 2016-10-04 01:04:09,235 [myid:] - INFO [main:ClientBase@448] - Initial fdcount is: 59 2016-10-04 01:04:09,243 [myid:] - INFO [main:ClientBase@466] - STARTING server 2016-10-04 01:04:09,243 [myid:] - INFO [main:ClientBase@386] - CREATING server instance 127.0.0.1:16610 2016-10-04 01:04:09,250 [myid:] - INFO [main:ClientBase@361] - STARTING server instance 127.0.0.1:16610 2016-10-04 01:04:09,255 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:04:09,255 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:04:09,255 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test7939377037580146364.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test7939377037580146364.junit.dir/version-2 2016-10-04 01:04:09,256 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16610 2016-10-04 01:04:09,257 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test7939377037580146364.junit.dir/version-2/snapshot.0 2016-10-04 01:04:09,258 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:09,258 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16610 2016-10-04 01:04:09,260 [myid:] - INFO [New I/O worker #133:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:34416 2016-10-04 01:04:09,260 [myid:] - INFO [New I/O worker #133:StatCommand@49] - Stat command output 2016-10-04 01:04:09,261 [myid:] - INFO [main:JMXEnv@228] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-10-04 01:04:09,262 [myid:] - INFO [main:JMXEnv@245] - expect:InMemoryDataTree 2016-10-04 01:04:09,263 [myid:] - INFO [main:JMXEnv@249] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port16610,name1=InMemoryDataTree 2016-10-04 01:04:09,263 [myid:] - INFO [main:JMXEnv@245] - expect:StandaloneServer_port 2016-10-04 01:04:09,263 [myid:] - INFO [main:JMXEnv@249] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port16610 2016-10-04 01:04:09,264 [myid:] - INFO [main:ClientBase@462] - Client test setup finished 2016-10-04 01:04:09,264 [myid:] - INFO [main:AsyncOpsTest@50] - Creating client testAsyncMultiSequential_NoSideEffect 2016-10-04 01:04:09,264 [myid:] - INFO [main:ZooKeeper@853] - Initiating client connection, connectString=127.0.0.1:16610 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@9a3da81 2016-10-04 01:04:09,266 [myid:127.0.0.1:16610] - INFO [main-SendThread(127.0.0.1:16610):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16610. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:04:09,266 [myid:127.0.0.1:16610] - INFO [main-SendThread(127.0.0.1:16610):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:34417, server: 127.0.0.1/127.0.0.1:16610 2016-10-04 01:04:09,267 [myid:] - INFO [New I/O worker #134:ZooKeeperServer@995] - Client attempting to establish new session at /127.0.0.1:34417 2016-10-04 01:04:09,267 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.1 2016-10-04 01:04:09,305 [myid:] - INFO [SyncThread:0:ZooKeeperServer@709] - Established session 0x10020f039c90000 with negotiated timeout 30000 for client /127.0.0.1:34417 2016-10-04 01:04:09,305 [myid:127.0.0.1:16610] - INFO [main-SendThread(127.0.0.1:16610):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16610, sessionid = 0x10020f039c90000, negotiated timeout = 30000 2016-10-04 01:04:09,308 [myid:] - INFO [main:JMXEnv@117] - expect:0x10020f039c90000 2016-10-04 01:04:09,308 [myid:] - INFO [main:JMXEnv@120] - found:0x10020f039c90000 org.apache.ZooKeeperService:name0=StandaloneServer_port16610,name1=Connections,name2=127.0.0.1,name3=0x10020f039c90000 2016-10-04 01:04:09,309 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testAsyncMultiSequential_NoSideEffect 2016-10-04 01:04:09,309 [myid:] - INFO [New I/O worker #134:ZooKeeperServer@1032] - got auth packet /127.0.0.1:34417 2016-10-04 01:04:09,310 [myid:] - INFO [New I/O worker #134:ZooKeeperServer@1050] - auth success /127.0.0.1:34417 2016-10-04 01:04:09,384 [myid:] - INFO [ProcessThread(sid:0 cport:16610)::PrepRequestProcessor@790] - Got user-level KeeperException when processing sessionid:0x10020f039c90000 type:multi cxid:0x4 zxid:0x4 txntype:2 reqpath:n/a aborting remaining multi ops. Error Path:/nonexist Error:KeeperErrorCode = NoNode for /nonexist 2016-10-04 01:04:09,430 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 62828 2016-10-04 01:04:09,430 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 56 2016-10-04 01:04:09,430 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testAsyncMultiSequential_NoSideEffect 2016-10-04 01:04:09,431 [myid:] - INFO [ProcessThread(sid:0 cport:16610)::PrepRequestProcessor@657] - Processed session termination for sessionid: 0x10020f039c90000 2016-10-04 01:04:09,454 [myid:] - WARN [New I/O worker #134:NettyServerCnxnFactory$CnxnChannelHandler@142] - Exception caught [id: 0x0743662e, /127.0.0.1:34417 => /127.0.0.1:16610] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-10-04 01:04:09,454 [myid:] - INFO [SyncThread:0:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16610,name1=Connections,name2=127.0.0.1,name3=0x10020f039c90000] 2016-10-04 01:04:09,555 [myid:] - INFO [main:ZooKeeper@1311] - Session: 0x10020f039c90000 closed 2016-10-04 01:04:09,555 [myid:] - INFO [main:ClientBase@543] - tearDown starting 2016-10-04 01:04:09,555 [myid:] - INFO [main:ClientBase@513] - STOPPING server 2016-10-04 01:04:09,556 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16610 2016-10-04 01:04:09,555 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for session: 0x10020f039c90000 2016-10-04 01:04:09,562 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:04:09,562 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:04:09,562 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:04:09,563 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:04:09,563 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:04:09,563 [myid:] - INFO [ProcessThread(sid:0 cport:16610)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:0 ...[truncated 6640749 chars]... ting 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-10-04 01:14:30,775 [myid:127.0.0.1:16699] - INFO [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16699. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:30,775 [myid:127.0.0.1:16699] - WARN [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1235] - Session 0x70020f2f1ed0001 for server 127.0.0.1/127.0.0.1:16699, 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-10-04 01:14:30,826 [myid:127.0.0.1:16690] - INFO [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16690. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:30,826 [myid:127.0.0.1:16690] - WARN [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1235] - Session 0x40020f2e0da0001 for server 127.0.0.1/127.0.0.1:16690, 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-10-04 01:14:30,912 [myid:] - INFO [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop! 2016-10-04 01:14:30,913 [myid:] - INFO [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop! 2016-10-04 01:14:30,913 [myid:] - INFO [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop! 2016-10-04 01:14:30,981 [myid:127.0.0.1:16696] - INFO [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16696. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:30,982 [myid:127.0.0.1:16696] - WARN [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1235] - Session 0x60020f2ea050001 for server 127.0.0.1/127.0.0.1:16696, 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-10-04 01:14:31,050 [myid:127.0.0.1:16681] - INFO [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16681. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,051 [myid:127.0.0.1:16681] - WARN [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1235] - Session 0x10020f2dfad0001 for server 127.0.0.1/127.0.0.1:16681, 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-10-04 01:14:31,051 [myid:127.0.0.1:16687] - INFO [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16687. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,051 [myid:127.0.0.1:16687] - WARN [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1235] - Session 0x30020f2dfad0001 for server 127.0.0.1/127.0.0.1:16687, 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-10-04 01:14:31,073 [myid:127.0.0.1:16693] - INFO [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16693. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,074 [myid:127.0.0.1:16693] - WARN [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1235] - Session 0x50020f2e0e30001 for server 127.0.0.1/127.0.0.1:16693, 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-10-04 01:14:31,152 [myid:127.0.0.1:16729] - INFO [main-SendThread(127.0.0.1:16729):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16729. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,152 [myid:127.0.0.1:16729] - WARN [main-SendThread(127.0.0.1:16729):ClientCnxn$SendThread@1235] - Session 0x10020f685ea0000 for server 127.0.0.1/127.0.0.1:16729, 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-10-04 01:14:31,190 [myid:127.0.0.1:16681] - INFO [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16681. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,190 [myid:127.0.0.1:16681] - WARN [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1235] - Session 0x10020f2dfad0000 for server 127.0.0.1/127.0.0.1:16681, 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-10-04 01:14:31,315 [myid:] - INFO [main:ClientBase@466] - STARTING server 2016-10-04 01:14:31,315 [myid:] - INFO [main:ClientBase@386] - CREATING server instance 127.0.0.1:16852 2016-10-04 01:14:31,324 [myid:] - INFO [main:ClientBase@361] - STARTING server instance 127.0.0.1:16852 2016-10-04 01:14:31,324 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:14:31,324 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:14:31,324 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2 2016-10-04 01:14:31,324 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16852 2016-10-04 01:14:31,325 [myid:] - INFO [main:FileSnap@83] - Reading snapshot /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2/snapshot.3 2016-10-04 01:14:31,326 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0x5 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2/snapshot.5 2016-10-04 01:14:31,327 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:14:31,328 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16852 2016-10-04 01:14:31,329 [myid:] - INFO [New I/O worker #6601:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:38348 2016-10-04 01:14:31,329 [myid:] - INFO [New I/O worker #6601:StatCommand@49] - Stat command output 2016-10-04 01:14:31,329 [myid:] - INFO [main:JMXEnv@228] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-10-04 01:14:31,331 [myid:] - INFO [main:JMXEnv@245] - expect:InMemoryDataTree 2016-10-04 01:14:31,331 [myid:] - INFO [main:JMXEnv@249] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port16852,name1=InMemoryDataTree 2016-10-04 01:14:31,331 [myid:] - INFO [main:JMXEnv@245] - expect:StandaloneServer_port 2016-10-04 01:14:31,331 [myid:] - INFO [main:JMXEnv@249] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port16852 2016-10-04 01:14:31,433 [myid:127.0.0.1:16699] - INFO [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16699. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,434 [myid:127.0.0.1:16699] - WARN [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1235] - Session 0x70020f2f1ed0000 for server 127.0.0.1/127.0.0.1:16699, 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-10-04 01:14:31,554 [myid:127.0.0.1:16684] - INFO [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16684. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,554 [myid:127.0.0.1:16684] - WARN [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1235] - Session 0x20020f2dfad0000 for server 127.0.0.1/127.0.0.1:16684, 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-10-04 01:14:31,673 [myid:127.0.0.1:16732] - INFO [main-SendThread(127.0.0.1:16732):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16732. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,674 [myid:127.0.0.1:16732] - WARN [main-SendThread(127.0.0.1:16732):ClientCnxn$SendThread@1235] - Session 0x20020f689b10000 for server 127.0.0.1/127.0.0.1:16732, 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-10-04 01:14:31,865 [myid:127.0.0.1:16735] - INFO [main-SendThread(127.0.0.1:16735):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16735. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,865 [myid:127.0.0.1:16735] - WARN [main-SendThread(127.0.0.1:16735):ClientCnxn$SendThread@1235] - Session 0x30020f6861c0000 for server 127.0.0.1/127.0.0.1:16735, 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-10-04 01:14:31,926 [myid:127.0.0.1:16684] - INFO [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16684. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,926 [myid:127.0.0.1:16684] - WARN [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1235] - Session 0x20020f2dfad0001 for server 127.0.0.1/127.0.0.1:16684, 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-10-04 01:14:31,964 [myid:127.0.0.1:16693] - INFO [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16693. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:31,964 [myid:127.0.0.1:16693] - WARN [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1235] - Session 0x50020f2e0e30000 for server 127.0.0.1/127.0.0.1:16693, 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-10-04 01:14:32,120 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16608. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,120 [myid:127.0.0.1:16608] - WARN [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1235] - Session 0x10020f0235b0000 for server 127.0.0.1/127.0.0.1:16608, 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-10-04 01:14:32,158 [myid:127.0.0.1:16690] - INFO [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16690. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,158 [myid:127.0.0.1:16690] - WARN [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1235] - Session 0x40020f2e0da0000 for server 127.0.0.1/127.0.0.1:16690, 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-10-04 01:14:32,201 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16852. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,201 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:38382, server: 127.0.0.1/127.0.0.1:16852 2016-10-04 01:14:32,202 [myid:] - INFO [New I/O worker #6602:ZooKeeperServer@1000] - Client attempting to renew session 0x10020f9ae620000 at /127.0.0.1:38382 2016-10-04 01:14:32,203 [myid:] - INFO [New I/O worker #6602:ZooKeeperServer@709] - Established session 0x10020f9ae620000 with negotiated timeout 6000 for client /127.0.0.1:38382 2016-10-04 01:14:32,203 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16852, sessionid = 0x10020f9ae620000, negotiated timeout = 6000 2016-10-04 01:14:32,210 [myid:127.0.0.1:16687] - INFO [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16687. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,210 [myid:127.0.0.1:16687] - WARN [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1235] - Session 0x30020f2dfad0001 for server 127.0.0.1/127.0.0.1:16687, 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-10-04 01:14:32,210 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.6 2016-10-04 01:14:32,248 [myid:] - INFO [main:ClientBase@513] - STOPPING server 2016-10-04 01:14:32,248 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16852 2016-10-04 01:14:32,248 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@1231] - Unable to read additional data from server sessionid 0x10020f9ae620000, likely server has closed socket, closing socket connection and attempting reconnect 2016-10-04 01:14:32,248 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16852,name1=Connections,name2=127.0.0.1,name3=0x10020f9ae620000] 2016-10-04 01:14:32,254 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:14:32,254 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:14:32,254 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:14:32,254 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:14:32,254 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:14:32,254 [myid:] - INFO [ProcessThread(sid:0 cport:16852)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:14:32,255 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited! 2016-10-04 01:14:32,255 [myid:] - INFO [main:FinalRequestProcessor@479] - shutdown of request processor complete 2016-10-04 01:14:32,255 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16852,name1=InMemoryDataTree] 2016-10-04 01:14:32,255 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16852] 2016-10-04 01:14:32,256 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16852 2016-10-04 01:14:32,256 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-10-04 01:14:32,349 [myid:] - INFO [main:ClientBase@466] - STARTING server 2016-10-04 01:14:32,349 [myid:] - INFO [main:ClientBase@386] - CREATING server instance 127.0.0.1:16852 2016-10-04 01:14:32,356 [myid:] - INFO [main:ClientBase@361] - STARTING server instance 127.0.0.1:16852 2016-10-04 01:14:32,356 [myid:] - INFO [main:ZooKeeperServer@889] - minSessionTimeout set to 6000 2016-10-04 01:14:32,356 [myid:] - INFO [main:ZooKeeperServer@898] - maxSessionTimeout set to 60000 2016-10-04 01:14:32,356 [myid:] - INFO [main:ZooKeeperServer@159] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2 2016-10-04 01:14:32,356 [myid:] - INFO [main:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:16852 2016-10-04 01:14:32,357 [myid:] - INFO [main:FileSnap@83] - Reading snapshot /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2/snapshot.5 2016-10-04 01:14:32,358 [myid:] - INFO [main:FileTxnSnapLog@306] - Snapshotting: 0x6 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/build/test/tmp/test8970971002755443544.junit.dir/version-2/snapshot.6 2016-10-04 01:14:32,359 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:14:32,359 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16852 2016-10-04 01:14:32,360 [myid:] - INFO [New I/O worker #6634:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:38388 2016-10-04 01:14:32,360 [myid:] - INFO [New I/O worker #6634:StatCommand@49] - Stat command output 2016-10-04 01:14:32,361 [myid:] - INFO [main:JMXEnv@228] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-10-04 01:14:32,362 [myid:] - INFO [main:JMXEnv@245] - expect:InMemoryDataTree 2016-10-04 01:14:32,362 [myid:] - INFO [main:JMXEnv@249] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port16852,name1=InMemoryDataTree 2016-10-04 01:14:32,362 [myid:] - INFO [main:JMXEnv@245] - expect:StandaloneServer_port 2016-10-04 01:14:32,362 [myid:] - INFO [main:JMXEnv@249] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port16852 2016-10-04 01:14:32,422 [myid:127.0.0.1:16687] - INFO [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16687. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,422 [myid:127.0.0.1:16687] - WARN [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1235] - Session 0x30020f2dfad0000 for server 127.0.0.1/127.0.0.1:16687, 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-10-04 01:14:32,527 [myid:127.0.0.1:16696] - INFO [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16696. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,528 [myid:127.0.0.1:16696] - WARN [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1235] - Session 0x60020f2ea050001 for server 127.0.0.1/127.0.0.1:16696, 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-10-04 01:14:32,580 [myid:127.0.0.1:16699] - INFO [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16699. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,581 [myid:127.0.0.1:16699] - WARN [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1235] - Session 0x70020f2f1ed0000 for server 127.0.0.1/127.0.0.1:16699, 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-10-04 01:14:32,718 [myid:127.0.0.1:16699] - INFO [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16699. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,718 [myid:127.0.0.1:16699] - WARN [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1235] - Session 0x70020f2f1ed0001 for server 127.0.0.1/127.0.0.1:16699, 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-10-04 01:14:32,737 [myid:127.0.0.1:16696] - INFO [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16696. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,737 [myid:127.0.0.1:16696] - WARN [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1235] - Session 0x60020f2ea050000 for server 127.0.0.1/127.0.0.1:16696, 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-10-04 01:14:32,791 [myid:127.0.0.1:16690] - INFO [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16690. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,791 [myid:127.0.0.1:16690] - WARN [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1235] - Session 0x40020f2e0da0001 for server 127.0.0.1/127.0.0.1:16690, 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-10-04 01:14:32,853 [myid:127.0.0.1:16729] - INFO [main-SendThread(127.0.0.1:16729):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16729. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,853 [myid:127.0.0.1:16729] - WARN [main-SendThread(127.0.0.1:16729):ClientCnxn$SendThread@1235] - Session 0x10020f685ea0000 for server 127.0.0.1/127.0.0.1:16729, 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-10-04 01:14:32,913 [myid:127.0.0.1:16681] - INFO [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16681. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,913 [myid:127.0.0.1:16681] - WARN [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1235] - Session 0x10020f2dfad0000 for server 127.0.0.1/127.0.0.1:16681, 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-10-04 01:14:32,975 [myid:127.0.0.1:16684] - INFO [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16684. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:32,975 [myid:127.0.0.1:16684] - WARN [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1235] - Session 0x20020f2dfad0000 for server 127.0.0.1/127.0.0.1:16684, 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-10-04 01:14:33,037 [myid:127.0.0.1:16684] - INFO [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16684. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,037 [myid:127.0.0.1:16684] - WARN [main-SendThread(127.0.0.1:16684):ClientCnxn$SendThread@1235] - Session 0x20020f2dfad0001 for server 127.0.0.1/127.0.0.1:16684, 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-10-04 01:14:33,077 [myid:127.0.0.1:16681] - INFO [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16681. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,078 [myid:127.0.0.1:16681] - WARN [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1235] - Session 0x10020f2dfad0001 for server 127.0.0.1/127.0.0.1:16681, 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-10-04 01:14:33,113 [myid:127.0.0.1:16693] - INFO [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16693. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,114 [myid:127.0.0.1:16693] - WARN [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1235] - Session 0x50020f2e0e30001 for server 127.0.0.1/127.0.0.1:16693, 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-10-04 01:14:33,128 [myid:127.0.0.1:16693] - INFO [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16693. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,130 [myid:127.0.0.1:16693] - WARN [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1235] - Session 0x50020f2e0e30000 for server 127.0.0.1/127.0.0.1:16693, 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-10-04 01:14:33,133 [myid:127.0.0.1:16732] - INFO [main-SendThread(127.0.0.1:16732):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16732. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,134 [myid:127.0.0.1:16732] - WARN [main-SendThread(127.0.0.1:16732):ClientCnxn$SendThread@1235] - Session 0x20020f689b10000 for server 127.0.0.1/127.0.0.1:16732, 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-10-04 01:14:33,361 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16852. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,362 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:38420, server: 127.0.0.1/127.0.0.1:16852 2016-10-04 01:14:33,362 [myid:] - INFO [New I/O worker #6635:ZooKeeperServer@1000] - Client attempting to renew session 0x10020f9ae620000 at /127.0.0.1:38420 2016-10-04 01:14:33,363 [myid:] - INFO [New I/O worker #6635:ZooKeeperServer@709] - Established session 0x10020f9ae620000 with negotiated timeout 6000 for client /127.0.0.1:38420 2016-10-04 01:14:33,363 [myid:127.0.0.1:16852] - INFO [main-SendThread(127.0.0.1:16852):ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:16852, sessionid = 0x10020f9ae620000, negotiated timeout = 6000 2016-10-04 01:14:33,368 [myid:] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.7 2016-10-04 01:14:33,548 [myid:127.0.0.1:16608] - INFO [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16608. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,548 [myid:127.0.0.1:16608] - WARN [main-SendThread(127.0.0.1:16608):ClientCnxn$SendThread@1235] - Session 0x10020f0235b0000 for server 127.0.0.1/127.0.0.1:16608, 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-10-04 01:14:33,724 [myid:127.0.0.1:16699] - INFO [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16699. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,724 [myid:127.0.0.1:16699] - WARN [main-SendThread(127.0.0.1:16699):ClientCnxn$SendThread@1235] - Session 0x70020f2f1ed0000 for server 127.0.0.1/127.0.0.1:16699, 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-10-04 01:14:33,875 [myid:127.0.0.1:16690] - INFO [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16690. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,875 [myid:127.0.0.1:16690] - WARN [main-SendThread(127.0.0.1:16690):ClientCnxn$SendThread@1235] - Session 0x40020f2e0da0000 for server 127.0.0.1/127.0.0.1:16690, 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-10-04 01:14:33,881 [myid:127.0.0.1:16735] - INFO [main-SendThread(127.0.0.1:16735):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16735. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,881 [myid:127.0.0.1:16735] - WARN [main-SendThread(127.0.0.1:16735):ClientCnxn$SendThread@1235] - Session 0x30020f6861c0000 for server 127.0.0.1/127.0.0.1:16735, 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-10-04 01:14:33,899 [myid:127.0.0.1:16696] - INFO [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16696. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,899 [myid:127.0.0.1:16696] - WARN [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1235] - Session 0x60020f2ea050000 for server 127.0.0.1/127.0.0.1:16696, 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-10-04 01:14:33,912 [myid:] - INFO [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop! 2016-10-04 01:14:33,929 [myid:127.0.0.1:16696] - INFO [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16696. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:33,930 [myid:127.0.0.1:16696] - WARN [main-SendThread(127.0.0.1:16696):ClientCnxn$SendThread@1235] - Session 0x60020f2ea050001 for server 127.0.0.1/127.0.0.1:16696, 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-10-04 01:14:34,202 [myid:127.0.0.1:16687] - INFO [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16687. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:34,202 [myid:127.0.0.1:16687] - WARN [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1235] - Session 0x30020f2dfad0000 for server 127.0.0.1/127.0.0.1:16687, 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-10-04 01:14:34,233 [myid:127.0.0.1:16687] - INFO [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16687. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:34,233 [myid:127.0.0.1:16687] - WARN [main-SendThread(127.0.0.1:16687):ClientCnxn$SendThread@1235] - Session 0x30020f2dfad0001 for server 127.0.0.1/127.0.0.1:16687, 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-10-04 01:14:34,240 [myid:127.0.0.1:16693] - INFO [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16693. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:34,241 [myid:127.0.0.1:16693] - WARN [main-SendThread(127.0.0.1:16693):ClientCnxn$SendThread@1235] - Session 0x50020f2e0e30000 for server 127.0.0.1/127.0.0.1:16693, 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-10-04 01:14:34,349 [myid:127.0.0.1:16681] - INFO [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16681. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:34,350 [myid:127.0.0.1:16681] - WARN [main-SendThread(127.0.0.1:16681):ClientCnxn$SendThread@1235] - Session 0x10020f2dfad0001 for server 127.0.0.1/127.0.0.1:16681, 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-10-04 01:14:34,424 [myid:] - INFO [ProcessThread(sid:0 cport:16852)::PrepRequestProcessor@657] - Processed session termination for sessionid: 0x10020f9ae620000 2016-10-04 01:14:34,432 [myid:] - WARN [New I/O worker #6635:NettyServerCnxnFactory$CnxnChannelHandler@142] - Exception caught [id: 0xfb034ea1, /127.0.0.1:38420 :> /127.0.0.1:16852] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-10-04 01:14:34,432 [myid:] - INFO [SyncThread:0:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16852,name1=Connections,name2=127.0.0.1,name3=0x10020f9ae620000] 2016-10-04 01:14:34,473 [myid:127.0.0.1:16729] - INFO [main-SendThread(127.0.0.1:16729):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:16729. Will not attempt to authenticate using SASL (unknown error) 2016-10-04 01:14:34,474 [myid:127.0.0.1:16729] - WARN [main-SendThread(127.0.0.1:16729):ClientCnxn$SendThread@1235] - Session 0x10020f685ea0000 for server 127.0.0.1/127.0.0.1:16729, 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-10-04 01:14:34,532 [myid:] - INFO [main:ZooKeeper@1311] - Session: 0x10020f9ae620000 closed 2016-10-04 01:14:34,532 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 187485 2016-10-04 01:14:34,532 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 1671 2016-10-04 01:14:34,533 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testWatcherAutoResetWithLocal 2016-10-04 01:14:34,533 [myid:] - INFO [main:ClientBase@543] - tearDown starting 2016-10-04 01:14:34,533 [myid:] - INFO [main:ClientBase@513] - STOPPING server 2016-10-04 01:14:34,533 [myid:] - INFO [main:NettyServerCnxnFactory@464] - shutdown called 0.0.0.0/0.0.0.0:16852 2016-10-04 01:14:34,532 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for session: 0x10020f9ae620000 2016-10-04 01:14:34,538 [myid:] - INFO [main:ZooKeeperServer@529] - shutting down 2016-10-04 01:14:34,539 [myid:] - ERROR [main:ZooKeeperServer@501] - ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes 2016-10-04 01:14:34,539 [myid:] - INFO [main:SessionTrackerImpl@232] - Shutting down 2016-10-04 01:14:34,539 [myid:] - INFO [main:PrepRequestProcessor@975] - Shutting down 2016-10-04 01:14:34,539 [myid:] - INFO [main:SyncRequestProcessor@191] - Shutting down 2016-10-04 01:14:34,539 [myid:] - INFO [ProcessThread(sid:0 cport:16852)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop! 2016-10-04 01:14:34,539 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited! 2016-10-04 01:14:34,539 [myid:] - INFO [main:FinalRequestProcessor@479] - shutdown of request processor complete 2016-10-04 01:14:34,540 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16852,name1=InMemoryDataTree] 2016-10-04 01:14:34,540 [myid:] - INFO [main:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port16852] 2016-10-04 01:14:34,540 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 16852 2016-10-04 01:14:34,541 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-10-04 01:14:34,547 [myid:] - INFO [main:ClientBase@568] - fdcount after test is: 4887 at start it was 4887 2016-10-04 01:14:34,547 [myid:] - INFO [main:ZKTestCase$1@65] - SUCCEEDED testWatcherAutoResetWithLocal 2016-10-04 01:14:34,547 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testWatcherAutoResetWithLocal {noformat}

    Apache's JIRA Issue Tracker | 2 months ago | Michael Han
    java.net.ConnectException: Connection refused
  3. 0

    Titan + HBase on a MapR Hadoop Cluster is it possible and how?

    Google Groups | 2 years ago | Blagovest Trenchev
    java.net.ConnectException: Connection refused
  4. Speed up your debug routine!

    Automated exception search integrated into your IDE

  5. 0

    I meet a problem when I use standalone Spark cluster mode

    Google Groups | 1 year ago | rht sjz
    java.net.ConnectException: Connection refused

  1. RoiOtero 525 times, last 2 weeks ago
  2. nasimk 1595 times, last 4 days ago
  3. Raggyman 30496 times, last 2 months ago
  4. Piz 204 times, last 4 months ago
  5. nasimk 78 times, last 5 months ago
10 more registered users
78 unregistered visitors
Not finding the right solution?
Take a tour to get the most out of Samebug.

Tired of useless tips?

Automated exception search integrated into your IDE

Root Cause Analysis

  1. java.net.ConnectException

    Connection refused

    at sun.nio.ch.SocketChannelImpl.checkConnect()
  2. Java RT
    SocketChannelImpl.finishConnect
    1. sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
    2. sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744)
    2 frames
  3. Zookeeper
    ClientCnxn$SendThread.run
    1. org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:357)
    2. org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1214)
    2 frames