Error Message
waiting for server 0 being up
Stacktrace
junit.framework.AssertionFailedError: waiting for server 0 being up
at org.apache.zookeeper.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
Standard Output
2016-08-03 05:33:41,529 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods.
2016-08-03 05:33:41,594 [myid:] - INFO [main:JUnit4ZKTestRunner@47] - No test.method specified. using default methods.
2016-08-03 05:33:41,608 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testSecureQuorumServer
2016-08-03 05:33:41,611 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testSecureQuorumServer
2016-08-03 05:33:41,614 [myid:] - INFO [main:PortAssignment@151] - Test process 8/8 using ports from 30072 - 32764.
2016-08-03 05:33:41,616 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30073 from range 30072 - 32764.
2016-08-03 05:33:41,617 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30074 from range 30072 - 32764.
2016-08-03 05:33:41,617 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30075 from range 30072 - 32764.
2016-08-03 05:33:41,617 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30076 from range 30072 - 32764.
2016-08-03 05:33:41,618 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30077 from range 30072 - 32764.
2016-08-03 05:33:41,618 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30078 from range 30072 - 32764.
2016-08-03 05:33:41,618 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30079 from range 30072 - 32764.
2016-08-03 05:33:41,619 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30080 from range 30072 - 32764.
2016-08-03 05:33:41,619 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30081 from range 30072 - 32764.
2016-08-03 05:33:41,620 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30082 from range 30072 - 32764.
2016-08-03 05:33:41,620 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30083 from range 30072 - 32764.
2016-08-03 05:33:41,623 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30084 from range 30072 - 32764.
2016-08-03 05:33:41,641 [myid:] - INFO [main:QuorumPeerTestBase$MainThread@131] - id = 0 tmpDir = /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test8166855371662584608.junit.dir clientPort = -1 adminServerPort = 8080
2016-08-03 05:33:41,647 [myid:] - INFO [main:QuorumPeerTestBase$MainThread@131] - id = 1 tmpDir = /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test5311610672905591522.junit.dir clientPort = -1 adminServerPort = 8080
2016-08-03 05:33:41,648 [myid:] - INFO [main:QuorumPeerTestBase$MainThread@131] - id = 2 tmpDir = /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test4754133370740902988.junit.dir clientPort = -1 adminServerPort = 8080
2016-08-03 05:33:41,651 [myid:] - INFO [Thread-1:QuorumPeerConfig@116] - Reading configuration from: /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test5311610672905591522.junit.dir/zoo.cfg
2016-08-03 05:33:41,651 [myid:] - INFO [Thread-0:QuorumPeerConfig@116] - Reading configuration from: /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test8166855371662584608.junit.dir/zoo.cfg
2016-08-03 05:33:41,651 [myid:] - INFO [Thread-2:QuorumPeerConfig@116] - Reading configuration from: /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test4754133370740902988.junit.dir/zoo.cfg
2016-08-03 05:33:41,651 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:41,653 [myid:] - INFO [Thread-2:QuorumPeerConfig@308] - clientPort is not set
2016-08-03 05:33:41,653 [myid:] - INFO [Thread-1:QuorumPeerConfig@308] - clientPort is not set
2016-08-03 05:33:41,653 [myid:] - INFO [Thread-1:QuorumPeerConfig@332] - secureClientPortAddress is 0.0.0.0/0.0.0.0:30078
2016-08-03 05:33:41,653 [myid:] - INFO [Thread-0:QuorumPeerConfig@308] - clientPort is not set
2016-08-03 05:33:41,653 [myid:] - INFO [Thread-2:QuorumPeerConfig@332] - secureClientPortAddress is 0.0.0.0/0.0.0.0:30082
2016-08-03 05:33:41,653 [myid:] - INFO [Thread-0:QuorumPeerConfig@332] - secureClientPortAddress is 0.0.0.0/0.0.0.0:30074
2016-08-03 05:33:41,655 [myid:] - INFO [main:ClientBase@248] - server 127.0.0.1:30073 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.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
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.RunBefores.evaluate(RunBefores.java:26)
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-08-03 05:33:41,664 [myid:1] - INFO [Thread-1:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2016-08-03 05:33:41,664 [myid:1] - INFO [Thread-1:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2016-08-03 05:33:41,664 [myid:1] - INFO [Thread-1:DatadirCleanupManager@101] - Purge task is not scheduled.
2016-08-03 05:33:41,664 [myid:2] - INFO [Thread-2:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2016-08-03 05:33:41,665 [myid:2] - INFO [Thread-2:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2016-08-03 05:33:41,665 [myid:2] - INFO [Thread-2:DatadirCleanupManager@101] - Purge task is not scheduled.
2016-08-03 05:33:41,664 [myid:0] - INFO [Thread-0:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2016-08-03 05:33:41,665 [myid:0] - INFO [Thread-0:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2016-08-03 05:33:41,665 [myid:0] - INFO [Thread-0:DatadirCleanupManager@101] - Purge task is not scheduled.
2016-08-03 05:33:41,665 [myid:1] - INFO [Thread-1:ManagedUtil@46] - Log4j found with jmx enabled.
2016-08-03 05:33:41,665 [myid:2] - INFO [Thread-2:ManagedUtil@46] - Log4j found with jmx enabled.
2016-08-03 05:33:41,665 [myid:0] - INFO [Thread-0:ManagedUtil@46] - Log4j found with jmx enabled.
2016-08-03 05:33:41,734 [myid:0] - ERROR [Thread-0:AppenderDynamicMBean@209] - Could not add DynamicLayoutMBean for [CONSOLE,layout=org.apache.log4j.PatternLayout].
javax.management.InstanceAlreadyExistsException: log4j:appender=CONSOLE,layout=org.apache.log4j.PatternLayout
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.AppenderDynamicMBean.registerLayoutMBean(AppenderDynamicMBean.java:203)
at org.apache.log4j.jmx.AppenderDynamicMBean.preRegister(AppenderDynamicMBean.java:339)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.preRegister(DefaultMBeanServerInterceptor.java:1007)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:919)
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.LoggerDynamicMBean.registerAppenderMBean(LoggerDynamicMBean.java:264)
at org.apache.log4j.jmx.LoggerDynamicMBean.appenderMBeanRegistration(LoggerDynamicMBean.java:252)
at org.apache.log4j.jmx.LoggerDynamicMBean.postRegister(LoggerDynamicMBean.java:280)
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.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-08-03 05:33:41,735 [myid:1] - ERROR [Thread-1: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-08-03 05:33:41,734 [myid:2] - ERROR [Thread-2:AppenderDynamicMBean@209] - Could not add DynamicLayoutMBean for [CONSOLE,layout=org.apache.log4j.PatternLayout].
javax.management.InstanceAlreadyExistsException: log4j:appender=CONSOLE,layout=org.apache.log4j.PatternLayout
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.AppenderDynamicMBean.registerLayoutMBean(AppenderDynamicMBean.java:203)
at org.apache.log4j.jmx.AppenderDynamicMBean.preRegister(AppenderDynamicMBean.java:339)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.preRegister(DefaultMBeanServerInterceptor.java:1007)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:919)
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.LoggerDynamicMBean.registerAppenderMBean(LoggerDynamicMBean.java:264)
at org.apache.log4j.jmx.LoggerDynamicMBean.appenderMBeanRegistration(LoggerDynamicMBean.java:252)
at org.apache.log4j.jmx.LoggerDynamicMBean.postRegister(LoggerDynamicMBean.java:280)
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.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-08-03 05:33:41,737 [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-08-03 05:33:41,736 [myid:0] - ERROR [Thread-0:LoggerDynamicMBean@270] - Could not add appenderMBean for [CONSOLE].
javax.management.InstanceAlreadyExistsException: log4j:appender=CONSOLE
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.LoggerDynamicMBean.registerAppenderMBean(LoggerDynamicMBean.java:264)
at org.apache.log4j.jmx.LoggerDynamicMBean.appenderMBeanRegistration(LoggerDynamicMBean.java:252)
at org.apache.log4j.jmx.LoggerDynamicMBean.postRegister(LoggerDynamicMBean.java:280)
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.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-08-03 05:33:41,739 [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-08-03 05:33:41,738 [myid:2] - ERROR [Thread-2:LoggerDynamicMBean@270] - Could not add appenderMBean for [CONSOLE].
javax.management.InstanceAlreadyExistsException: log4j:appender=CONSOLE
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.LoggerDynamicMBean.registerAppenderMBean(LoggerDynamicMBean.java:264)
at org.apache.log4j.jmx.LoggerDynamicMBean.appenderMBeanRegistration(LoggerDynamicMBean.java:252)
at org.apache.log4j.jmx.LoggerDynamicMBean.postRegister(LoggerDynamicMBean.java:280)
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.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-08-03 05:33:41,740 [myid:1] - INFO [Thread-1:QuorumPeerMain@136] - Starting quorum peer
2016-08-03 05:33:41,742 [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-08-03 05:33:41,743 [myid:2] - ERROR [Thread-2: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-08-03 05:33:41,743 [myid:2] - WARN [Thread-2: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-08-03 05:33:41,744 [myid:2] - INFO [Thread-2:QuorumPeerMain@136] - Starting quorum peer
2016-08-03 05:33:41,746 [myid:0] - INFO [Thread-0:QuorumPeerMain@136] - Starting quorum peer
2016-08-03 05:33:41,909 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:41,910 [myid:] - INFO [main:ClientBase@248] - server 127.0.0.1:30073 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.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
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.RunBefores.evaluate(RunBefores.java:26)
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-08-03 05:33:41,949 [myid:2] - INFO [Thread-2:QuorumPeer@1327] - Local sessions disabled
2016-08-03 05:33:41,949 [myid:1] - INFO [Thread-1:QuorumPeer@1327] - Local sessions disabled
2016-08-03 05:33:41,949 [myid:1] - INFO [Thread-1:QuorumPeer@1338] - Local session upgrading disabled
2016-08-03 05:33:41,949 [myid:0] - INFO [Thread-0:QuorumPeer@1327] - Local sessions disabled
2016-08-03 05:33:41,950 [myid:0] - INFO [Thread-0:QuorumPeer@1338] - Local session upgrading disabled
2016-08-03 05:33:41,949 [myid:1] - INFO [Thread-1:QuorumPeer@1305] - tickTime set to 4000
2016-08-03 05:33:41,950 [myid:1] - INFO [Thread-1:QuorumPeer@1349] - minSessionTimeout set to 8000
2016-08-03 05:33:41,950 [myid:1] - INFO [Thread-1:QuorumPeer@1360] - maxSessionTimeout set to 80000
2016-08-03 05:33:41,950 [myid:1] - INFO [Thread-1:QuorumPeer@1375] - initLimit set to 10
2016-08-03 05:33:41,949 [myid:2] - INFO [Thread-2:QuorumPeer@1338] - Local session upgrading disabled
2016-08-03 05:33:41,950 [myid:2] - INFO [Thread-2:QuorumPeer@1305] - tickTime set to 4000
2016-08-03 05:33:41,950 [myid:2] - INFO [Thread-2:QuorumPeer@1349] - minSessionTimeout set to 8000
2016-08-03 05:33:41,950 [myid:2] - INFO [Thread-2:QuorumPeer@1360] - maxSessionTimeout set to 80000
2016-08-03 05:33:41,950 [myid:2] - INFO [Thread-2:QuorumPeer@1375] - initLimit set to 10
2016-08-03 05:33:41,950 [myid:0] - INFO [Thread-0:QuorumPeer@1305] - tickTime set to 4000
2016-08-03 05:33:41,951 [myid:0] - INFO [Thread-0:QuorumPeer@1349] - minSessionTimeout set to 8000
2016-08-03 05:33:41,951 [myid:0] - INFO [Thread-0:QuorumPeer@1360] - maxSessionTimeout set to 80000
2016-08-03 05:33:41,951 [myid:0] - INFO [Thread-0:QuorumPeer@1375] - initLimit set to 10
2016-08-03 05:33:41,967 [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-08-03 05:33:41,968 [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-08-03 05:33:41,967 [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-08-03 05:33:42,161 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:42,162 [myid:] - INFO [main:ClientBase@248] - server 127.0.0.1:30073 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.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
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.RunBefores.evaluate(RunBefores.java:26)
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-08-03 05:33:42,413 [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-08-03 05:33:42,413 [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-08-03 05:33:42,413 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:42,413 [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-08-03 05:33:42,414 [myid:] - INFO [main:ClientBase@248] - server 127.0.0.1:30073 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.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
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.RunBefores.evaluate(RunBefores.java:26)
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-08-03 05:33:42,463 [myid:0] - INFO [Thread-0:NettyServerCnxnFactory@487] - binding to port localhost/127.0.0.1:30073
2016-08-03 05:33:42,463 [myid:2] - INFO [Thread-2:NettyServerCnxnFactory@487] - binding to port localhost/127.0.0.1:30081
2016-08-03 05:33:42,470 [myid:1] - INFO [Thread-1:NettyServerCnxnFactory@487] - binding to port localhost/127.0.0.1:30077
2016-08-03 05:33:42,488 [myid:1] - INFO [Thread-1:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:30078
2016-08-03 05:33:42,488 [myid:2] - INFO [Thread-2:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:30082
2016-08-03 05:33:42,488 [myid:0] - INFO [Thread-0:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:30074
2016-08-03 05:33:42,497 [myid:0] - INFO [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: localhost/127.0.0.1:30076
2016-08-03 05:33:42,498 [myid:2] - INFO [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: localhost/127.0.0.1:30084
2016-08-03 05:33:42,499 [myid:1] - INFO [QuorumPeerListener:QuorumCnxManager$Listener@632] - My election bind port: localhost/127.0.0.1:30080
2016-08-03 05:33:42,506 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):QuorumPeer@1033] - LOOKING
2016-08-03 05:33:42,506 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):QuorumPeer@1033] - LOOKING
2016-08-03 05:33:42,507 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):QuorumPeer@1033] - LOOKING
2016-08-03 05:33:42,508 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):FastLeaderElection@894] - New election. My id = 2, proposed zxid=0x0
2016-08-03 05:33:42,508 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):FastLeaderElection@894] - New election. My id = 1, proposed zxid=0x0
2016-08-03 05:33:42,508 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):FastLeaderElection@894] - New election. My id = 0, proposed zxid=0x0
2016-08-03 05:33:42,510 [myid:0] - INFO [localhost/127.0.0.1:30076:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:51833
2016-08-03 05:33:42,510 [myid:1] - INFO [localhost/127.0.0.1:30080:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:59407
2016-08-03 05:33:42,511 [myid:0] - INFO [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier, so dropping the connection: (1, 0)
2016-08-03 05:33:42,512 [myid:0] - INFO [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier, so dropping the connection: (2, 0)
2016-08-03 05:33:42,512 [myid:2] - INFO [localhost/127.0.0.1:30084:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:38675
2016-08-03 05:33:42,512 [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-08-03 05:33:42,512 [myid:0] - INFO [localhost/127.0.0.1:30076:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:51832
2016-08-03 05:33:42,513 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 0 my id = 2
2016-08-03 05:33:42,514 [myid:1] - INFO [WorkerSender[myid=1]:QuorumCnxManager@276] - Have smaller server identifier, so dropping the connection: (2, 1)
2016-08-03 05:33:42,513 [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-08-03 05:33:42,514 [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-08-03 05:33:42,514 [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-08-03 05:33:42,514 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@915] - Connection broken for id 2, my id = 0, 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-08-03 05:33:42,515 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,514 [myid:1] - INFO [localhost/127.0.0.1:30080:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:59410
2016-08-03 05:33:42,515 [myid:2] - INFO [localhost/127.0.0.1:30084:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:38676
2016-08-03 05:33:42,515 [myid:0] - INFO [localhost/127.0.0.1:30076:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:51839
2016-08-03 05:33:42,514 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 2 my id = 0
2016-08-03 05:33:42,514 [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-08-03 05:33:42,516 [myid:2] - 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-08-03 05:33:42,514 [myid:2] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,516 [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-08-03 05:33:42,516 [myid:2] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 1 my id = 2
2016-08-03 05:33:42,516 [myid:1] - INFO [localhost/127.0.0.1:30080:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:59413
2016-08-03 05:33:42,516 [myid:0] - INFO [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier, so dropping the connection: (2, 0)
2016-08-03 05:33:42,516 [myid:1] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@837] - Exception when using channel: for id 2 my id = 1 error = java.net.SocketException: Broken pipe
2016-08-03 05:33:42,516 [myid:1] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@915] - Connection broken for id 2, my id = 1, 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-08-03 05:33:42,517 [myid:1] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,516 [myid:2] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@915] - Connection broken for id 1, 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-08-03 05:33:42,518 [myid:2] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,515 [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-08-03 05:33:42,515 [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-08-03 05:33:42,517 [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-08-03 05:33:42,517 [myid:1] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 2 my id = 1
2016-08-03 05:33:42,516 [myid:2] - INFO [localhost/127.0.0.1:30084:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:38679
2016-08-03 05:33:42,519 [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-08-03 05:33:42,519 [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), 0 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2016-08-03 05:33:42,519 [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-08-03 05:33:42,519 [myid:2] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,519 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@915] - Connection broken for id 2, my id = 0, 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-08-03 05:33:42,520 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,519 [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-08-03 05:33:42,520 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 0 my id = 2
2016-08-03 05:33:42,520 [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-08-03 05:33:42,520 [myid:0] - WARN [SendWorker:2: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-08-03 05:33:42,521 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 2 my id = 0
2016-08-03 05:33:42,520 [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-08-03 05:33:42,519 [myid:0] - INFO [localhost/127.0.0.1:30076:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:51842
2016-08-03 05:33:42,519 [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-08-03 05:33:42,521 [myid:0] - INFO [WorkerSender[myid=0]:QuorumCnxManager@276] - Have smaller server identifier, so dropping the connection: (2, 0)
2016-08-03 05:33:42,521 [myid:2] - INFO [localhost/127.0.0.1:30084:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:38682
2016-08-03 05:33:42,522 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@915] - Connection broken for id 2, my id = 0, 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-08-03 05:33:42,522 [myid:0] - INFO [localhost/127.0.0.1:30076:QuorumCnxManager$Listener@638] - Received connection request /127.0.0.1:51844
2016-08-03 05:33:42,522 [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-08-03 05:33:42,522 [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-08-03 05:33:42,523 [myid:2] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,522 [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-08-03 05:33:42,524 [myid:2] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 0 my id = 2
2016-08-03 05:33:42,524 [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-08-03 05:33:42,523 [myid:0] - WARN [SendWorker:2: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-08-03 05:33:42,523 [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-08-03 05:33:42,523 [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-08-03 05:33:42,522 [myid:0] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@918] - Interrupting SendWorker
2016-08-03 05:33:42,524 [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-08-03 05:33:42,524 [myid:0] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@841] - Send worker leaving thread id 2 my id = 0
2016-08-03 05:33:42,525 [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-08-03 05:33:42,525 [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-08-03 05:33:42,526 [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-08-03 05:33:42,526 [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-08-03 05:33:42,665 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:42,701 [myid:0] - INFO [New I/O worker #1:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60036
2016-08-03 05:33:42,725 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=LeaderElection]
2016-08-03 05:33:42,726 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):QuorumPeer@1109] - FOLLOWING
2016-08-03 05:33:42,726 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id0,name1=replica.0,name2=LeaderElection]
2016-08-03 05:33:42,726 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=ReplicatedServer_id2,name1=replica.2,name2=LeaderElection]
2016-08-03 05:33:42,727 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):QuorumPeer@1109] - FOLLOWING
2016-08-03 05:33:42,727 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):QuorumPeer@1121] - LEADING
2016-08-03 05:33:42,730 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):Leader@63] - TCP NoDelay set to: true
2016-08-03 05:33:42,730 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):Leader@83] - zookeeper.leader.maxConcurrentSnapshots = 10
2016-08-03 05:33:42,730 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):Leader@85] - zookeeper.leader.maxConcurrentSnapshotTimeout = 5
2016-08-03 05:33:42,731 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):Learner@88] - TCP NoDelay set to: true
2016-08-03 05:33:42,737 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:zookeeper.version=3.6.0-SNAPSHOT-1755017, built on 08/03/2016 05:24 GMT
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:host.name=asf909.gq1.ygridcore.net
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.version=1.7.0_80
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.vendor=Oracle Corporation
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.home=/home/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/jre
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.class.path=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/apache-rat-core-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/apache-rat-tasks-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-compress-1.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-io-2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-lang-2.6.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jetty-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jetty-util-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/servlet-api-2.5-20081211.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/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-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.io.tmpdir=/tmp
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:java.compiler=<NA>
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:os.name=Linux
2016-08-03 05:33:42,738 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:os.arch=amd64
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:os.version=3.13.0-36-lowlatency
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:user.name=jenkins
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:user.home=/home/jenkins
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:user.dir=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:os.memory.free=437MB
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:os.memory.max=491MB
2016-08-03 05:33:42,739 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Environment@109] - Server environment:os.memory.total=491MB
2016-08-03 05:33:42,741 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):ZooKeeperServer@858] - minSessionTimeout set to 8000
2016-08-03 05:33:42,741 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):ZooKeeperServer@858] - minSessionTimeout set to 8000
2016-08-03 05:33:42,741 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):ZooKeeperServer@867] - maxSessionTimeout set to 80000
2016-08-03 05:33:42,741 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):ZooKeeperServer@858] - minSessionTimeout set to 8000
2016-08-03 05:33:42,741 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):ZooKeeperServer@867] - maxSessionTimeout set to 80000
2016-08-03 05:33:42,741 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):ZooKeeperServer@156] - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test4754133370740902988.junit.dir/data/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test4754133370740902988.junit.dir/data/version-2
2016-08-03 05:33:42,741 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):ZooKeeperServer@867] - maxSessionTimeout set to 80000
2016-08-03 05:33:42,742 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):ZooKeeperServer@156] - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test8166855371662584608.junit.dir/data/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test8166855371662584608.junit.dir/data/version-2
2016-08-03 05:33:42,741 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):ZooKeeperServer@156] - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test5311610672905591522.junit.dir/data/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test5311610672905591522.junit.dir/data/version-2
2016-08-03 05:33:42,742 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 15 MS
2016-08-03 05:33:42,742 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):Follower@66] - FOLLOWING - LEADER ELECTION TOOK - 16 MS
2016-08-03 05:33:42,743 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):Leader@412] - LEADING - LEADER ELECTION TOOK - 16 MS
2016-08-03 05:33:42,747 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):FileTxnSnapLog@298] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test4754133370740902988.junit.dir/data/version-2/snapshot.0
2016-08-03 05:33:42,764 [myid:2] - INFO [LearnerHandler-/127.0.0.1:38806:LearnerHandler@382] - Follower sid: 1 : info : localhost:30079:30080:participant;localhost:30077
2016-08-03 05:33:42,764 [myid:2] - INFO [LearnerHandler-/127.0.0.1:38807:LearnerHandler@382] - Follower sid: 0 : info : localhost:30075:30076:participant;localhost:30073
2016-08-03 05:33:42,961 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:42,962 [myid:0] - INFO [New I/O worker #5:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60040
2016-08-03 05:33:43,213 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:43,215 [myid:0] - INFO [New I/O worker #8:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60043
2016-08-03 05:33:43,465 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:43,467 [myid:0] - INFO [New I/O worker #12:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60044
2016-08-03 05:33:43,718 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:43,719 [myid:0] - INFO [New I/O worker #15:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60047
2016-08-03 05:33:43,725 [myid:2] - INFO [LearnerHandler-/127.0.0.1:38806:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0 peerLastZxid=0x0
2016-08-03 05:33:43,725 [myid:2] - INFO [LearnerHandler-/127.0.0.1:38806:LearnerHandler@727] - Sending DIFF zxid=0x0 for peer sid: 1
2016-08-03 05:33:43,727 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):Learner@366] - Getting a diff from the leader 0x0
2016-08-03 05:33:43,732 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):Learner@509] - Learner received NEWLEADER message
2016-08-03 05:33:43,783 [myid:2] - INFO [LearnerHandler-/127.0.0.1:38807:LearnerHandler@683] - Synchronizing with Follower sid: 0 maxCommittedLog=0x0 minCommittedLog=0x0 lastProcessedZxid=0x0 peerLastZxid=0x0
2016-08-03 05:33:43,783 [myid:2] - INFO [LearnerHandler-/127.0.0.1:38807:LearnerHandler@727] - Sending DIFF zxid=0x0 for peer sid: 0
2016-08-03 05:33:43,784 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Learner@366] - Getting a diff from the leader 0x0
2016-08-03 05:33:43,784 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Learner@509] - Learner received NEWLEADER message
2016-08-03 05:33:43,908 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):FileTxnSnapLog@298] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test5311610672905591522.junit.dir/data/version-2/snapshot.0
2016-08-03 05:33:43,908 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):FileTxnSnapLog@298] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test8166855371662584608.junit.dir/data/version-2/snapshot.0
2016-08-03 05:33:43,964 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):Leader@1249] - Have quorum of supporters, sids: [ [0, 2],[0, 2] ]; starting up and setting last processed zxid: 0x100000000
2016-08-03 05:33:43,970 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:43,971 [myid:0] - INFO [New I/O worker #17:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60050
2016-08-03 05:33:44,222 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:44,223 [myid:0] - INFO [New I/O worker #20:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60051
2016-08-03 05:33:44,474 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:44,475 [myid:0] - INFO [New I/O worker #23:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60055
2016-08-03 05:33:44,726 [myid:] - INFO [main:FourLetterWordMain@85] - connecting to 127.0.0.1 30073
2016-08-03 05:33:44,728 [myid:0] - INFO [New I/O worker #26:NettyServerCnxn@275] - Processing stat command from /127.0.0.1:60056
2016-08-03 05:33:44,729 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@98] - TEST METHOD FAILED testSecureQuorumServer
java.lang.AssertionError: waiting for server 0 being up
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.zookeeper.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
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.RunBefores.evaluate(RunBefores.java:26)
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-08-03 05:33:44,731 [myid:] - INFO [main:ZKTestCase$1@70] - FAILED testSecureQuorumServer
java.lang.AssertionError: waiting for server 0 being up
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.zookeeper.test.SSLTest.testSecureQuorumServer(SSLTest.java:100)
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.RunBefores.evaluate(RunBefores.java:26)
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-08-03 05:33:44,732 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testSecureQuorumServer
2016-08-03 05:33:44,736 [myid:] - INFO [main:ZKTestCase$1@55] - STARTING testSecureStandaloneServer
2016-08-03 05:33:44,737 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testSecureStandaloneServer
2016-08-03 05:33:44,737 [myid:] - INFO [main:PortAssignment@85] - Assigned port 30085 from range 30072 - 32764.
2016-08-03 05:33:44,737 [myid:] - INFO [main:QuorumPeerTestBase$MainThread@131] - id = -1 tmpDir = /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test1220380102294608498.junit.dir clientPort = -1 adminServerPort = 8080
2016-08-03 05:33:44,738 [myid:] - INFO [Thread-6:QuorumPeerConfig@116] - Reading configuration from: /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test1220380102294608498.junit.dir/zoo.cfg
2016-08-03 05:33:44,738 [myid:] - INFO [Thread-6:QuorumPeerConfig@308] - clientPort is not set
2016-08-03 05:33:44,739 [myid:] - INFO [Thread-6:QuorumPeerConfig@332] - secureClientPortAddress is 0.0.0.0/0.0.0.0:30085
2016-08-03 05:33:44,739 [myid:-1] - INFO [Thread-6:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2016-08-03 05:33:44,739 [myid:-1] - INFO [Thread-6:DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2016-08-03 05:33:44,739 [myid:-1] - INFO [Thread-6:DatadirCleanupManager@101] - Purge task is not scheduled.
2016-08-03 05:33:44,740 [myid:-1] - WARN [Thread-6:QuorumPeerMain@122] - Either no config or no quorum defined in config, running in standalone mode
2016-08-03 05:33:44,741 [myid:-1] - INFO [Thread-6:ManagedUtil@46] - Log4j found with jmx enabled.
2016-08-03 05:33:44,741 [myid:-1] - ERROR [Thread-6: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.ZooKeeperServerMain.initializeAndRun(ZooKeeperServerMain.java:91)
at org.apache.zookeeper.server.ZooKeeperServerMain.main(ZooKeeperServerMain.java:61)
at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:125)
at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
at java.lang.Thread.run(Thread.java:745)
2016-08-03 05:33:44,742 [myid:-1] - WARN [Thread-6:ZooKeeperServerMain@93] - 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.ZooKeeperServerMain.initializeAndRun(ZooKeeperServerMain.java:91)
at org.apache.zookeeper.server.ZooKeeperServerMain.main(ZooKeeperServerMain.java:61)
at org.apache.zookeeper.server.quorum.QuorumPeerMain.initializeAndRun(QuorumPeerMain.java:125)
at org.apache.zookeeper.server.quorum.QuorumPeerTestBase$MainThread.run(QuorumPeerTestBase.java:245)
at java.lang.Thread.run(Thread.java:745)
2016-08-03 05:33:44,743 [myid:-1] - INFO [Thread-6:QuorumPeerConfig@116] - Reading configuration from: /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test1220380102294608498.junit.dir/zoo.cfg
2016-08-03 05:33:44,743 [myid:] - INFO [main:Environment@109] - Client environment:zookeeper.version=3.6.0-SNAPSHOT-1755017, built on 08/03/2016 05:24 GMT
2016-08-03 05:33:44,743 [myid:] - INFO [main:Environment@109] - Client environment:host.name=asf909.gq1.ygridcore.net
2016-08-03 05:33:44,744 [myid:] - INFO [main:Environment@109] - Client environment:java.version=1.7.0_80
2016-08-03 05:33:44,744 [myid:] - INFO [main:Environment@109] - Client environment:java.vendor=Oracle Corporation
2016-08-03 05:33:44,744 [myid:] - INFO [main:Environment@109] - Client environment:java.home=/home/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/jre
2016-08-03 05:33:44,743 [myid:-1] - INFO [Thread-6:QuorumPeerConfig@308] - clientPort is not set
2016-08-03 05:33:44,744 [myid:] - INFO [main:Environment@109] - Client environment:java.class.path=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/classes:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/apache-rat-core-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/apache-rat-tasks-0.10.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-compress-1.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-io-2.2.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/commons-lang-2.6.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jetty-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jetty-util-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/servlet-api-2.5-20081211.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/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-08-03 05:33:44,745 [myid:] - INFO [main:Environment@109] - Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2016-08-03 05:33:44,745 [myid:] - INFO [main:Environment@109] - Client environment:java.io.tmpdir=/tmp
2016-08-03 05:33:44,745 [myid:] - INFO [main:Environment@109] - Client environment:java.compiler=<NA>
2016-08-03 05:33:44,745 [myid:] - INFO [main:Environment@109] - Client environment:os.name=Linux
2016-08-03 05:33:44,745 [myid:] - INFO [main:Environment@109] - Client environment:os.arch=amd64
2016-08-03 05:33:44,744 [myid:-1] - INFO [Thread-6:QuorumPeerConfig@332] - secureClientPortAddress is 0.0.0.0/0.0.0.0:30085
2016-08-03 05:33:44,745 [myid:] - INFO [main:Environment@109] - Client environment:os.version=3.13.0-36-lowlatency
2016-08-03 05:33:44,746 [myid:] - INFO [main:Environment@109] - Client environment:user.name=jenkins
2016-08-03 05:33:44,746 [myid:] - INFO [main:Environment@109] - Client environment:user.home=/home/jenkins
2016-08-03 05:33:44,746 [myid:] - INFO [main:Environment@109] - Client environment:user.dir=/home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test
2016-08-03 05:33:44,746 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.free=424MB
2016-08-03 05:33:44,747 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.max=491MB
2016-08-03 05:33:44,747 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.total=491MB
2016-08-03 05:33:44,746 [myid:-1] - INFO [Thread-6:ZooKeeperServerMain@113] - Starting server
2016-08-03 05:33:44,747 [myid:-1] - INFO [Thread-6:ZooKeeperServer@858] - minSessionTimeout set to 8000
2016-08-03 05:33:44,748 [myid:-1] - INFO [Thread-6:ZooKeeperServer@867] - maxSessionTimeout set to 80000
2016-08-03 05:33:44,748 [myid:-1] - INFO [Thread-6:ZooKeeperServer@156] - Created server with tickTime 4000 minSessionTimeout 8000 maxSessionTimeout 80000 datadir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test1220380102294608498.junit.dir/data/version-2 snapdir /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test1220380102294608498.junit.dir/data/version-2
2016-08-03 05:33:44,749 [myid:] - INFO [main:ZooKeeper@855] - Initiating client connection, connectString=127.0.0.1:30085 sessionTimeout=3000 watcher=org.apache.zookeeper.test.SSLTest$2@10614f3d
2016-08-03 05:33:44,760 [myid:-1] - INFO [Thread-6:NettyServerCnxnFactory@487] - binding to port 0.0.0.0/0.0.0.0:30085
2016-08-03 05:33:44,761 [myid:-1] - INFO [Thread-6:FileTxnSnapLog@298] - Snapshotting: 0x0 to /home/jenkins/jenkins-slave/workspace/PreCommit-ZOOKEEPER-Build/trunk/build/test/tmp/test1220380102294608498.junit.dir/data/version-2/snapshot.0
2016-08-03 05:33:44,778 [myid:-1] - INFO [Thread-6:ContainerManager@64] - Using checkIntervalMs=60000 maxPerMinute=10000
2016-08-03 05:33:44,783 [myid:127.0.0.1:30085] - INFO [main-SendThread(127.0.0.1:30085):ClientCnxn$SendThread@1113] - Opening socket connection to server 127.0.0.1/127.0.0.1:30085. Will not attempt to authenticate using SASL (unknown error)
2016-08-03 05:33:45,065 [myid:127.0.0.1:30085] - INFO [main-SendThread(127.0.0.1:30085):ClientCnxnSocketNetty$ZKClientPipelineFactory@370] - SSL handler added for channel: null
2016-08-03 05:33:45,073 [myid:] - INFO [New I/O worker #221:ClientCnxn$SendThread@948] - Socket connection established, initiating session, client: /127.0.0.1:57010, server: 127.0.0.1/127.0.0.1:30085
2016-08-03 05:33:45,076 [myid:] - INFO [New I/O worker #221:ClientCnxnSocketNetty$1@153] - channel is connected: [id: 0x073f691d, /127.0.0.1:57010 => 127.0.0.1/127.0.0.1:30085]
2016-08-03 05:33:45,079 [myid:-1] - INFO [New I/O server boss #242:NettyServerCnxnFactory@384] - SSL handler added for channel: null
2016-08-03 05:33:45,214 [myid:-1] - INFO [New I/O worker #199:X509AuthenticationProvider@157] - Authenticated Id 'CN=localhost,OU=ZooKeeper,O=Apache,L=Unknown,ST=Unknown,C=Unknown' for Scheme 'x509'
2016-08-03 05:33:45,215 [myid:-1] - INFO [New I/O worker #199:ZooKeeperServer@964] - Client attempting to establish new session at /127.0.0.1:57010
2016-08-03 05:33:45,218 [myid:-1] - INFO [SyncThread:0:FileTxnLog@204] - Creating new log file: log.1
2016-08-03 05:33:45,256 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):CommitProcessor@318] - Configuring CommitProcessor with 16 worker threads.
2016-08-03 05:33:45,260 [myid:2] - INFO [QuorumPeer[myid=2](plain=localhost/127.0.0.1:30081)(secure=0.0.0.0/0.0.0.0:30082):ContainerManager@64] - Using checkIntervalMs=60000 maxPerMinute=10000
2016-08-03 05:33:45,261 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):Learner@493] - Learner received UPTODATE message
2016-08-03 05:33:45,261 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):Learner@493] - Learner received UPTODATE message
2016-08-03 05:33:45,349 [myid:-1] - INFO [SyncThread:0:ZooKeeperServer@678] - Established session 0x101a7cee3fd0000 with negotiated timeout 8000 for client /127.0.0.1:57010
2016-08-03 05:33:45,350 [myid:] - INFO [New I/O worker #221:ClientCnxn$SendThread@1381] - Session establishment complete on server 127.0.0.1/127.0.0.1:30085, sessionid = 0x101a7cee3fd0000, negotiated timeout = 8000
2016-08-03 05:33:45,421 [myid:1] - INFO [QuorumPeer[myid=1](plain=localhost/127.0.0.1:30077)(secure=0.0.0.0/0.0.0.0:30078):CommitProcessor@318] - Configuring CommitProcessor with 16 worker threads.
2016-08-03 05:33:45,421 [myid:0] - INFO [QuorumPeer[myid=0](plain=localhost/127.0.0.1:30073)(secure=0.0.0.0/0.0.0.0:30074):CommitProcessor@318] - Configuring CommitProcessor with 16 worker threads.
2016-08-03 05:33:45,459 [myid:-1] - INFO [ProcessThread(sid:0 cport:-1)::PrepRequestProcessor@647] - Processed session termination for sessionid: 0x101a7cee3fd0000
2016-08-03 05:33:45,503 [myid:] - INFO [main:ClientCnxnSocketNetty@208] - channel is told closing
2016-08-03 05:33:45,503 [myid:] - INFO [main:ZooKeeper@1313] - Session: 0x101a7cee3fd0000 closed
2016-08-03 05:33:45,503 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for session: 0x101a7cee3fd0000
2016-08-03 05:33:45,503 [myid:] - INFO [New I/O worker #221:ClientCnxnSocketNetty$ZKClientHandler@384] - channel is disconnected: [id: 0x073f691d, /127.0.0.1:57010 :> 127.0.0.1/127.0.0.1:30085]
2016-08-03 05:33:45,504 [myid:] - INFO [New I/O worker #221:ClientCnxnSocketNetty@208] - channel is told closing
2016-08-03 05:33:45,510 [myid:-1] - INFO [SyncThread:0:MBeanRegistry@128] - Unregister MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=Connections,name2=127.0.0.1,name3=0x101a7cee3fd0000]
2016-08-03 05:33:46,003 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 92699
2016-08-03 05:33:46,004 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 283
2016-08-03 05:33:46,004 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD testSecureStandaloneServer
2016-08-03 05:33:46,004 [myid:] - INFO [main:ZKTestCase$1@65] - SUCCEEDED testSecureStandaloneServer
2016-08-03 05:33:46,004 [myid:] - INFO [main:ZKTestCase$1@60] - FINISHED testSecureStandaloneServer
Sub-task
Major