Details
-
Sub-task
-
Status: Closed
-
Major
-
Resolution: Cannot Reproduce
-
3.4.8
Description
From https://builds.apache.org/job/ZooKeeper_branch34_jdk7/1156/
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
Attachments
Issue Links
- relates to
-
ZOOKEEPER-2135 fix trunk build
-
- Open
-