java.nio.channels.ClosedChannelException

Apache's JIRA Issue Tracker | Michael Han | 5 months ago
  1. 0

    From https://builds.apache.org/job/ZooKeeper_branch34_jdk7/1156/ {noformat} Error Message test timed out after 30000 milliseconds Stacktrace java.lang.Exception: test timed out after 30000 milliseconds at java.io.FileOutputStream.writeBytes(Native Method) at java.io.FileOutputStream.write(FileOutputStream.java:345) at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122) at java.io.PrintStream.write(PrintStream.java:480) at java.io.PrintStream.write(PrintStream.java:480) at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221) at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291) at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295) at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141) at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229) at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:59) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:324) at org.apache.log4j.WriterAppender.append(WriterAppender.java:162) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66) at org.apache.log4j.Category.callAppenders(Category.java:206) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:305) at org.apache.zookeeper.test.FourLetterWordsTest.verify(FourLetterWordsTest.java:121) at org.apache.zookeeper.test.FourLetterWordsTest.testFourLetterWords(FourLetterWordsTest.java:52) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) Standard Output 2016-07-21 08:05:43,150 [myid:] - INFO [main:PortAssignment@32] - assigning port 11221 2016-07-21 08:05:43,156 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testDisconnectedAddAuth 2016-07-21 08:05:43,157 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testDisconnectedAddAuth 2016-07-21 08:05:43,178 [myid:] - INFO [main:Environment@100] - Server environment:zookeeper.version=3.4.9-SNAPSHOT-1753645, built on 07/21/2016 07:46 GMT 2016-07-21 08:05:43,178 [myid:] - INFO [main:Environment@100] - Server environment:host.name=asf907.gq1.ygridcore.net 2016-07-21 08:05:43,178 [myid:] - INFO [main:Environment@100] - Server environment:java.version=1.7.0_80 2016-07-21 08:05:43,178 [myid:] - INFO [main:Environment@100] - Server environment:java.vendor=Oracle Corporation 2016-07-21 08:05:43,178 [myid:] - INFO [main:Environment@100] - Server environment:java.home=/home/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/jre 2016-07-21 08:05:43,179 [myid:] - INFO [main:Environment@100] - Server environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/antlr-2.7.6.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/checkstyle-5.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-beanutils-core-1.7.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-cli-1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-lang-1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-logging-1.0.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/google-collections-0.9.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/junit-4.8.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/jline-0.9.94.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/log4j-1.2.16.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/slf4j-api-1.6.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/slf4j-log4j12-1.6.1.jar:/home/jenkins/tools/ant/apache-ant-1.9.4/lib/ant-launcher.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools/ant/latest/lib/ant-junit4.jar 2016-07-21 08:05:43,179 [myid:] - INFO [main:Environment@100] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2016-07-21 08:05:43,179 [myid:] - INFO [main:Environment@100] - Server environment:java.io.tmpdir=/tmp 2016-07-21 08:05:43,179 [myid:] - INFO [main:Environment@100] - Server environment:java.compiler=<NA> 2016-07-21 08:05:43,179 [myid:] - INFO [main:Environment@100] - Server environment:os.name=Linux 2016-07-21 08:05:43,180 [myid:] - INFO [main:Environment@100] - Server environment:os.arch=amd64 2016-07-21 08:05:43,180 [myid:] - INFO [main:Environment@100] - Server environment:os.version=3.13.0-36-lowlatency 2016-07-21 08:05:43,180 [myid:] - INFO [main:Environment@100] - Server environment:user.name=jenkins 2016-07-21 08:05:43,182 [myid:] - INFO [main:Environment@100] - Server environment:user.home=/home/jenkins 2016-07-21 08:05:43,182 [myid:] - INFO [main:Environment@100] - Server environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4 2016-07-21 08:05:43,199 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4168931007806197633.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4168931007806197633.junit.dir/version-2 2016-07-21 08:05:43,295 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11221 2016-07-21 08:05:43,387 [myid:] - INFO [main:ACLTest@62] - starting up the zookeeper server .. waiting 2016-07-21 08:05:43,388 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11221 2016-07-21 08:05:43,420 [myid:] - INFO [New I/O worker #1:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:35232 2016-07-21 08:05:43,422 [myid:] - INFO [New I/O worker #1:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:05:43,431 [myid:] - INFO [main:Environment@100] - Client environment:zookeeper.version=3.4.9-SNAPSHOT-1753645, built on 07/21/2016 07:46 GMT 2016-07-21 08:05:43,431 [myid:] - INFO [main:Environment@100] - Client environment:host.name=asf907.gq1.ygridcore.net 2016-07-21 08:05:43,431 [myid:] - INFO [main:Environment@100] - Client environment:java.version=1.7.0_80 2016-07-21 08:05:43,431 [myid:] - INFO [main:Environment@100] - Client environment:java.vendor=Oracle Corporation 2016-07-21 08:05:43,431 [myid:] - INFO [main:Environment@100] - Client environment:java.home=/home/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/jre 2016-07-21 08:05:43,431 [myid:] - INFO [main:Environment@100] - Client environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/antlr-2.7.6.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/checkstyle-5.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-beanutils-core-1.7.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-cli-1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-lang-1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-logging-1.0.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/google-collections-0.9.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/junit-4.8.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/jline-0.9.94.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/log4j-1.2.16.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/slf4j-api-1.6.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/slf4j-log4j12-1.6.1.jar:/home/jenkins/tools/ant/apache-ant-1.9.4/lib/ant-launcher.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools/ant/latest/lib/ant-junit4.jar 2016-07-21 08:05:43,432 [myid:] - INFO [main:Environment@100] - Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2016-07-21 08:05:43,432 [myid:] - INFO [main:Environment@100] - Client environment:java.io.tmpdir=/tmp 2016-07-21 08:05:43,432 [myid:] - INFO [main:Environment@100] - Client environment:java.compiler=<NA> 2016-07-21 08:05:43,432 [myid:] - INFO [main:Environment@100] - Client environment:os.name=Linux 2016-07-21 08:05:43,432 [myid:] - INFO [main:Environment@100] - Client environment:os.arch=amd64 2016-07-21 08:05:43,433 [myid:] - INFO [main:Environment@100] - Client environment:os.version=3.13.0-36-lowlatency 2016-07-21 08:05:43,433 [myid:] - INFO [main:Environment@100] - Client environment:user.name=jenkins 2016-07-21 08:05:43,433 [myid:] - INFO [main:Environment@100] - Client environment:user.home=/home/jenkins 2016-07-21 08:05:43,433 [myid:] - INFO [main:Environment@100] - Client environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4 2016-07-21 08:05:43,434 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11221 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ACLTest@14f8e8b 2016-07-21 08:05:43,450 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11221. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:05:43,450 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11221, initiating session 2016-07-21 08:05:43,454 [myid:] - INFO [New I/O worker #2:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:35233 2016-07-21 08:05:43,458 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:05:43,468 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7d251c0000 with negotiated timeout 30000 for client /127.0.0.1:35233 2016-07-21 08:05:43,471 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11221, sessionid = 0x1560c7d251c0000, negotiated timeout = 30000 2016-07-21 08:05:43,474 [myid:] - INFO [main-EventThread:ACLTest@175] - Event:SyncConnected None null 2016-07-21 08:05:43,475 [myid:] - INFO [New I/O worker #2:ZooKeeperServer@924] - got auth packet /127.0.0.1:35233 2016-07-21 08:05:43,475 [myid:] - WARN [main-EventThread:ACLTest@182] - startsignal null 2016-07-21 08:05:43,478 [myid:] - INFO [New I/O worker #2:ZooKeeperServer@958] - auth success /127.0.0.1:35233 2016-07-21 08:05:43,479 [myid:] - INFO [New I/O worker #2:ZooKeeperServer@924] - got auth packet /127.0.0.1:35233 2016-07-21 08:05:43,479 [myid:] - INFO [New I/O worker #2:ZooKeeperServer@958] - auth success /127.0.0.1:35233 2016-07-21 08:05:43,485 [myid:] - INFO [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7d251c0000 2016-07-21 08:05:43,488 [myid:] - WARN [New I/O worker #2:NettyServerCnxnFactory$CnxnChannelHandler@111] - Exception caught [id: 0xbe54f7b5, /127.0.0.1:35233 :> /127.0.0.1:11221] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:05:43,587 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7d251c0000 closed 2016-07-21 08:05:43,588 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7d251c0000 2016-07-21 08:05:43,588 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11221 2016-07-21 08:05:43,607 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:05:43,607 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:05:43,607 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:05:43,608 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:05:43,608 [myid:] - INFO [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:05:43,608 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:05:43,608 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:05:43,609 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11221 2016-07-21 08:05:43,610 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 124233 2016-07-21 08:05:43,611 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 5 2016-07-21 08:05:43,611 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testDisconnectedAddAuth 2016-07-21 08:05:43,611 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testDisconnectedAddAuth 2016-07-21 08:05:43,611 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testDisconnectedAddAuth 2016-07-21 08:05:43,613 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testAcls 2016-07-21 08:05:43,613 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testAcls 2016-07-21 08:05:43,614 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test2000752507502946075.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test2000752507502946075.junit.dir/version-2 2016-07-21 08:05:43,635 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11221 2016-07-21 08:05:43,639 [myid:] - INFO [main:ACLTest@98] - starting up the zookeeper server .. waiting 2016-07-21 08:05:43,639 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11221 2016-07-21 08:05:43,640 [myid:] - INFO [New I/O worker #34:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:35236 2016-07-21 08:05:43,641 [myid:] - INFO [New I/O worker #34:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:05:43,641 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11221 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ACLTest@114f6322 2016-07-21 08:05:43,642 [myid:] - INFO [main:ACLTest@102] - starting creating acls 2016-07-21 08:05:43,642 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11221. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:05:43,643 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11221, initiating session 2016-07-21 08:05:43,644 [myid:] - INFO [New I/O worker #35:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:35237 2016-07-21 08:05:43,644 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:05:43,648 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7d26540000 with negotiated timeout 30000 for client /127.0.0.1:35237 2016-07-21 08:05:43,648 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11221, sessionid = 0x1560c7d26540000, negotiated timeout = 30000 2016-07-21 08:05:43,648 [myid:] - INFO [main-EventThread:ACLTest@175] - Event:SyncConnected None null 2016-07-21 08:05:43,648 [myid:] - WARN [main-EventThread:ACLTest@182] - startsignal null 2016-07-21 08:05:43,954 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11221 2016-07-21 08:05:43,955 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7d26540000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:05:43,961 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:05:43,961 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:05:43,961 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:05:43,962 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:05:43,962 [myid:] - INFO [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:05:43,962 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:05:43,963 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:05:43,963 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11221 2016-07-21 08:05:43,964 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test2000752507502946075.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test2000752507502946075.junit.dir/version-2 2016-07-21 08:05:43,972 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11221 2016-07-21 08:05:44,002 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11221 2016-07-21 08:05:44,004 [myid:] - INFO [New I/O worker #67:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:35240 2016-07-21 08:05:44,004 [myid:] - INFO [New I/O worker #67:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:05:44,055 [myid:] - INFO [main-EventThread:ACLTest@175] - Event:Disconnected None null 2016-07-21 08:05:45,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:05:45,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:05:45,784 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11221. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:05:45,784 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11221, initiating session 2016-07-21 08:05:45,785 [myid:] - INFO [New I/O worker #68:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7d26540000 at /127.0.0.1:35246 2016-07-21 08:05:45,786 [myid:] - INFO [New I/O worker #68:ZooKeeperServer@645] - Established session 0x1560c7d26540000 with negotiated timeout 30000 for client /127.0.0.1:35246 2016-07-21 08:05:45,786 [myid:] - INFO [main-SendThread(127.0.0.1:11221):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11221, sessionid = 0x1560c7d26540000, negotiated timeout = 30000 2016-07-21 08:05:45,786 [myid:] - INFO [main-EventThread:ACLTest@175] - Event:SyncConnected None null 2016-07-21 08:05:45,786 [myid:] - INFO [main-EventThread:ACLTest@179] - startsignal.countDown() 2016-07-21 08:05:45,788 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.ca 2016-07-21 08:05:45,795 [myid:] - INFO [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7d26540000 2016-07-21 08:05:45,795 [myid:] - WARN [New I/O worker #68:NettyServerCnxnFactory$CnxnChannelHandler@111] - Exception caught [id: 0x0ae869d5, /127.0.0.1:35246 :> /127.0.0.1:11221] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:05:45,896 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7d26540000 closed 2016-07-21 08:05:45,896 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11221 2016-07-21 08:05:45,896 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7d26540000 2016-07-21 08:05:45,901 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:05:45,901 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:05:45,901 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:05:45,902 [myid:] - INFO [ProcessThread(sid:0 cport:11221)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:05:45,902 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:05:45,902 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:05:45,902 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:05:45,903 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11221 2016-07-21 08:05:45,904 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 81805 2016-07-21 08:05:45,904 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 7 2016-07-21 08:05:45,904 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testAcls 2016-07-21 08:05:45,904 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testAcls 2016-07-21 08:05:45,905 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testAcls 2016-07-21 08:05:45,914 [myid:] - INFO [main:PortAssignment@32] - assigning port 11222 2016-07-21 08:05:45,915 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testAsyncCreate 2016-07-21 08:05:45,916 [myid:] - INFO [main:ClientBase@425] - Initial fdcount is: 33 2016-07-21 08:05:46,035 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:05:46,035 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11222 2016-07-21 08:05:46,042 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11222 2016-07-21 08:05:46,043 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4160740823067989579.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4160740823067989579.junit.dir/version-2 2016-07-21 08:05:46,043 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11222 2016-07-21 08:05:46,046 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11222 2016-07-21 08:05:46,047 [myid:] - INFO [New I/O worker #100:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:49831 2016-07-21 08:05:46,047 [myid:] - INFO [New I/O worker #100:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:05:46,048 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:05:46,053 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:05:46,053 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree 2016-07-21 08:05:46,054 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:05:46,054 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11222 2016-07-21 08:05:46,054 [myid:] - INFO [main:ClientBase@439] - Client test setup finished 2016-07-21 08:05:46,054 [myid:] - INFO [main:AsyncOpsTest@47] - Creating client testAsyncCreate 2016-07-21 08:05:46,055 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11222 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@42701c57 2016-07-21 08:05:46,056 [myid:] - INFO [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11222. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:05:46,056 [myid:] - INFO [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11222, initiating session 2016-07-21 08:05:46,057 [myid:] - INFO [New I/O worker #101:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:49832 2016-07-21 08:05:46,057 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:05:46,060 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7d2fbb0000 with negotiated timeout 30000 for client /127.0.0.1:49832 2016-07-21 08:05:46,060 [myid:] - INFO [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 0x1560c7d2fbb0000, negotiated timeout = 30000 2016-07-21 08:05:46,062 [myid:] - INFO [main:JMXEnv@117] - expect:0x1560c7d2fbb0000 2016-07-21 08:05:46,062 [myid:] - INFO [main:JMXEnv@120] - found:0x1560c7d2fbb0000 org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x1560c7d2fbb0000 2016-07-21 08:05:46,063 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testAsyncCreate 2016-07-21 08:05:46,063 [myid:] - INFO [New I/O worker #101:ZooKeeperServer@924] - got auth packet /127.0.0.1:49832 2016-07-21 08:05:46,063 [myid:] - INFO [New I/O worker #101:ZooKeeperServer@958] - auth success /127.0.0.1:49832 2016-07-21 08:05:46,069 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 40629 2016-07-21 08:05:46,069 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 51 2016-07-21 08:05:46,069 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testAsyncCreate 2016-07-21 08:05:46,070 [myid:] - INFO [ProcessThread(sid:0 cport:11222)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7d2fbb0000 2016-07-21 08:05:46,070 [myid:] - WARN [New I/O worker #101:NettyServerCnxnFactory$CnxnChannelHandler@111] - Exception caught [id: 0xe25524be, /127.0.0.1:49832 :> /127.0.0.1:11222] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:05:46,171 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7d2fbb0000 closed 2016-07-21 08:05:46,171 [myid:] - INFO [main:ClientBase@520] - tearDown starting 2016-07-21 08:05:46,171 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7d2fbb0000 2016-07-21 08:05:46,171 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:05:46,172 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11222 2016-07-21 08:05:46,183 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:05:46,183 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:05:46,183 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:05:46,184 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:05:46,184 [myid:] - INFO [ProcessThread(sid:0 cport:11222)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:05:46,184 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:05:46,185 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:05:46,185 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11222 2016-07-21 08:05:46,186 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:05:46,189 [myid:] - INFO [main:ClientBase@545] - fdcount after test is: 34 at start it was 33 2016-07-21 08:05:46,190 [myid:] - INFO [main:ClientBase@547] - sleeping for 20 secs 2016-07-21 08:05:46,190 [myid:] - INFO [main:AsyncOpsTest@60] - Test clients shutting down 2016-07-21 08:05:46,191 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testAsyncCreate 2016-07-21 08:05:46,191 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testAsyncCreate 2016-07-21 08:05:46,192 [myid:] - INFO [main:PortAssignment@32] - assigning port 11223 2016-07-21 08:05:46,193 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testAsyncCreateThree 2016-07-21 08:05:46,193 [myid:] - INFO [main:ClientBase@425] - Initial fdcount is: 34 2016-07-21 08:05:46,204 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:05:46,204 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11223 2016-07-21 08:05:46,212 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11223 2016-07-21 08:05:46,212 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test8798982101480729726.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test8798982101480729726.junit.dir/version-2 2016-07-21 08:05:46,212 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11223 2016-07-21 08:05:46,214 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11223 2016-07-21 08:05:46,215 [myid:] - INFO [New I/O worker #133:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:38741 2016-07-21 08:05:46,215 [myid:] - INFO [New I/O worker #133:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:05:46,216 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:05:46,218 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:05:46,218 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11223,name1=InMemoryDataTree 2016-07-21 08:05:46,218 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:05:46,218 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11223 2016-07-21 08:05:46,218 [myid:] - INFO [main:ClientBase@439] - Client test setup finished 2016-07-21 08:05:46,219 [myid:] - INFO [main:AsyncOpsTest@47] - Creating client testAsyncCreateThree 2016-07-21 08:05:46,219 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11223 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@41327667 2016-07-21 08:05:46,220 [myid:] - INFO [main-SendThread(127.0.0.1:11223):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11223. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:05:46,220 [myid:] - INFO [main-SendThread(127.0.0.1:11223):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11223, initiating session 2016-07-21 08:05:46,221 [myid:] - INFO [New I/O worker #134:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:38742 2016-07-21 08:05:46,221 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:05:46,223 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7d30650000 with negotiated timeout 30000 for client /127.0.0.1:38742 2016-07-21 08:05:46,224 [myid:] - INFO [main-SendThread(127.0.0.1:11223):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11223, sessionid = 0x1560c7d30650000, negotiated timeout = 30000 2016-07-21 08:05:46,226 [myid:] - INFO [main:JMXEnv@117] - expect:0x1560c7d30650000 2016-07-21 08:05:46,226 [myid:] - INFO [main:JMXEnv@120] - found:0x1560c7d30650000 org.apache.ZooKeeperService:name0=StandaloneServer_port11223,name1=Connections,name2=127.0.0.1,name3=0x1560c7d30650000 2016-07-21 08:05:46,226 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testAsyncCreateThree 2016-07-21 08:05:46,227 [myid:] - INFO [New I/O worker #134:ZooKeeperServer@924] - got auth packet /127.0.0.1:38742 2016-07-21 08:05:46,227 [myid:] - INFO [New I/O worker #134:ZooKeeperServer@958] - auth success /127.0.0.1:38742 2016-07-21 08:05:46,230 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 77876 2016-07-21 08:05:46,230 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 52 2016-07-21 08:05:46,230 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testAsyncCreateThree 2016-07-21 08:05:46,231 [myid:] - INFO [ProcessThread(sid:0 cport:11223)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7d30650000 2016-07-21 08:05:46,232 [myid:] - WARN [New I/O worker #134:NettyServerCnxnFactory$CnxnChannelHandler@111] - Exception caught [id: 0x84929b58, /127.0.0.1:38742 :> /127.0.0.1:11223] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:05:46,332 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7d30650000 closed 2016-07-21 08:05:46,333 [myid:] - INFO [main:ClientBase@520] - tearDown starting 2016-07-21 08:05:46,333 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:05:46,332 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7d30650000 2016-07-21 08:05:46,333 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11223 2016-07-21 08:05:46,340 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:05:46,341 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:05:46,341 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:05:46,341 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:05:46,341 [myid:] - INFO [ProcessThread(sid:0 cport:11223)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:05:46,342 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:05:46,342 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:05:46,343 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11223 2016-07-21 08:05:46,343 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:05:46,346 [myid:] - INFO [main:ClientBase@545] - fdcount after test is: 34 at start it was 34 2016-07-21 08:05:46,346 [myid:] - INFO [main:AsyncOpsTest@60] - Test clients shutting down 2016-07-21 08:05:46,347 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testAsyncCreateThree 2016-07-21 08:05:46,347 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testAsyncCreateThree 2016-07-21 08:05:46,347 [myid:] - INFO [main:PortAssignment@32] - assigning port 11224 2016-07-21 08:05:46,348 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testAsyncCreateFailure_NodeExists 2016-07-21 08:05:46,348 [myid:] - INFO [main:ClientBase@425] - Initial fdcount is: 34 2016-07-21 08:05:46,355 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:05:46,355 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11224 2016-07-21 08:05:46,362 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11224 2016-07-21 08:05:46,363 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test937004609623311539.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test937004609623311539.junit.dir/version-2 2016-07-21 08:05:46,363 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11224 2016-07-21 08:05:46,364 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11224 2016-07-21 08:05:46,365 [myid:] - INFO [New I/O worker #166:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:54116 2016-07-21 08:05:46,366 [myid:] - INFO [New I/O worker #166:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:05:46,366 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:05:46,368 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:05:46,368 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11224,name1=InMemoryDataTree 2016-07-21 08:05:46,368 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:05:46,369 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11224 2016-07-21 08:05:46,369 [myid:] - INFO [main:ClientBase@439] - Client test setup finished 2016-07-21 08:05:46,369 [myid:] - INFO [main:AsyncOpsTest@47] - Creating client testAsyncCreateFailure_NodeExists 2016-07-21 08:05:46,369 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11224 sessionTimeout=30000 watcher=org.apache.zookeeper.test.ClientBase$CountdownWatcher@78f394a2 2016-07-21 08:05:46,370 [myid:] - INFO [main-SendThread(127.0.0.1:11224):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11224. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:05:46,371 [myid:] - INFO [main-SendThread(127.0.0.1:11224):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11224, initiating session 2016-07-21 08:05:46,371 [myid:] - INFO [New I/O worker #167:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:54117 2016-07-21 08:05:46,372 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:05:46,374 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7d30fb0000 with negotiated timeout 30000 for client /127.0.0.1:54117 2016-07-21 08:05:46,374 [myid:] - INFO [main-SendThread(127.0.0.1:11224):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11224, sessionid = 0x1560c7d30fb0000, negotiated timeout = 30000 2016-07-21 08:05:46,376 [myid:] - INFO [main:JMXEnv@117] - expect:0x1560c7d30fb0000 2016-07-21 08:05:46,377 [myid:] - INFO [main:JMXEnv@120] - found:0x1560c7d30fb0000 org.apache.ZooKeeperService:name0=StandaloneServer_port11224,name1=Connections,name2=127.0.0.1,name3=0x1560c7d30fb0000 2016-07-21 08:05:46,377 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testAsyncCreateFailure_NodeExists 2016-07-21 08:05:46,377 [myid:] - INFO [New I/O worker #167:ZooKeeperServer@924] - got auth packet /127.0.0.1:54117 2016-07-21 08:05:46,378 [myid:] - INFO [New I/O worker #167:ZooKeeperServer@958] - auth success /127.0.0.1:54117 2016-07-21 08:05:46,382 [myid:] - INFO [ProcessThread(sid:0 cport:11224)::PrepRequestProcessor@649] - Got user-level KeeperException when processing sessionid:0x1560c7d30fb0000 type:create cxid:0x2 zxid:0x3 txntype:-1 reqpath:n/a Error Path:/foo Error:KeeperErrorCode = NodeExists for /foo 2016-07-21 08:05:46,382 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 115887 2016-07-21 08:05:46,383 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 53 2016-07-21 08:05:46,383 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testAsyncCreateFailure_NodeExists 2016-07-21 08:05:46,384 [myid:] - INFO [ProcessThread(sid:0 cport:11224)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7d30fb0000 2016-07-21 08:05:46,385 [myid:] - WARN [New I/O worker #167:NettyServerCnxnFactory$CnxnChannelHandler@111] - Exception caught [id: 0x08491bfc, /127.0.0.1:54117 :> /127.0.0.1:11224] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:05:46,485 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7d30fb0000 closed 2016-07-21 08:05:46,485 [myid:] - INFO [main:ClientBase@520] - tearDown starting 2016-07-21 08:05:46,485 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:05:46,486 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11224 2016-07-21 08:05:46,485 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7d30fb0000 2016-07-21 08:05:46,495 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:05:46,495 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:05:46,495 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:05:46,496 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:05:46,496 [myid:] - INFO [ProcessThread(sid:0 cport:11224)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:05:46,496 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:05:46,496 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:05:46,498 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11224 2016-07-21 08:05:46,499 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:05:46,502 [myid:] - INFO [main:ClientBase@545] - fdcount after test is: 34 at start it was 34 2016-07-21 08:05:46,502 [myid:] - INFO [main:AsyncOpsTest@60] - Test clients shutting down 2016-07-21 08:05:46,502 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testAsyncCreateFailure_NodeExists 2016-07-21 08:05:46,502 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testAsyncCreateFailure_NodeExists 2016-07-21 08:05:46,503 [myid:] - INFO [main:PortAssignment@32] - assigning port 11225 2016-07-21 08:05:46,503 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testAsyncCreateFailure_NoNode 2016-07-21 08:05:46,504 [myid:] - INFO [main:ClientBase@425] - Initial fdcount is: 34 2016-07-21 08:05:46,514 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:05:46,514 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11225 2016-07-21 08:05:46,525 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11225 2016-07-21 08:05:46,525 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5380464042991622148.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5380464042991622148.junit.dir/version-2 2016-07-21 08:05:46,525 [myid:] - INFO [main:NettyServerCnxnFactory@365] - bindin ...[truncated 880056 chars]... ocessor exited loop! 2016-07-21 08:08:01,738 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:01,739 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:01,740 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11289 2016-07-21 08:08:01,740 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:02,332 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:02,332 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11289 2016-07-21 08:08:02,340 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11289 2016-07-21 08:08:02,341 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4028127123136724556.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4028127123136724556.junit.dir/version-2 2016-07-21 08:08:02,341 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11289 2016-07-21 08:08:02,344 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11289 2016-07-21 08:08:02,345 [myid:] - INFO [New I/O worker #2707:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:36112 2016-07-21 08:08:02,345 [myid:] - INFO [New I/O worker #2707:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:02,345 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:02,346 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:02,347 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11289,name1=InMemoryDataTree 2016-07-21 08:08:02,347 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:02,347 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11289 2016-07-21 08:08:03,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:03,274 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11289. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:03,274 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11289, initiating session 2016-07-21 08:08:03,275 [myid:] - INFO [New I/O worker #2708:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f3a630000 at /127.0.0.1:36116 2016-07-21 08:08:03,276 [myid:] - INFO [New I/O worker #2708:ZooKeeperServer@645] - Established session 0x1560c7f3a630000 with negotiated timeout 6000 for client /127.0.0.1:36116 2016-07-21 08:08:03,276 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11289, sessionid = 0x1560c7f3a630000, negotiated timeout = 6000 2016-07-21 08:08:03,281 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.6 2016-07-21 08:08:03,283 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:03,283 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11289 2016-07-21 08:08:03,284 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f3a630000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:03,293 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:03,295 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:03,296 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:03,296 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:03,296 [myid:] - INFO [ProcessThread(sid:0 cport:11289)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:03,296 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:03,297 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:03,298 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11289 2016-07-21 08:08:03,298 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:03,384 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:03,385 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11289 2016-07-21 08:08:03,392 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11289 2016-07-21 08:08:03,392 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4028127123136724556.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test4028127123136724556.junit.dir/version-2 2016-07-21 08:08:03,392 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11289 2016-07-21 08:08:03,395 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11289 2016-07-21 08:08:03,396 [myid:] - INFO [New I/O worker #2740:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:36118 2016-07-21 08:08:03,396 [myid:] - INFO [New I/O worker #2740:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:03,397 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:03,398 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:03,398 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11289,name1=InMemoryDataTree 2016-07-21 08:08:03,399 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:03,399 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11289 2016-07-21 08:08:04,956 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11289. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:04,956 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11289, initiating session 2016-07-21 08:08:04,957 [myid:] - INFO [New I/O worker #2741:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f3a630000 at /127.0.0.1:36123 2016-07-21 08:08:04,958 [myid:] - INFO [New I/O worker #2741:ZooKeeperServer@645] - Established session 0x1560c7f3a630000 with negotiated timeout 6000 for client /127.0.0.1:36123 2016-07-21 08:08:04,958 [myid:] - INFO [main-SendThread(127.0.0.1:11289):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11289, sessionid = 0x1560c7f3a630000, negotiated timeout = 6000 2016-07-21 08:08:04,959 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.7 2016-07-21 08:08:05,963 [myid:] - INFO [ProcessThread(sid:0 cport:11289)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7f3a630000 2016-07-21 08:08:05,964 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7f3a630000 closed 2016-07-21 08:08:05,964 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7f3a630000 2016-07-21 08:08:05,965 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 71640 2016-07-21 08:08:05,965 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 65 2016-07-21 08:08:05,965 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testWatcherAutoResetWithLocal 2016-07-21 08:08:05,965 [myid:] - INFO [main:ClientBase@520] - tearDown starting 2016-07-21 08:08:05,965 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:05,965 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11289 2016-07-21 08:08:05,972 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:05,975 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:05,975 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:05,975 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:05,975 [myid:] - INFO [ProcessThread(sid:0 cport:11289)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:05,975 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:05,976 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:05,977 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11289 2016-07-21 08:08:05,978 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:05,981 [myid:] - INFO [main:ClientBase@545] - fdcount after test is: 45 at start it was 41 2016-07-21 08:08:05,981 [myid:] - INFO [main:ClientBase@547] - sleeping for 20 secs 2016-07-21 08:08:05,981 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testWatcherAutoResetWithLocal 2016-07-21 08:08:05,982 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testWatcherAutoResetWithLocal 2016-07-21 08:08:05,983 [myid:] - INFO [main:PortAssignment@32] - assigning port 11290 2016-07-21 08:08:05,983 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testWatcherAutoResetDisabledWithGlobal 2016-07-21 08:08:05,983 [myid:] - INFO [main:ClientBase@425] - Initial fdcount is: 45 2016-07-21 08:08:05,991 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:05,992 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11290 2016-07-21 08:08:06,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:06,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:06,002 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11290 2016-07-21 08:08:06,002 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 2016-07-21 08:08:06,002 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:06,004 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:06,005 [myid:] - INFO [New I/O worker #2773:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:59460 2016-07-21 08:08:06,005 [myid:] - INFO [New I/O worker #2773:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:06,006 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:06,007 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:06,007 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11290,name1=InMemoryDataTree 2016-07-21 08:08:06,007 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:06,007 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11290 2016-07-21 08:08:06,007 [myid:] - INFO [main:ClientBase@439] - Client test setup finished 2016-07-21 08:08:06,008 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testWatcherAutoResetDisabledWithGlobal 2016-07-21 08:08:06,008 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11290 sessionTimeout=5000 watcher=org.apache.zookeeper.test.WatcherTest$MyWatcher@63979eb4 2016-07-21 08:08:06,009 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11290. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:06,009 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11290, initiating session 2016-07-21 08:08:06,010 [myid:] - INFO [New I/O worker #2774:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:59461 2016-07-21 08:08:06,010 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:08:06,012 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7f52730000 with negotiated timeout 6000 for client /127.0.0.1:59461 2016-07-21 08:08:06,012 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11290, sessionid = 0x1560c7f52730000, negotiated timeout = 6000 2016-07-21 08:08:06,013 [myid:] - INFO [main:JMXEnv@117] - expect:0x1560c7f52730000 2016-07-21 08:08:06,013 [myid:] - INFO [main:JMXEnv@120] - found:0x1560c7f52730000 org.apache.ZooKeeperService:name0=StandaloneServer_port11290,name1=Connections,name2=127.0.0.1,name3=0x1560c7f52730000 2016-07-21 08:08:06,018 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:06,019 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:06,019 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f52730000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:06,023 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:06,023 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:06,024 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:06,024 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:06,024 [myid:] - INFO [ProcessThread(sid:0 cport:11290)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:06,024 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:06,026 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:06,027 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:06,027 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:06,119 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:06,120 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11290 2016-07-21 08:08:06,126 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11290 2016-07-21 08:08:06,127 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 2016-07-21 08:08:06,127 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:06,129 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:06,130 [myid:] - INFO [New I/O worker #2806:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:59463 2016-07-21 08:08:06,130 [myid:] - INFO [New I/O worker #2806:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:06,131 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:06,132 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:06,132 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11290,name1=InMemoryDataTree 2016-07-21 08:08:06,132 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:06,132 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11290 2016-07-21 08:08:07,861 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11290. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:07,861 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11290, initiating session 2016-07-21 08:08:07,862 [myid:] - INFO [New I/O worker #2807:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f52730000 at /127.0.0.1:59469 2016-07-21 08:08:07,862 [myid:] - INFO [New I/O worker #2807:ZooKeeperServer@645] - Established session 0x1560c7f52730000 with negotiated timeout 6000 for client /127.0.0.1:59469 2016-07-21 08:08:07,862 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11290, sessionid = 0x1560c7f52730000, negotiated timeout = 6000 2016-07-21 08:08:07,864 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.4 2016-07-21 08:08:07,868 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:07,868 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:07,869 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f52730000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:07,872 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:07,872 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:07,872 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:07,873 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:07,873 [myid:] - INFO [ProcessThread(sid:0 cport:11290)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:07,873 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:07,874 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:07,874 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:07,875 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:07,969 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:07,970 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11290 2016-07-21 08:08:07,978 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11290 2016-07-21 08:08:07,978 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 2016-07-21 08:08:07,978 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:07,981 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:07,982 [myid:] - INFO [New I/O worker #2839:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:59471 2016-07-21 08:08:07,982 [myid:] - INFO [New I/O worker #2839:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:07,983 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:07,984 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:07,985 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11290,name1=InMemoryDataTree 2016-07-21 08:08:07,985 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:07,985 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11290 2016-07-21 08:08:09,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:09,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:09,515 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11290. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:09,515 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11290, initiating session 2016-07-21 08:08:09,516 [myid:] - INFO [New I/O worker #2840:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f52730000 at /127.0.0.1:59477 2016-07-21 08:08:09,517 [myid:] - INFO [New I/O worker #2840:ZooKeeperServer@645] - Established session 0x1560c7f52730000 with negotiated timeout 6000 for client /127.0.0.1:59477 2016-07-21 08:08:09,517 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11290, sessionid = 0x1560c7f52730000, negotiated timeout = 6000 2016-07-21 08:08:09,521 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.6 2016-07-21 08:08:09,523 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:09,523 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:09,524 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f52730000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:09,530 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:09,530 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:09,530 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:09,530 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:09,531 [myid:] - INFO [ProcessThread(sid:0 cport:11290)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:09,531 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:09,532 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:09,533 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:09,534 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:09,625 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:09,625 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11290 2016-07-21 08:08:09,631 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11290 2016-07-21 08:08:09,632 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test6527239161822360616.junit.dir/version-2 2016-07-21 08:08:09,632 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:09,635 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:09,636 [myid:] - INFO [New I/O worker #2872:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:59479 2016-07-21 08:08:09,636 [myid:] - INFO [New I/O worker #2872:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:09,637 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:09,638 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:09,638 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11290,name1=InMemoryDataTree 2016-07-21 08:08:09,638 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:09,638 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11290 2016-07-21 08:08:11,158 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11290. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:11,159 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11290, initiating session 2016-07-21 08:08:11,160 [myid:] - INFO [New I/O worker #2873:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f52730000 at /127.0.0.1:59485 2016-07-21 08:08:11,161 [myid:] - INFO [New I/O worker #2873:ZooKeeperServer@645] - Established session 0x1560c7f52730000 with negotiated timeout 6000 for client /127.0.0.1:59485 2016-07-21 08:08:11,162 [myid:] - INFO [main-SendThread(127.0.0.1:11290):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11290, sessionid = 0x1560c7f52730000, negotiated timeout = 6000 2016-07-21 08:08:11,163 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.7 2016-07-21 08:08:12,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:12,166 [myid:] - INFO [ProcessThread(sid:0 cport:11290)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7f52730000 2016-07-21 08:08:12,167 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7f52730000 closed 2016-07-21 08:08:12,167 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7f52730000 2016-07-21 08:08:12,168 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 93132 2016-07-21 08:08:12,168 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 64 2016-07-21 08:08:12,168 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testWatcherAutoResetDisabledWithGlobal 2016-07-21 08:08:12,168 [myid:] - INFO [main:ClientBase@520] - tearDown starting 2016-07-21 08:08:12,168 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:12,169 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11290 2016-07-21 08:08:12,175 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:12,176 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:12,177 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:12,177 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:12,177 [myid:] - INFO [ProcessThread(sid:0 cport:11290)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:12,177 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:12,178 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:12,179 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11290 2016-07-21 08:08:12,179 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:12,181 [myid:] - INFO [main:ClientBase@545] - fdcount after test is: 45 at start it was 45 2016-07-21 08:08:12,182 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testWatcherAutoResetDisabledWithGlobal 2016-07-21 08:08:12,182 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testWatcherAutoResetDisabledWithGlobal 2016-07-21 08:08:12,182 [myid:] - INFO [main:PortAssignment@32] - assigning port 11291 2016-07-21 08:08:12,182 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testWatcherAutoResetDisabledWithLocal 2016-07-21 08:08:12,183 [myid:] - INFO [main:ClientBase@425] - Initial fdcount is: 45 2016-07-21 08:08:12,191 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:12,191 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11291 2016-07-21 08:08:12,197 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11291 2016-07-21 08:08:12,197 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 2016-07-21 08:08:12,198 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:12,199 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:12,200 [myid:] - INFO [New I/O worker #2905:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:51830 2016-07-21 08:08:12,200 [myid:] - INFO [New I/O worker #2905:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:12,200 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:12,202 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:12,202 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11291,name1=InMemoryDataTree 2016-07-21 08:08:12,202 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:12,202 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11291 2016-07-21 08:08:12,202 [myid:] - INFO [main:ClientBase@439] - Client test setup finished 2016-07-21 08:08:12,202 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testWatcherAutoResetDisabledWithLocal 2016-07-21 08:08:12,202 [myid:] - INFO [main:ZooKeeper@438] - Initiating client connection, connectString=127.0.0.1:11291 sessionTimeout=5000 watcher=org.apache.zookeeper.test.WatcherTest$MyWatcher@b901239 2016-07-21 08:08:12,203 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11291. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:12,203 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11291, initiating session 2016-07-21 08:08:12,204 [myid:] - INFO [New I/O worker #2906:ZooKeeperServer@900] - Client attempting to establish new session at /127.0.0.1:51831 2016-07-21 08:08:12,205 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.1 2016-07-21 08:08:12,206 [myid:] - INFO [SyncThread:0:ZooKeeperServer@645] - Established session 0x1560c7f6aa60000 with negotiated timeout 6000 for client /127.0.0.1:51831 2016-07-21 08:08:12,207 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11291, sessionid = 0x1560c7f6aa60000, negotiated timeout = 6000 2016-07-21 08:08:12,208 [myid:] - INFO [main:JMXEnv@117] - expect:0x1560c7f6aa60000 2016-07-21 08:08:12,209 [myid:] - INFO [main:JMXEnv@120] - found:0x1560c7f6aa60000 org.apache.ZooKeeperService:name0=StandaloneServer_port11291,name1=Connections,name2=127.0.0.1,name3=0x1560c7f6aa60000 2016-07-21 08:08:12,214 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:12,214 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:12,214 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f6aa60000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:12,219 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:12,219 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:12,219 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:12,220 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:12,220 [myid:] - INFO [ProcessThread(sid:0 cport:11291)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:12,220 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:12,221 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:12,222 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:12,223 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:12,315 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:12,315 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11291 2016-07-21 08:08:12,321 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11291 2016-07-21 08:08:12,321 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 2016-07-21 08:08:12,321 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:12,324 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:12,325 [myid:] - INFO [New I/O worker #2938:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:51833 2016-07-21 08:08:12,325 [myid:] - INFO [New I/O worker #2938:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:12,326 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:12,327 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:12,327 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11291,name1=InMemoryDataTree 2016-07-21 08:08:12,327 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:12,327 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11291 2016-07-21 08:08:13,518 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11291. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:13,518 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11291, initiating session 2016-07-21 08:08:13,519 [myid:] - INFO [New I/O worker #2939:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f6aa60000 at /127.0.0.1:51839 2016-07-21 08:08:13,520 [myid:] - INFO [New I/O worker #2939:ZooKeeperServer@645] - Established session 0x1560c7f6aa60000 with negotiated timeout 6000 for client /127.0.0.1:51839 2016-07-21 08:08:13,520 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11291, sessionid = 0x1560c7f6aa60000, negotiated timeout = 6000 2016-07-21 08:08:13,521 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.4 2016-07-21 08:08:13,523 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:13,524 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:13,525 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f6aa60000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:13,531 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:13,531 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:13,531 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:13,531 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:13,531 [myid:] - INFO [ProcessThread(sid:0 cport:11291)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:13,531 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:13,532 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:13,533 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:13,533 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:13,625 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:13,625 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11291 2016-07-21 08:08:13,633 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11291 2016-07-21 08:08:13,634 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 2016-07-21 08:08:13,634 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:13,636 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:13,637 [myid:] - INFO [New I/O worker #2971:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:51841 2016-07-21 08:08:13,637 [myid:] - INFO [New I/O worker #2971:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:13,637 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:13,639 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:13,639 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11291,name1=InMemoryDataTree 2016-07-21 08:08:13,639 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:13,639 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11291 2016-07-21 08:08:14,760 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11291. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:14,761 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11291, initiating session 2016-07-21 08:08:14,762 [myid:] - INFO [New I/O worker #2972:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f6aa60000 at /127.0.0.1:51846 2016-07-21 08:08:14,763 [myid:] - INFO [New I/O worker #2972:ZooKeeperServer@645] - Established session 0x1560c7f6aa60000 with negotiated timeout 6000 for client /127.0.0.1:51846 2016-07-21 08:08:14,763 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11291, sessionid = 0x1560c7f6aa60000, negotiated timeout = 6000 2016-07-21 08:08:14,768 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.6 2016-07-21 08:08:14,770 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:14,771 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:14,771 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1158] - Unable to read additional data from server sessionid 0x1560c7f6aa60000, likely server has closed socket, closing socket connection and attempting reconnect 2016-07-21 08:08:14,777 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:14,777 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:14,778 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:14,779 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:14,779 [myid:] - INFO [ProcessThread(sid:0 cport:11291)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:14,779 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:14,780 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:14,782 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:14,782 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:14,871 [myid:] - INFO [main:ClientBase@443] - STARTING server 2016-07-21 08:08:14,872 [myid:] - INFO [main:ClientBase@364] - CREATING server instance 127.0.0.1:11291 2016-07-21 08:08:14,880 [myid:] - INFO [main:ClientBase@339] - STARTING server instance 127.0.0.1:11291 2016-07-21 08:08:14,881 [myid:] - INFO [main:ZooKeeperServer@170] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 snapdir /home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/tmp/test5697721892495919568.junit.dir/version-2 2016-07-21 08:08:14,881 [myid:] - INFO [main:NettyServerCnxnFactory@365] - binding to port 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:14,884 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:14,885 [myid:] - INFO [New I/O worker #3004:NettyServerCnxn@632] - Processing stat command from /127.0.0.1:51849 2016-07-21 08:08:14,886 [myid:] - INFO [New I/O worker #3004:NettyServerCnxn$StatCommand@469] - Stat command output 2016-07-21 08:08:14,886 [myid:] - INFO [main:JMXEnv@229] - ensureParent:[InMemoryDataTree, StandaloneServer_port] 2016-07-21 08:08:14,887 [myid:] - INFO [main:JMXEnv@246] - expect:InMemoryDataTree 2016-07-21 08:08:14,887 [myid:] - INFO [main:JMXEnv@250] - found:InMemoryDataTree org.apache.ZooKeeperService:name0=StandaloneServer_port11291,name1=InMemoryDataTree 2016-07-21 08:08:14,887 [myid:] - INFO [main:JMXEnv@246] - expect:StandaloneServer_port 2016-07-21 08:08:14,888 [myid:] - INFO [main:JMXEnv@250] - found:StandaloneServer_port org.apache.ZooKeeperService:name0=StandaloneServer_port11291 2016-07-21 08:08:15,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:15,001 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:15,001 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:15,001 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:08:16,075 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1032] - Opening socket connection to server 127.0.0.1/127.0.0.1:11291. Will not attempt to authenticate using SASL (unknown error) 2016-07-21 08:08:16,075 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@876] - Socket connection established to 127.0.0.1/127.0.0.1:11291, initiating session 2016-07-21 08:08:16,076 [myid:] - INFO [New I/O worker #3005:ZooKeeperServer@893] - Client attempting to renew session 0x1560c7f6aa60000 at /127.0.0.1:51852 2016-07-21 08:08:16,077 [myid:] - INFO [New I/O worker #3005:ZooKeeperServer@645] - Established session 0x1560c7f6aa60000 with negotiated timeout 6000 for client /127.0.0.1:51852 2016-07-21 08:08:16,077 [myid:] - INFO [main-SendThread(127.0.0.1:11291):ClientCnxn$SendThread@1299] - Session establishment complete on server 127.0.0.1/127.0.0.1:11291, sessionid = 0x1560c7f6aa60000, negotiated timeout = 6000 2016-07-21 08:08:16,078 [myid:] - INFO [SyncThread:0:FileTxnLog@203] - Creating new log file: log.7 2016-07-21 08:08:17,082 [myid:] - INFO [ProcessThread(sid:0 cport:11291)::PrepRequestProcessor@487] - Processed session termination for sessionid: 0x1560c7f6aa60000 2016-07-21 08:08:17,083 [myid:] - WARN [New I/O worker #3005:NettyServerCnxnFactory$CnxnChannelHandler@111] - Exception caught [id: 0x3265227a, /127.0.0.1:51852 :> /127.0.0.1:11291] EXCEPTION: java.nio.channels.ClosedChannelException java.nio.channels.ClosedChannelException at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479) at org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151) at org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391) at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315) at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:08:17,184 [myid:] - INFO [main:ZooKeeper@684] - Session: 0x1560c7f6aa60000 closed 2016-07-21 08:08:17,184 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@519] - EventThread shut down for session: 0x1560c7f6aa60000 2016-07-21 08:08:17,184 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 115316 2016-07-21 08:08:17,184 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 63 2016-07-21 08:08:17,184 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testWatcherAutoResetDisabledWithLocal 2016-07-21 08:08:17,184 [myid:] - INFO [main:ClientBase@520] - tearDown starting 2016-07-21 08:08:17,184 [myid:] - INFO [main:ClientBase@490] - STOPPING server 2016-07-21 08:08:17,185 [myid:] - INFO [main:NettyServerCnxnFactory@342] - shutdown called 0.0.0.0/0.0.0.0:11291 2016-07-21 08:08:17,190 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:08:17,191 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:08:17,191 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:08:17,191 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:08:17,191 [myid:] - INFO [ProcessThread(sid:0 cport:11291)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:08:17,191 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:08:17,192 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:08:17,192 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11291 2016-07-21 08:08:17,193 [myid:] - INFO [main:JMXEnv@146] - ensureOnly:[] 2016-07-21 08:08:17,195 [myid:] - INFO [main:ClientBase@545] - fdcount after test is: 41 at start it was 45 2016-07-21 08:08:17,195 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testWatcherAutoResetDisabledWithLocal 2016-07-21 08:08:17,195 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testWatcherAutoResetDisabledWithLocal {noformat}

    Apache's JIRA Issue Tracker | 5 months ago | Michael Han
    java.nio.channels.ClosedChannelException
  2. 0

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

    Apache's JIRA Issue Tracker | 2 months ago | Michael Han
    java.nio.channels.ClosedChannelException
  3. 0

    [JIRA] [core] (JENKINS-30558) Cron based jobs are no longer triggered

    Google Groups | 1 year ago | jwst...@gmail.com (JIRA)
    java.nio.channels.ClosedChannelException
  4. Speed up your debug routine!

    Automated exception search integrated into your IDE

  5. 0

    Activator fails

    GitHub | 3 years ago | jim-collins
    java.nio.channels.ClosedChannelException
  6. 0

    MasterDaemonTest failed for several times in the last week

    GitHub | 4 years ago | slxu
    org.eclipse.jetty.io.EofException

  1. mellson 2 times, last 3 months ago
  2. davidvanlaatum 5 times, last 6 months ago
