java.lang.Exception: test timed out after 30000 milliseconds

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

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

    Apache's JIRA Issue Tracker | 4 months ago | Michael Han
    java.lang.Exception: test timed out after 30000 milliseconds
  2. 0

    Transient test failure - io.druid.indexing.worker.WorkerTaskMonitorTest testRestartCleansOldStatus

    GitHub | 9 months ago | pjain1
    java.lang.Exception: test timed out after 30000 milliseconds
  3. 0

    GitHub comment 2726#201075586

    GitHub | 8 months ago | drcrallen
    java.lang.Exception: test timed out after 30000 milliseconds
  4. Speed up your debug routine!

    Automated exception search integrated into your IDE

  5. 0

    Failed: YARN-2910 PreCommit Build #6028

    hadoop-yarn-dev | 2 years ago | Apache Jenkins Server
    java.lang.Exception: test timed out after 30000 milliseconds
  6. 0

    GitHub comment 2637#201075800

    GitHub | 8 months ago | gianm
    java.lang.Exception: test timed out after 30000 milliseconds

    Not finding the right solution?
    Take a tour to get the most out of Samebug.

    Tired of useless tips?

    Automated exception search integrated into your IDE

    Root Cause Analysis

    1. java.lang.Exception

      test timed out after 30000 milliseconds

      at java.io.FileOutputStream.writeBytes()
    2. Java RT
      OutputStreamWriter.flush
      1. java.io.FileOutputStream.writeBytes(Native Method)
      2. java.io.FileOutputStream.write(FileOutputStream.java:345)
      3. java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
      4. java.io.PrintStream.write(PrintStream.java:480)
      5. java.io.PrintStream.write(PrintStream.java:480)
      6. sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
      7. sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
      8. sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295)
      9. sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
      10. java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
      10 frames
    3. Apache Log4j
      Category.log
      1. org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:59)
      2. org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:324)
      3. org.apache.log4j.WriterAppender.append(WriterAppender.java:162)
      4. org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
      5. org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
      6. org.apache.log4j.Category.callAppenders(Category.java:206)
      7. org.apache.log4j.Category.forcedLog(Category.java:391)
      8. org.apache.log4j.Category.log(Category.java:856)
      8 frames
    4. SLF4J LOG4J-12 Binding
      Log4jLoggerAdapter.info
      1. org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:305)
      1 frame
    5. org.apache.zookeeper
      FourLetterWordsTest.testFourLetterWords
      1. org.apache.zookeeper.test.FourLetterWordsTest.verify(FourLetterWordsTest.java:121)
      2. org.apache.zookeeper.test.FourLetterWordsTest.testFourLetterWords(FourLetterWordsTest.java:52)
      2 frames
    6. Zookeeper
      JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate
      1. org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55)
      1 frame