[ https://issues.apache.org/jira/browse/ZOOKEEPER-2485?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Andor Molnar resolved ZOOKEEPER-2485. ------------------------------------- Resolution: Cannot Reproduce > Flaky Test: org.apache.zookeeper.test.FourLetterWordsTest.testFourLetterWords > ----------------------------------------------------------------------------- > > Key: ZOOKEEPER-2485 > URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2485 > Project: ZooKeeper > Issue Type: Sub-task > Components: tests > Affects Versions: 3.4.8 > Reporter: Michael Han > Assignee: Andor Molnar > Priority: Major > Labels: flaky, flaky-test > Fix For: 3.6.0, 3.5.5 > > > 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 (v7.6.3#76005)