8 unregistered visitors
Not finding the right solution?
Take a tour to get the most out of Samebug.

Tired of useless tips?

Automated exception search integrated into your IDE

Root Cause Analysis

  1. java.nio.channels.ClosedChannelException

    No message provided

    at sun.nio.ch.SocketChannelImpl.ensureWriteOpen()
  2. Java RT
    SocketChannelImpl.write
    1. sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:270)
    2. sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:479)
    2 frames
  3. Netty
    DeadLockProofWorker$1.run
    1. org.jboss.netty.channel.socket.nio.SocketSendBufferPool$UnpooledSendBuffer.transferTo(SocketSendBufferPool.java:203)
    2. org.jboss.netty.channel.socket.nio.AbstractNioWorker.write0(AbstractNioWorker.java:201)
    3. org.jboss.netty.channel.socket.nio.AbstractNioWorker.writeFromTaskLoop(AbstractNioWorker.java:151)
    4. org.jboss.netty.channel.socket.nio.AbstractNioChannel$WriteTask.run(AbstractNioChannel.java:315)
    5. org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391)
    6. org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315)
    7. org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89)
    8. org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
    9. org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
    10. org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
    10 frames
  4. Java RT
    Thread.run
    1. java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    2. java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    3. java.lang.Thread.run(Thread.java:745)
    3 frames