[ZOOKEEPER-2484] Flaky Test: org.apache.zookeeper.test.LoadFromLogTest.testLoadFailure - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Test
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: 3.4.8, 3.5.2
Fix Version/s: 3.5.3, 3.6.0
Component/s: server, tests
Labels:
- flaky
- flaky-test

Hadoop Flags:

Reviewed

Description

From https://builds.apache.org/job/ZooKeeper-trunk-openjdk7/1098/

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

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending

ZOOKEEPER-2484.patch
08/Sep/16 17:33
15 kB
Michael Han
ZOOKEEPER-2484.patch
22/Jul/16 20:37
11 kB
Michael Han

Issue Links

relates to

ZOOKEEPER-2135 fix trunk build

Open

Activity

People

Assignee:: Michael Han

Reporter:: Michael Han

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 21/Jul/16 21:55

Updated:: 18/May/17 03:43

Resolved:: 08/Sep/16 22:11