[ 
https://issues.apache.org/jira/browse/ZOOKEEPER-2484?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Michael Han updated ZOOKEEPER-2484:
-----------------------------------
    Attachment: ZOOKEEPER-2484.patch

We are sharing a static port number over multiple tests, and this is 
problematic because if one test failed and not got cleaned up properly, then 
there will be a cascading failure of the remaining tests that depends on the 
same port number. This patch changes the scope of the port number so each test 
case has their own specific port number when the test is executed. In case a 
port number assigned to a test case is occupied, the test case will rely on the 
existing resilient logic in PortAssignment.unique to retry a different port, 
which improved the overall stability of the tests.

> Flaky Test: org.apache.zookeeper.test.LoadFromLogTest.testLoadFailure
> ---------------------------------------------------------------------
>
>                 Key: ZOOKEEPER-2484
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2484
>             Project: ZooKeeper
>          Issue Type: Bug
>          Components: server, tests
>    Affects Versions: 3.4.8, 3.5.2
>            Reporter: Michael Han
>            Assignee: Michael Han
>              Labels: flaky, flaky-test
>             Fix For: 3.5.3
>
>         Attachments: ZOOKEEPER-2484.patch
>
>
> From https://builds.apache.org/job/ZooKeeper-trunk-openjdk7/1098/
> {noformat}
> Error Message
> KeeperErrorCode = ConnectionLoss for /data-
> Stacktrace
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode 
> = ConnectionLoss for /data-
>       at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
>       at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
>       at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:1412)
>       at 
> org.apache.zookeeper.test.LoadFromLogTest.testLoadFailure(LoadFromLogTest.java:157)
>       at 
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
> Standard Output
> 2016-07-21 04:29:02,537 [myid:] - INFO  [main:PortAssignment@157] - Single 
> test process using ports from 11221 - 32767.
> 2016-07-21 04:29:02,551 [myid:] - INFO  [main:PortAssignment@85] - Assigned 
> port 11222 from range 11221 - 32767.
> 2016-07-21 04:29:02,652 [myid:] - INFO  [main:JUnit4ZKTestRunner@47] - No 
> test.method specified. using default methods.
> 2016-07-21 04:29:02,719 [myid:] - INFO  [main:JUnit4ZKTestRunner@47] - No 
> test.method specified. using default methods.
> 2016-07-21 04:29:02,733 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testReloadSnapshotWithMissingParent
> 2016-07-21 04:29:02,734 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD 
> testReloadSnapshotWithMissingParent
> 2016-07-21 04:29:02,768 [myid:] - INFO  [main:Environment@109] - Server 
> environment:zookeeper.version=3.6.0-SNAPSHOT-1753636, built on 07/21/2016 
> 03:58 GMT
> 2016-07-21 04:29:02,768 [myid:] - INFO  [main:Environment@109] - Server 
> environment:host.name=jenkins-test-3b9
> 2016-07-21 04:29:02,768 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.version=1.7.0_101
> 2016-07-21 04:29:02,769 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.vendor=Oracle Corporation
> 2016-07-21 04:29:02,769 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre
> 2016-07-21 04:29:02,769 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jetty-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jetty-util-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/servlet-api-2.5-20081211.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/slf4j-log4j12-1.7.5.jar:/home/jenkins/tools/ant/apache-ant-1.8.2/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 04:29:02,769 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> 2016-07-21 04:29:02,769 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.io.tmpdir=/tmp
> 2016-07-21 04:29:02,770 [myid:] - INFO  [main:Environment@109] - Server 
> environment:java.compiler=<NA>
> 2016-07-21 04:29:02,770 [myid:] - INFO  [main:Environment@109] - Server 
> environment:os.name=Linux
> 2016-07-21 04:29:02,772 [myid:] - INFO  [main:Environment@109] - Server 
> environment:os.arch=amd64
> 2016-07-21 04:29:02,773 [myid:] - INFO  [main:Environment@109] - Server 
> environment:os.version=3.13.0-30-generic
> 2016-07-21 04:29:02,773 [myid:] - INFO  [main:Environment@109] - Server 
> environment:user.name=jenkins
> 2016-07-21 04:29:02,773 [myid:] - INFO  [main:Environment@109] - Server 
> environment:user.home=/home/jenkins
> 2016-07-21 04:29:02,773 [myid:] - INFO  [main:Environment@109] - Server 
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test
> 2016-07-21 04:29:02,773 [myid:] - INFO  [main:Environment@109] - Server 
> environment:os.memory.free=48MB
> 2016-07-21 04:29:02,773 [myid:] - INFO  [main:Environment@109] - Server 
> environment:os.memory.max=455MB
> 2016-07-21 04:29:02,774 [myid:] - INFO  [main:Environment@109] - Server 
> environment:os.memory.total=60MB
> 2016-07-21 04:29:02,790 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:02,790 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:02,790 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2
> 2016-07-21 04:29:02,811 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:02,821 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:02,835 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x0 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2/snapshot.0
> 2016-07-21 04:29:02,952 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:02,958 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48675
> 2016-07-21 04:29:02,967 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48675
> 2016-07-21 04:29:02,984 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:02,985 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48675 (no session 
> established for client)
> 2016-07-21 04:29:02,992 [myid:] - INFO  [main:Environment@109] - Client 
> environment:zookeeper.version=3.6.0-SNAPSHOT-1753636, built on 07/21/2016 
> 03:58 GMT
> 2016-07-21 04:29:02,992 [myid:] - INFO  [main:Environment@109] - Client 
> environment:host.name=jenkins-test-3b9
> 2016-07-21 04:29:02,992 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.version=1.7.0_101
> 2016-07-21 04:29:02,992 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.vendor=Oracle Corporation
> 2016-07-21 04:29:02,993 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.home=/usr/lib/jvm/java-7-openjdk-amd64/jre
> 2016-07-21 04:29:02,993 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/antlr-2.7.7.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/checkstyle-6.13.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-beanutils-1.9.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-cli-1.3.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-lang3-3.4.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/commons-logging-1.1.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/guava-18.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/hamcrest-core-1.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/junit-4.12.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/commons-cli-1.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jackson-core-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jackson-mapper-asl-1.9.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/javacc.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jetty-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jetty-util-6.1.26.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/jline-2.11.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/log4j-1.2.17.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/servlet-api-2.5-20081211.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/slf4j-api-1.7.5.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/lib/slf4j-log4j12-1.7.5.jar:/home/jenkins/tools/ant/apache-ant-1.8.2/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 04:29:02,993 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> 2016-07-21 04:29:02,993 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.io.tmpdir=/tmp
> 2016-07-21 04:29:02,994 [myid:] - INFO  [main:Environment@109] - Client 
> environment:java.compiler=<NA>
> 2016-07-21 04:29:02,994 [myid:] - INFO  [main:Environment@109] - Client 
> environment:os.name=Linux
> 2016-07-21 04:29:02,994 [myid:] - INFO  [main:Environment@109] - Client 
> environment:os.arch=amd64
> 2016-07-21 04:29:02,994 [myid:] - INFO  [main:Environment@109] - Client 
> environment:os.version=3.13.0-30-generic
> 2016-07-21 04:29:02,994 [myid:] - INFO  [main:Environment@109] - Client 
> environment:user.name=jenkins
> 2016-07-21 04:29:02,994 [myid:] - INFO  [main:Environment@109] - Client 
> environment:user.home=/home/jenkins
> 2016-07-21 04:29:02,995 [myid:] - INFO  [main:Environment@109] - Client 
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test
> 2016-07-21 04:29:02,995 [myid:] - INFO  [main:Environment@109] - Client 
> environment:os.memory.free=56MB
> 2016-07-21 04:29:02,995 [myid:] - INFO  [main:Environment@109] - Client 
> environment:os.memory.max=455MB
> 2016-07-21 04:29:02,995 [myid:] - INFO  [main:Environment@109] - Client 
> environment:os.memory.total=60MB
> 2016-07-21 04:29:02,998 [myid:] - INFO  [main:ZooKeeper@855] - Initiating 
> client connection, connectString=127.0.0.1:11222 sessionTimeout=3000 
> watcher=org.apache.zookeeper.test.LoadFromLogTest@20772fd3
> 2016-07-21 04:29:03,020 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:03,021 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48676
> 2016-07-21 04:29:03,021 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48676, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:03,026 [myid:] - INFO  
> [NIOWorkerThread-2:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48676
> 2016-07-21 04:29:03,030 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.1
> 2016-07-21 04:29:03,049 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e28feb0000 with negotiated timeout 6000 for client 
> /127.0.0.1:48676
> 2016-07-21 04:29:03,051 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1381] - Session 
> establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 
> 0x10002e28feb0000, negotiated timeout = 6000
> 2016-07-21 04:29:03,244 [myid:] - INFO  [main:LoadFromLogTest@553] - Set 
> lastProcessedZxid to 2
> 2016-07-21 04:29:03,244 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x2 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2/snapshot.2
> 2016-07-21 04:29:03,245 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:03,245 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:03,245 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:03,245 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:03,245 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:03,245 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:03,246 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:03,246 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:03,246 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:03,247 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:03,247 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:MBeanRegistry@128] - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e28feb0000]
> 2016-07-21 04:29:03,247 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxn@607] - Closed socket 
> connection for client /127.0.0.1:48676 which had sessionid 0x10002e28feb0000
> 2016-07-21 04:29:03,247 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:03,248 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1231] - Unable to 
> read additional data from server sessionid 0x10002e28feb0000, likely server 
> has closed socket, closing socket connection and attempting reconnect
> 2016-07-21 04:29:03,248 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:03,248 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:03,249 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:03,249 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2
> 2016-07-21 04:29:03,249 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:03,249 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:03,251 [myid:] - INFO  [main:FileSnap@83] - Reading snapshot 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2/snapshot.2
> 2016-07-21 04:29:03,253 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x5 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test393292139818745013.junit.dir/version-2/snapshot.5
> 2016-07-21 04:29:03,255 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:03,255 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48677
> 2016-07-21 04:29:03,256 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48677
> 2016-07-21 04:29:03,256 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:03,256 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48677 (no session 
> established for client)
> 2016-07-21 04:29:03,257 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:03,257 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:03,257 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:03,257 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:03,257 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:03,258 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:03,258 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:03,258 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:03,258 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:03,258 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:03,259 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:03,259 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:03,259 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 8501
> 2016-07-21 04:29:03,259 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 8
> 2016-07-21 04:29:03,260 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testReloadSnapshotWithMissingParent
> 2016-07-21 04:29:03,260 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testReloadSnapshotWithMissingParent
> 2016-07-21 04:29:03,260 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testReloadSnapshotWithMissingParent
> 2016-07-21 04:29:03,262 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testRestoreWithTransactionErrors
> 2016-07-21 04:29:03,262 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD 
> testRestoreWithTransactionErrors
> 2016-07-21 04:29:03,262 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:03,263 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:03,263 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2
> 2016-07-21 04:29:03,263 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:03,263 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:03,264 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x0 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2/snapshot.0
> 2016-07-21 04:29:03,265 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:03,266 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48678
> 2016-07-21 04:29:03,267 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48678
> 2016-07-21 04:29:03,267 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:03,267 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48678 (no session 
> established for client)
> 2016-07-21 04:29:03,268 [myid:] - INFO  [main:ZooKeeper@855] - Initiating 
> client connection, connectString=127.0.0.1:11222 sessionTimeout=3000 
> watcher=org.apache.zookeeper.test.LoadFromLogTest@5763013f
> 2016-07-21 04:29:03,268 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:03,269 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48679, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:03,269 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48679
> 2016-07-21 04:29:03,270 [myid:] - INFO  
> [NIOWorkerThread-2:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48679
> 2016-07-21 04:29:03,270 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.1
> 2016-07-21 04:29:03,273 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e291910000 with negotiated timeout 6000 for client 
> /127.0.0.1:48679
> 2016-07-21 04:29:03,274 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1381] - Session 
> establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 
> 0x10002e291910000, negotiated timeout = 6000
> 2016-07-21 04:29:03,472 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1 zxid:0x2 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,475 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2 zxid:0x3 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,477 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3 zxid:0x4 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,479 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4 zxid:0x5 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,481 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x5 zxid:0x6 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,483 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x6 zxid:0x7 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,485 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x7 zxid:0x8 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,487 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x8 zxid:0x9 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,489 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x9 zxid:0xa 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,491 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0xa zxid:0xb 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,492 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0xb zxid:0xc 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,494 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0xc zxid:0xd 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,496 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0xd zxid:0xe 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,498 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0xe zxid:0xf 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,499 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0xf zxid:0x10 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,501 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x10 zxid:0x11 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,503 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x11 zxid:0x12 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,505 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x12 zxid:0x13 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,507 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x13 zxid:0x14 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,508 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x14 zxid:0x15 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,510 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x15 zxid:0x16 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,512 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x16 zxid:0x17 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,514 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x17 zxid:0x18 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,516 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x18 zxid:0x19 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,517 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x19 zxid:0x1a 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,519 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1a zxid:0x1b 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,521 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1b zxid:0x1c 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,523 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1c zxid:0x1d 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,524 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1d zxid:0x1e 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,526 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1e zxid:0x1f 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,528 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x1f zxid:0x20 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,530 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x20 zxid:0x21 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,531 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x21 zxid:0x22 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,534 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x22 zxid:0x23 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,535 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x23 zxid:0x24 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,537 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x24 zxid:0x25 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,539 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x25 zxid:0x26 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,541 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x26 zxid:0x27 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,542 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x27 zxid:0x28 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,545 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x28 zxid:0x29 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,548 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x29 zxid:0x2a 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,549 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2a zxid:0x2b 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,551 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2b zxid:0x2c 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,552 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2c zxid:0x2d 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,554 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2d zxid:0x2e 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,556 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2e zxid:0x2f 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,557 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x2f zxid:0x30 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,559 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x30 zxid:0x31 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,561 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x31 zxid:0x32 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,563 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x32 zxid:0x33 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,564 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x33 zxid:0x34 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,565 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x34 zxid:0x35 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,567 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x35 zxid:0x36 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,569 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x36 zxid:0x37 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,571 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x37 zxid:0x38 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,572 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x38 zxid:0x39 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,574 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x39 zxid:0x3a 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,575 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3a zxid:0x3b 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,577 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3b zxid:0x3c 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,578 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3c zxid:0x3d 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,580 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3d zxid:0x3e 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,581 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3e zxid:0x3f 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,583 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x3f zxid:0x40 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,584 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x40 zxid:0x41 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,586 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x41 zxid:0x42 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,587 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x42 zxid:0x43 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,589 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x43 zxid:0x44 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,591 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x44 zxid:0x45 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,592 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x45 zxid:0x46 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,594 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x46 zxid:0x47 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,595 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x47 zxid:0x48 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,597 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x48 zxid:0x49 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,598 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x49 zxid:0x4a 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,600 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4a zxid:0x4b 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,602 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4b zxid:0x4c 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,603 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4c zxid:0x4d 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,605 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4d zxid:0x4e 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,606 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4e zxid:0x4f 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,608 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x4f zxid:0x50 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,610 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x50 zxid:0x51 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,611 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x51 zxid:0x52 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,613 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x52 zxid:0x53 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,614 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x53 zxid:0x54 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,617 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x54 zxid:0x55 
> txntype:-1 reqpath:n/a Error
> ...[truncated 64722 chars]...
>  INFO  [ProcessThread(sid:0 cport:11222)::PrepRequestProcessor@841] - Got 
> user-level KeeperException when processing sessionid:0x10002e291910000 
> type:create cxid:0x12a zxid:0x12b txntype:-1 reqpath:n/a Error 
> Path:/invaliddir Error:KeeperErrorCode = NoNode for /invaliddir
> 2016-07-21 04:29:03,976 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x12b zxid:0x12c 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,978 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@841] - Got user-level KeeperException when 
> processing sessionid:0x10002e291910000 type:create cxid:0x12c zxid:0x12d 
> txntype:-1 reqpath:n/a Error Path:/invaliddir Error:KeeperErrorCode = NoNode 
> for /invaliddir
> 2016-07-21 04:29:03,980 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@647] - Processed session termination for 
> sessionid: 0x10002e291910000
> 2016-07-21 04:29:03,981 [myid:] - INFO  [NIOWorkerThread-5:MBeanRegistry@128] 
> - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e291910000]
> 2016-07-21 04:29:03,981 [myid:] - INFO  
> [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for 
> session: 0x10002e291910000
> 2016-07-21 04:29:03,981 [myid:] - INFO  [main:ZooKeeper@1313] - Session: 
> 0x10002e291910000 closed
> 2016-07-21 04:29:03,981 [myid:] - INFO  [NIOWorkerThread-5:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48679 which had sessionid 
> 0x10002e291910000
> 2016-07-21 04:29:04,578 [myid:] - INFO  [main:LoadFromLogTest@465] - Set 
> lastProcessedZxid to 292
> 2016-07-21 04:29:04,579 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x124 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2/snapshot.124
> 2016-07-21 04:29:04,579 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:04,580 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:04,580 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:04,580 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:04,580 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:04,580 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:04,580 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:04,581 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:04,581 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:04,582 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:04,582 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:04,583 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:04,583 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:04,584 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:04,584 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2
> 2016-07-21 04:29:04,584 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:04,584 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:04,586 [myid:] - INFO  [main:FileSnap@83] - Reading snapshot 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2/snapshot.124
> 2016-07-21 04:29:04,593 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x12e to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test7440274560972421200.junit.dir/version-2/snapshot.12e
> 2016-07-21 04:29:04,594 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:04,595 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48680
> 2016-07-21 04:29:04,596 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48680
> 2016-07-21 04:29:04,596 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:04,596 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48680 (no session 
> established for client)
> 2016-07-21 04:29:04,597 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:04,597 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:04,597 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:04,598 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:04,598 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:04,598 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:04,598 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:04,598 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:04,598 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:04,599 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:04,599 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:04,599 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:04,599 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 16613
> 2016-07-21 04:29:04,600 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 10
> 2016-07-21 04:29:04,600 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testRestoreWithTransactionErrors
> 2016-07-21 04:29:04,600 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testRestoreWithTransactionErrors
> 2016-07-21 04:29:04,600 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testRestoreWithTransactionErrors
> 2016-07-21 04:29:04,601 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testPad
> 2016-07-21 04:29:04,601 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testPad
> 2016-07-21 04:29:04,601 [myid:] - INFO  [main:FileTxnLog@204] - Creating new 
> log file: log.123
> 2016-07-21 04:29:04,602 [myid:] - INFO  [main:LoadFromLogTest@343] - Received 
> magic : 1514884167 Expected : 1514884167
> 2016-07-21 04:29:04,602 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 16921
> 2016-07-21 04:29:04,602 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 10
> 2016-07-21 04:29:04,602 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testPad
> 2016-07-21 04:29:04,602 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testPad
> 2016-07-21 04:29:04,603 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testPad
> 2016-07-21 04:29:04,603 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testLoad
> 2016-07-21 04:29:04,603 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD testLoad
> 2016-07-21 04:29:04,604 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:04,604 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:04,604 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6104680937889031731.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6104680937889031731.junit.dir/version-2
> 2016-07-21 04:29:04,604 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:04,651 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:04,652 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x0 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6104680937889031731.junit.dir/version-2/snapshot.0
> 2016-07-21 04:29:04,654 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:04,654 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48681
> 2016-07-21 04:29:04,655 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48681
> 2016-07-21 04:29:04,656 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:04,656 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48681 (no session 
> established for client)
> 2016-07-21 04:29:04,656 [myid:] - INFO  [main:ZooKeeper@855] - Initiating 
> client connection, connectString=127.0.0.1:11222 sessionTimeout=3000 
> watcher=org.apache.zookeeper.test.LoadFromLogTest@24fa3073
> 2016-07-21 04:29:04,657 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:04,658 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48682
> 2016-07-21 04:29:04,658 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48682, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:04,659 [myid:] - INFO  
> [NIOWorkerThread-2:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48682
> 2016-07-21 04:29:04,659 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.1
> 2016-07-21 04:29:04,663 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e296fd0000 with negotiated timeout 6000 for client 
> /127.0.0.1:48682
> 2016-07-21 04:29:04,663 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1381] - Session 
> establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 
> 0x10002e296fd0000, negotiated timeout = 6000
> 2016-07-21 04:29:04,839 [myid:] - INFO  [Snapshot Thread:FileTxnSnapLog@298] 
> - Snapshotting: 0x63 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6104680937889031731.junit.dir/version-2/snapshot.63
> 2016-07-21 04:29:04,840 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.65
> 2016-07-21 04:29:04,958 [myid:] - INFO  [Snapshot Thread:FileTxnSnapLog@298] 
> - Snapshotting: 0xac to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6104680937889031731.junit.dir/version-2/snapshot.ac
> 2016-07-21 04:29:04,959 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.ae
> 2016-07-21 04:29:05,068 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:05,069 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48683
> 2016-07-21 04:29:05,069 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48683, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:05,070 [myid:] - INFO  
> [NIOWorkerThread-1:ZooKeeperServer@969] - Client attempting to renew session 
> 0x10002e28feb0000 at /127.0.0.1:48683
> 2016-07-21 04:29:05,070 [myid:] - INFO  
> [NIOWorkerThread-1:ZooKeeperServer@686] - Invalid session 0x10002e28feb0000 
> for client /127.0.0.1:48683, probably expired
> 2016-07-21 04:29:05,071 [myid:] - INFO  [NIOWorkerThread-4:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48683 which had sessionid 
> 0x10002e28feb0000
> 2016-07-21 04:29:05,071 [myid:] - INFO  
> [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for 
> session: 0x10002e28feb0000
> 2016-07-21 04:29:05,071 [myid:127.0.0.1:11222] - WARN  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1367] - Unable to 
> reconnect to ZooKeeper service, session 0x10002e28feb0000 has expired
> 2016-07-21 04:29:05,071 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1227] - Unable to 
> reconnect to ZooKeeper service, session 0x10002e28feb0000 has expired, 
> closing socket connection
> 2016-07-21 04:29:05,106 [myid:] - INFO  [Snapshot Thread:FileTxnSnapLog@298] 
> - Snapshotting: 0x107 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6104680937889031731.junit.dir/version-2/snapshot.107
> 2016-07-21 04:29:05,107 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.109
> 2016-07-21 04:29:05,165 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@647] - Processed session termination for 
> sessionid: 0x10002e296fd0000
> 2016-07-21 04:29:05,166 [myid:] - INFO  [main:ZooKeeper@1313] - Session: 
> 0x10002e296fd0000 closed
> 2016-07-21 04:29:05,167 [myid:] - INFO  
> [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for 
> session: 0x10002e296fd0000
> 2016-07-21 04:29:05,167 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:05,166 [myid:] - INFO  [NIOWorkerThread-7:MBeanRegistry@128] 
> - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e296fd0000]
> 2016-07-21 04:29:05,167 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:05,167 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:05,168 [myid:] - INFO  [NIOWorkerThread-7:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48682 which had sessionid 
> 0x10002e296fd0000
> 2016-07-21 04:29:05,168 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:05,168 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:05,168 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:05,169 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:05,169 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:05,169 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:05,169 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:05,169 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:05,170 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:05,170 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:05,172 [myid:] - INFO  [main:LoadFromLogTest@115] - Txnlog 
> size: 307248 bytes
> 2016-07-21 04:29:05,186 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 7789
> 2016-07-21 04:29:05,187 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 11
> 2016-07-21 04:29:05,187 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testLoad
> 2016-07-21 04:29:05,187 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testLoad
> 2016-07-21 04:29:05,187 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testLoad
> 2016-07-21 04:29:05,188 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testTxnFailure
> 2016-07-21 04:29:05,188 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD 
> testTxnFailure
> 2016-07-21 04:29:05,188 [myid:] - INFO  [main:LoadFromLogTest@245] - 
> Attempting to create /test/3
> 2016-07-21 04:29:05,189 [myid:] - INFO  [main:LoadFromLogTest@281] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,189 [myid:] - INFO  [main:LoadFromLogTest@282] - 
> (cverions, pzxid): 3, 3
> 2016-07-21 04:29:05,189 [myid:] - INFO  [main:LoadFromLogTest@319] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,189 [myid:] - INFO  [main:LoadFromLogTest@320] - 
> (cverions, pzxid): 4, 4
> 2016-07-21 04:29:05,189 [myid:] - INFO  [main:LoadFromLogTest@248] - 
> Attempting to create /test/3
> 2016-07-21 04:29:05,189 [myid:] - INFO  [main:LoadFromLogTest@281] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,190 [myid:] - INFO  [main:LoadFromLogTest@282] - 
> (cverions, pzxid): 4, 4
> 2016-07-21 04:29:05,190 [myid:] - INFO  [main:LoadFromLogTest@319] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,190 [myid:] - INFO  [main:LoadFromLogTest@320] - 
> (cverions, pzxid): 5, 5
> 2016-07-21 04:29:05,190 [myid:] - INFO  [main:LoadFromLogTest@252] - 
> Attempting to create /test/3
> 2016-07-21 04:29:05,190 [myid:] - INFO  [main:LoadFromLogTest@281] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,190 [myid:] - INFO  [main:LoadFromLogTest@282] - 
> (cverions, pzxid): 5, 5
> 2016-07-21 04:29:05,192 [myid:] - INFO  [main:LoadFromLogTest@319] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,192 [myid:] - INFO  [main:LoadFromLogTest@320] - 
> (cverions, pzxid): 6, 6
> 2016-07-21 04:29:05,192 [myid:] - INFO  [main:LoadFromLogTest@256] - 
> Attempting to create /test/3
> 2016-07-21 04:29:05,193 [myid:] - INFO  [main:LoadFromLogTest@281] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,193 [myid:] - INFO  [main:LoadFromLogTest@282] - 
> (cverions, pzxid): 6, 6
> 2016-07-21 04:29:05,193 [myid:] - INFO  [main:LoadFromLogTest@319] - 
> Children: 3 2 1  for /test
> 2016-07-21 04:29:05,193 [myid:] - INFO  [main:LoadFromLogTest@320] - 
> (cverions, pzxid): 7, 7
> 2016-07-21 04:29:05,193 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 8013
> 2016-07-21 04:29:05,193 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 11
> 2016-07-21 04:29:05,194 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testTxnFailure
> 2016-07-21 04:29:05,194 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testTxnFailure
> 2016-07-21 04:29:05,194 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testTxnFailure
> 2016-07-21 04:29:05,194 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testDatadirAutocreate
> 2016-07-21 04:29:05,194 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD 
> testDatadirAutocreate
> 2016-07-21 04:29:05,195 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:05,195 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:05,195 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6847426618122472335.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6847426618122472335.junit.dir/version-2
> 2016-07-21 04:29:05,195 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:05,196 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:05,197 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x0 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6847426618122472335.junit.dir/version-2/snapshot.0
> 2016-07-21 04:29:05,198 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:05,198 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48685
> 2016-07-21 04:29:05,199 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48685
> 2016-07-21 04:29:05,199 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:05,200 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48685 (no session 
> established for client)
> 2016-07-21 04:29:05,200 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:05,200 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:05,200 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:05,200 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:05,200 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:05,200 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:05,201 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:05,201 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:05,201 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:05,202 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:05,202 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:05,202 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:05,202 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:05,203 [myid:] - INFO  [main:LoadFromLogTest@517] - Server 
> failed to start - correct behavior 
> org.apache.zookeeper.server.persistence.FileTxnSnapLog$DatadirException: 
> Missing data directory 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test6323392488588100984.junit.dir/version-2,
>  automatic data directory creation is disabled (zookeeper.datadir.autocreate 
> is false). Please create this directory manually.
> 2016-07-21 04:29:05,203 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 8605
> 2016-07-21 04:29:05,203 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 12
> 2016-07-21 04:29:05,203 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testDatadirAutocreate
> 2016-07-21 04:29:05,203 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testDatadirAutocreate
> 2016-07-21 04:29:05,203 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testDatadirAutocreate
> 2016-07-21 04:29:05,204 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testRestore
> 2016-07-21 04:29:05,204 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD 
> testRestore
> 2016-07-21 04:29:05,205 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:05,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:05,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:05,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:05,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:05,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:05,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:13,168 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:13,169 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2
> 2016-07-21 04:29:13,170 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:13,170 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:13,171 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x0 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2/snapshot.0
> 2016-07-21 04:29:13,173 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:13,173 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48687
> 2016-07-21 04:29:13,175 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48687
> 2016-07-21 04:29:13,175 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:13,176 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48687 (no session 
> established for client)
> 2016-07-21 04:29:13,176 [myid:] - INFO  [main:ZooKeeper@855] - Initiating 
> client connection, connectString=127.0.0.1:11222 sessionTimeout=3000 
> watcher=org.apache.zookeeper.test.LoadFromLogTest@3f9e244f
> 2016-07-21 04:29:13,177 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:13,177 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48688, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:13,177 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48688
> 2016-07-21 04:29:13,178 [myid:] - INFO  
> [NIOWorkerThread-2:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48688
> 2016-07-21 04:29:13,179 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.1
> 2016-07-21 04:29:13,182 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e2b8440000 with negotiated timeout 6000 for client 
> /127.0.0.1:48688
> 2016-07-21 04:29:13,182 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1381] - Session 
> establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 
> 0x10002e2b8440000, negotiated timeout = 6000
> 2016-07-21 04:29:13,823 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@647] - Processed session termination for 
> sessionid: 0x10002e2b8440000
> 2016-07-21 04:29:13,824 [myid:] - INFO  [main:ZooKeeper@1313] - Session: 
> 0x10002e2b8440000 closed
> 2016-07-21 04:29:13,824 [myid:] - INFO  
> [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for 
> session: 0x10002e2b8440000
> 2016-07-21 04:29:13,824 [myid:] - INFO  [NIOWorkerThread-7:MBeanRegistry@128] 
> - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e2b8440000]
> 2016-07-21 04:29:13,824 [myid:] - INFO  [main:LoadFromLogTest@387] - Set 
> lastProcessedZxid to 293
> 2016-07-21 04:29:13,825 [myid:] - INFO  [NIOWorkerThread-7:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48688 which had sessionid 
> 0x10002e2b8440000
> 2016-07-21 04:29:13,825 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x125 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2/snapshot.125
> 2016-07-21 04:29:13,830 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:13,830 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:13,830 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:13,830 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:13,830 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:13,830 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:13,831 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:13,831 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:13,831 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:13,832 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:13,834 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:13,834 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:13,835 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:13,835 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:13,835 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2
> 2016-07-21 04:29:13,836 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:13,836 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:13,837 [myid:] - INFO  [main:FileSnap@83] - Reading snapshot 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2/snapshot.125
> 2016-07-21 04:29:13,858 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x12f to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test4732590081806435620.junit.dir/version-2/snapshot.12f
> 2016-07-21 04:29:13,862 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:14,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:19,360 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48689
> 2016-07-21 04:29:19,362 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48689
> 2016-07-21 04:29:19,362 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:19,362 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48689 (no session 
> established for client)
> 2016-07-21 04:29:19,363 [myid:] - INFO  [main:ZooKeeper@855] - Initiating 
> client connection, connectString=127.0.0.1:11222 sessionTimeout=3000 
> watcher=org.apache.zookeeper.test.LoadFromLogTest@3f9e244f
> 2016-07-21 04:29:19,364 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:19,364 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48690
> 2016-07-21 04:29:19,364 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48690, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:19,365 [myid:] - INFO  
> [NIOWorkerThread-2:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48690
> 2016-07-21 04:29:19,366 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.130
> 2016-07-21 04:29:19,368 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e2baf60000 with negotiated timeout 6000 for client 
> /127.0.0.1:48690
> 2016-07-21 04:29:19,369 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1381] - Session 
> establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 
> 0x10002e2baf60000, negotiated timeout = 6000
> 2016-07-21 04:29:19,574 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@647] - Processed session termination for 
> sessionid: 0x10002e2baf60000
> 2016-07-21 04:29:19,575 [myid:] - INFO  [main:ZooKeeper@1313] - Session: 
> 0x10002e2baf60000 closed
> 2016-07-21 04:29:19,575 [myid:] - INFO  
> [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for 
> session: 0x10002e2baf60000
> 2016-07-21 04:29:19,575 [myid:] - INFO  [NIOWorkerThread-1:MBeanRegistry@128] 
> - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e2baf60000]
> 2016-07-21 04:29:19,575 [myid:] - INFO  [main:LoadFromLogTest@420] - Expected 
> /invalidsnap/test-0000000300 found /invalidsnap/test-0000000300
> 2016-07-21 04:29:19,576 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48690 which had sessionid 
> 0x10002e2baf60000
> 2016-07-21 04:29:19,576 [myid:] - INFO  
> [ConnnectionExpirer:NIOServerCnxnFactory$ConnectionExpirerThread@583] - 
> ConnnectionExpirerThread interrupted
> 2016-07-21 04:29:19,578 [myid:] - INFO  
> [NIOServerCxnFactory.SelectorThread-0:NIOServerCnxnFactory$SelectorThread@420]
>  - selector thread exitted run method
> 2016-07-21 04:29:19,578 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@219]
>  - accept thread exitted run method
> 2016-07-21 04:29:19,578 [myid:] - INFO  [main:ZooKeeperServer@498] - shutting 
> down
> 2016-07-21 04:29:19,578 [myid:] - INFO  [main:SessionTrackerImpl@232] - 
> Shutting down
> 2016-07-21 04:29:19,578 [myid:] - INFO  [main:PrepRequestProcessor@965] - 
> Shutting down
> 2016-07-21 04:29:19,578 [myid:] - INFO  [main:SyncRequestProcessor@191] - 
> Shutting down
> 2016-07-21 04:29:19,578 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@154] - PrepRequestProcessor exited loop!
> 2016-07-21 04:29:19,579 [myid:] - INFO  
> [SyncThread:0:SyncRequestProcessor@169] - SyncRequestProcessor exited!
> 2016-07-21 04:29:19,579 [myid:] - INFO  [main:FinalRequestProcessor@479] - 
> shutdown of request processor complete
> 2016-07-21 04:29:19,579 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=InMemoryDataTree]
> 2016-07-21 04:29:19,580 [myid:] - INFO  [main:MBeanRegistry@128] - Unregister 
> MBean [org.apache.ZooKeeperService:name0=StandaloneServer_port11222]
> 2016-07-21 04:29:19,580 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@82] - Memory used 16954
> 2016-07-21 04:29:19,580 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@87] - Number of threads 6
> 2016-07-21 04:29:19,580 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@102] - FINISHED TEST METHOD 
> testRestore
> 2016-07-21 04:29:19,580 [myid:] - INFO  [main:ZKTestCase$1@65] - SUCCEEDED 
> testRestore
> 2016-07-21 04:29:19,580 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testRestore
> 2016-07-21 04:29:19,581 [myid:] - INFO  [main:ZKTestCase$1@55] - STARTING 
> testLoadFailure
> 2016-07-21 04:29:19,581 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@77] - RUNNING TEST METHOD 
> testLoadFailure
> 2016-07-21 04:29:19,581 [myid:] - INFO  [main:ZooKeeperServer@858] - 
> minSessionTimeout set to 6000
> 2016-07-21 04:29:19,581 [myid:] - INFO  [main:ZooKeeperServer@867] - 
> maxSessionTimeout set to 60000
> 2016-07-21 04:29:19,582 [myid:] - INFO  [main:ZooKeeperServer@156] - Created 
> server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 
> datadir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test436661564740529918.junit.dir/version-2
>  snapdir 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test436661564740529918.junit.dir/version-2
> 2016-07-21 04:29:19,582 [myid:] - INFO  [main:NIOServerCnxnFactory@673] - 
> Configuring NIO connection handler with 10s sessionless connection timeout, 1 
> selector thread(s), 8 worker threads, and 64 kB direct buffers.
> 2016-07-21 04:29:19,582 [myid:] - INFO  [main:NIOServerCnxnFactory@686] - 
> binding to port 0.0.0.0/0.0.0.0:11222
> 2016-07-21 04:29:19,583 [myid:] - INFO  [main:FileTxnSnapLog@298] - 
> Snapshotting: 0x0 to 
> /home/jenkins/jenkins-slave/workspace/ZooKeeper-trunk-openjdk7/trunk/build/test/tmp/test436661564740529918.junit.dir/version-2/snapshot.0
> 2016-07-21 04:29:19,584 [myid:] - INFO  [main:FourLetterWordMain@85] - 
> connecting to 127.0.0.1 11222
> 2016-07-21 04:29:19,585 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48691
> 2016-07-21 04:29:19,586 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@485] 
> - Processing stat command from /127.0.0.1:48691
> 2016-07-21 04:29:19,586 [myid:] - INFO  [NIOWorkerThread-1:StatCommand@49] - 
> Stat command output
> 2016-07-21 04:29:19,586 [myid:] - INFO  [NIOWorkerThread-1:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48691 (no session 
> established for client)
> 2016-07-21 04:29:19,586 [myid:] - INFO  [main:ZooKeeper@855] - Initiating 
> client connection, connectString=127.0.0.1:11222 sessionTimeout=3000 
> watcher=org.apache.zookeeper.test.LoadFromLogTest@1b2090ab
> 2016-07-21 04:29:19,587 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:19,588 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48692
> 2016-07-21 04:29:19,588 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48692, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:20,432 [myid:] - INFO  
> [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
> 2016-07-21 04:29:27,620 [myid:127.0.0.1:11222] - WARN  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1181] - Client 
> session timed out, have not heard from server in 8032ms for sessionid 0x0
> 2016-07-21 04:29:27,621 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1229] - Client 
> session timed out, have not heard from server in 8032ms for sessionid 0x0, 
> closing socket connection and attempting reconnect
> 2016-07-21 04:29:27,621 [myid:] - INFO  
> [NIOWorkerThread-2:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48692
> 2016-07-21 04:29:27,622 [myid:] - INFO  [SyncThread:0:FileTxnLog@204] - 
> Creating new log file: log.1
> 2016-07-21 04:29:27,624 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e2d1500000 with negotiated timeout 6000 for client 
> /127.0.0.1:48692
> 2016-07-21 04:29:27,625 [myid:] - WARN  [NIOWorkerThread-4:NIOServerCnxn@365] 
> - Unable to read additional data from client sessionid 0x10002e2d1500000, 
> likely client has closed socket
> 2016-07-21 04:29:27,626 [myid:] - INFO  [NIOWorkerThread-4:MBeanRegistry@128] 
> - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e2d1500000]
> 2016-07-21 04:29:27,626 [myid:] - INFO  [NIOWorkerThread-4:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48692 which had sessionid 
> 0x10002e2d1500000
> 2016-07-21 04:29:28,739 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1113] - 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 04:29:28,740 [myid:] - INFO  
> [NIOServerCxnFactory.AcceptThread:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory$AcceptThread@296]
>  - Accepted socket connection from /127.0.0.1:48693
> 2016-07-21 04:29:28,740 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@948] - Socket 
> connection established, initiating session, client: /127.0.0.1:48693, server: 
> 127.0.0.1/127.0.0.1:11222
> 2016-07-21 04:29:28,741 [myid:] - INFO  
> [NIOWorkerThread-5:ZooKeeperServer@964] - Client attempting to establish new 
> session at /127.0.0.1:48693
> 2016-07-21 04:29:28,742 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@678] - 
> Established session 0x10002e2d1500001 with negotiated timeout 6000 for client 
> /127.0.0.1:48693
> 2016-07-21 04:29:28,743 [myid:127.0.0.1:11222] - INFO  
> [main-SendThread(127.0.0.1:11222):ClientCnxn$SendThread@1381] - Session 
> establishment complete on server 127.0.0.1/127.0.0.1:11222, sessionid = 
> 0x10002e2d1500001, negotiated timeout = 6000
> 2016-07-21 04:29:28,744 [myid:] - INFO  [ProcessThread(sid:0 
> cport:11222)::PrepRequestProcessor@647] - Processed session termination for 
> sessionid: 0x10002e2d1500001
> 2016-07-21 04:29:28,746 [myid:] - INFO  [NIOWorkerThread-8:MBeanRegistry@128] 
> - Unregister MBean 
> [org.apache.ZooKeeperService:name0=StandaloneServer_port11222,name1=Connections,name2=127.0.0.1,name3=0x10002e2d1500001]
> 2016-07-21 04:29:28,746 [myid:] - INFO  
> [main-EventThread:ClientCnxn$EventThread@513] - EventThread shut down for 
> session: 0x10002e2d1500001
> 2016-07-21 04:29:28,746 [myid:] - INFO  [NIOWorkerThread-8:NIOServerCnxn@607] 
> - Closed socket connection for client /127.0.0.1:48693 which had sessionid 
> 0x10002e2d1500001
> 2016-07-21 04:29:28,746 [myid:] - INFO  [main:ZooKeeper@1313] - Session: 
> 0x10002e2d1500001 closed
> 2016-07-21 04:29:28,748 [myid:] - INFO  
> [main:JUnit4ZKTestRunner$LoggedInvokeMethod@98] - TEST METHOD FAILED 
> testLoadFailure
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode 
> = ConnectionLoss for /data-
>       at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
>       at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
>       at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:1412)
>       at 
> org.apache.zookeeper.test.LoadFromLogTest.testLoadFailure(LoadFromLogTest.java:157)
>       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>       at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>       at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>       at java.lang.reflect.Method.invoke(Method.java:606)
>       at 
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
>       at 
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
>       at 
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
>       at 
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
>       at 
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
>       at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
>       at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
>       at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
>       at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
>       at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
>       at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
>       at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
>       at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
>       at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
>       at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
>       at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
>       at 
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518)
>       at 
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052)
>       at 
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906)
> 2016-07-21 04:29:28,750 [myid:] - INFO  [main:ZKTestCase$1@70] - FAILED 
> testLoadFailure
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode 
> = ConnectionLoss for /data-
>       at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
>       at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
>       at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:1412)
>       at 
> org.apache.zookeeper.test.LoadFromLogTest.testLoadFailure(LoadFromLogTest.java:157)
>       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>       at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>       at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>       at java.lang.reflect.Method.invoke(Method.java:606)
>       at 
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
>       at 
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
>       at 
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
>       at 
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
>       at 
> org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:79)
>       at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:53)
>       at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
>       at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
>       at 
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
>       at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
>       at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
>       at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
>       at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
>       at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
>       at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
>       at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
>       at 
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518)
>       at 
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052)
>       at 
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906)
> 2016-07-21 04:29:29,830 [myid:] - INFO  [main:ZKTestCase$1@60] - FINISHED 
> testLoadFailure
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to