You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by "Michael Han (JIRA)" <ji...@apache.org> on 2017/03/13 16:22:06 UTC
[jira] [Updated] (ZOOKEEPER-2485) Flaky Test:
org.apache.zookeeper.test.FourLetterWordsTest.testFourLetterWords
[ https://issues.apache.org/jira/browse/ZOOKEEPER-2485?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Michael Han updated ZOOKEEPER-2485:
-----------------------------------
Fix Version/s: (was: 3.5.3)
3.6.0
3.5.4
> Flaky Test: org.apache.zookeeper.test.FourLetterWordsTest.testFourLetterWords
> -----------------------------------------------------------------------------
>
> Key: ZOOKEEPER-2485
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2485
> Project: ZooKeeper
> Issue Type: Test
> Components: tests
> Affects Versions: 3.4.8
> Reporter: Michael Han
> Labels: flaky, flaky-test
> Fix For: 3.5.4, 3.6.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}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)