sgroschupf/zkclient

SaslAuthenticatedTest failure

Opened this issue · 2 comments

Hi
I'm getting:

org.I0Itec.zkclient.exception.ZkException: org.apache.zookeeper.KeeperException$InvalidACLException: KeeperErrorCode = InvalidACL for /test
    at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:68)
    at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1000)
    at org.I0Itec.zkclient.ZkClient.create(ZkClient.java:527)
    at org.I0Itec.zkclient.ZkClient.createPersistent(ZkClient.java:404)
    at org.I0Itec.zkclient.SaslAuthenticatedTest.testConnection(SaslAuthenticatedTest.java:121)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    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:52)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
    at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
    at org.junit.rules.RunRules.evaluate(RunRules.java:20)
    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 org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
    at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
    at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
    at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
    at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
    at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
    at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
    at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
    at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54)
    at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$InvalidACLException: KeeperErrorCode = InvalidACL for /test
    at org.apache.zookeeper.KeeperException.create(KeeperException.java:121)
    at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
    at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
    at org.I0Itec.zkclient.ZkConnection.create(ZkConnection.java:99)
    at org.I0Itec.zkclient.ZkClient$3.call(ZkClient.java:530)
    at org.I0Itec.zkclient.ZkClient$3.call(ZkClient.java:527)
    at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:990)
    ... 50 more

Environment:
Gradle 2.5
Build number: Fedora 2.5-3.fc23
Groovy: 2.4.4
Ant: Apache Ant(TM) version 1.9.6 compiled on July 10 2015
JVM: 1.8.0_91 (Oracle Corporation 25.91-b14)
Java version: 1.8.0_91, vendor: Oracle Corporation
Java home: /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.91-2.b14.fc23.i386/jre
OS: Linux 4.4.7-300.fc23.i686 i386
Default locale: it_IT, platform encoding: UTF-8

Any ideas as to why?
(temporarily i removed @test annotations in SaslAuthenticatedTest.java)
Thanks in advance

fpj commented

Weird, I can't repro it. I'll have a closer look. You may want to have a look at your log4j output to see if you can spot any problems. If you can post it somewhere, then perhaps I can have a look.

Sorry for delay
I used log4j 1.2.17

<?xml version="1.0" encoding="UTF-8"?>
<testsuite name="org.I0Itec.zkclient.SaslAuthenticatedTest" tests="6" skipped="0" failures="1" errors="0" timestamp="2016-12-01T23:37:49" hostname="localhost.localdomain" time="32.394">
  <properties/>
  <testcase name="testConnection" classname="org.I0Itec.zkclient.SaslAuthenticatedTest" time="0.507">
    <failure message="org.I0Itec.zkclient.exception.ZkException: org.apache.zookeeper.KeeperException$InvalidACLException: KeeperErrorCode = InvalidACL for /test" type="org.I0Itec.zkclient.exception.ZkException">org.I0Itec.zkclient.exception.ZkException: org.apache.zookeeper.KeeperException$InvalidACLException: KeeperErrorCode = InvalidACL for /test
	at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:68)
	at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1001)
	at org.I0Itec.zkclient.ZkClient.create(ZkClient.java:528)
	at org.I0Itec.zkclient.ZkClient.createPersistent(ZkClient.java:405)
	at org.I0Itec.zkclient.SaslAuthenticatedTest.testConnection(SaslAuthenticatedTest.java:121)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	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:52)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	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 org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:112)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:56)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54)
	at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$InvalidACLException: KeeperErrorCode = InvalidACL for /test
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:121)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.I0Itec.zkclient.ZkConnection.create(ZkConnection.java:100)
	at org.I0Itec.zkclient.ZkClient$3.call(ZkClient.java:531)
	at org.I0Itec.zkclient.ZkClient$3.call(ZkClient.java:528)
	at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:991)
	... 50 more
</failure>
  </testcase>
  <testcase name="testNoZkJaasFile" classname="org.I0Itec.zkclient.SaslAuthenticatedTest" time="0.303"/>
  <testcase name="testAuthFailure_DisabledSasl" classname="org.I0Itec.zkclient.SaslAuthenticatedTest" time="20.394"/>
  <testcase name="testAuthFailure_AllowFailedSasl" classname="org.I0Itec.zkclient.SaslAuthenticatedTest" time="0.292"/>
  <testcase name="testAuthFailure" classname="org.I0Itec.zkclient.SaslAuthenticatedTest" time="10.581"/>
  <testcase name="testUnauthenticatedClient" classname="org.I0Itec.zkclient.SaslAuthenticatedTest" time="0.317"/>
  <system-out><![CDATA[16/12/02 00:37:49  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:37:49  INFO [Time-limited test-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:37:49  INFO [Time-limited test-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:37:49  INFO [Time-limited test-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:37:49  INFO [Test worker] (ZkServer.java:89) - Starting ZkServer on: [ localhost, 192.168.1.3, fe80:0:0:0:225:22ff:fe6f:d60a%enp2s0, localhost6.localdomain6, 0.0.0.0000000000001, localhost.localdomain, 127.0.0.1, 254.128.0.000002373425525411121410] port 4700...
16/12/02 00:37:49  INFO [Test worker] (ZkServer.java:127) - Start single zookeeper server...
16/12/02 00:37:49  INFO [Test worker] (ZkServer.java:128) - data dir: /tmp/junit1558871446783463971/data
16/12/02 00:37:49  INFO [Test worker] (ZkServer.java:129) - data log dir: /tmp/junit1558871446783463971/log
16/12/02 00:37:49  INFO [Test worker] (ZkServer.java:130) - JAAS login file: /tmp/junit1558871446783463971/jaas.conf
16/12/02 00:37:49  INFO [Test worker] (ZkClient.java:902) - JAAS File name: /tmp/junit1558871446783463971/jaas.conf
16/12/02 00:37:49  INFO [ZkClient-EventThread-497-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:37:49  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SaslAuthenticated
16/12/02 00:37:50  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:37:50  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SaslAuthenticated)
16/12/02 00:37:50 ERROR [ProcessThread(sid:0 cport:-1):] (PrepRequestProcessor.java:726) - Missing AuthenticationProvider for sasl
16/12/02 00:37:50  INFO [ZkClient-EventThread-497-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:155) - Shutting down ZkServer...
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:176) - Shutting down ZkServer...done
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:89) - Starting ZkServer on: [ localhost, 192.168.1.3, fe80:0:0:0:225:22ff:fe6f:d60a%enp2s0, localhost6.localdomain6, 0.0.0.0000000000001, localhost.localdomain, 127.0.0.1, 254.128.0.000002373425525411121410] port 4700...
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:127) - Start single zookeeper server...
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:128) - data dir: /tmp/junit2475850039928376802/data
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:129) - data log dir: /tmp/junit2475850039928376802/log
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:130) - JAAS login file: /tmp/junit2475850039928376802/jaas.conf
16/12/02 00:37:50  INFO [Test worker] (ZkClient.java:902) - JAAS File name: /tmp/junit2475850039928376802/jaas.conf
16/12/02 00:37:50  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SyncConnected
16/12/02 00:37:50  INFO [ZkClient-EventThread-504-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:37:50  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (AuthFailed)
16/12/02 00:37:50  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:37:50  INFO [ZkClient-EventThread-504-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:155) - Shutting down ZkServer...
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:176) - Shutting down ZkServer...done
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:89) - Starting ZkServer on: [ localhost, 192.168.1.3, fe80:0:0:0:225:22ff:fe6f:d60a%enp2s0, localhost6.localdomain6, 0.0.0.0000000000001, localhost.localdomain, 127.0.0.1, 254.128.0.000002373425525411121410] port 4700...
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:127) - Start single zookeeper server...
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:128) - data dir: /tmp/junit9045833519867582132/data
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:129) - data log dir: /tmp/junit9045833519867582132/log
16/12/02 00:37:50  INFO [Test worker] (ZkServer.java:130) - JAAS login file: /tmp/junit9045833519867582132/jaas.conf
16/12/02 00:37:50  WARN [Test worker] (ZkClient.java:896) - Client SASL has been explicitly disabled with zookeeper.sasl.client
16/12/02 00:37:50  INFO [ZkClient-EventThread-511-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:37:50  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SyncConnected
16/12/02 00:37:50  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:37:50  INFO [ZkClient-EventThread-511-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:38:10  INFO [Test worker] (ZkServer.java:155) - Shutting down ZkServer...
16/12/02 00:38:10  INFO [Test worker] (ZkServer.java:176) - Shutting down ZkServer...done
16/12/02 00:38:10  INFO [Test worker] (ZkServer.java:89) - Starting ZkServer on: [ localhost, 192.168.1.3, fe80:0:0:0:225:22ff:fe6f:d60a%enp2s0, localhost6.localdomain6, 0.0.0.0000000000001, localhost.localdomain, 127.0.0.1, 254.128.0.000002373425525411121410] port 4700...
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:127) - Start single zookeeper server...
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:128) - data dir: /tmp/junit1813257635615635540/data
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:129) - data log dir: /tmp/junit1813257635615635540/log
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:130) - JAAS login file: /tmp/junit1813257635615635540/jaas.conf
16/12/02 00:38:11  INFO [Test worker] (ZkClient.java:902) - JAAS File name: /tmp/junit1813257635615635540/jaas.conf
16/12/02 00:38:11  INFO [ZkClient-EventThread-518-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:38:11  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SaslAuthenticated
16/12/02 00:38:11  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:11 ERROR [Test worker-SendThread(localhost.localdomain:4700)] (ZooKeeperSaslClient.java:323) - SASL authentication failed using login context 'Client'.
16/12/02 00:38:11  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (AuthFailed)
16/12/02 00:38:11  INFO [ZkClient-EventThread-518-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:155) - Shutting down ZkServer...
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:176) - Shutting down ZkServer...done
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:89) - Starting ZkServer on: [ localhost, 192.168.1.3, fe80:0:0:0:225:22ff:fe6f:d60a%enp2s0, localhost6.localdomain6, 0.0.0.0000000000001, localhost.localdomain, 127.0.0.1, 254.128.0.000002373425525411121410] port 4700...
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:127) - Start single zookeeper server...
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:128) - data dir: /tmp/junit4779014690450239353/data
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:129) - data log dir: /tmp/junit4779014690450239353/log
16/12/02 00:38:11  INFO [Test worker] (ZkServer.java:130) - JAAS login file: /tmp/junit4779014690450239353/jaas.conf
16/12/02 00:38:11  INFO [Test worker] (ZkClient.java:902) - JAAS File name: /tmp/junit4779014690450239353/jaas.conf
16/12/02 00:38:11  INFO [ZkClient-EventThread-525-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:38:11  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SaslAuthenticated
16/12/02 00:38:11  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:11 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:11  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:12  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:12 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:12  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:14  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:14 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:14  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:16  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:16 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:16  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:17  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:17 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:17  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:19  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:19 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:19  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:20  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:20 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:20  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (Disconnected)
16/12/02 00:38:21  INFO [ZkClient-EventThread-525-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:38:21 ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:4700] (NIOServerCnxn.java:178) - Unexpected Exception: 
java.nio.channels.CancelledKeyException
	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:151)
	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1081)
	at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:936)
	at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:373)
	at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:200)
	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:244)
	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
	at java.lang.Thread.run(Thread.java:745)
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:155) - Shutting down ZkServer...
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:176) - Shutting down ZkServer...done
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:89) - Starting ZkServer on: [ localhost, 192.168.1.3, fe80:0:0:0:225:22ff:fe6f:d60a%enp2s0, localhost6.localdomain6, 0.0.0.0000000000001, localhost.localdomain, 127.0.0.1, 254.128.0.000002373425525411121410] port 4700...
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:127) - Start single zookeeper server...
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:128) - data dir: /tmp/junit7580197541578640069/data
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:129) - data log dir: /tmp/junit7580197541578640069/log
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:130) - JAAS login file: /tmp/junit7580197541578640069/jaas.conf
16/12/02 00:38:21  INFO [Test worker] (ZkClient.java:902) - JAAS File name: /tmp/junit7580197541578640069/jaas.conf
16/12/02 00:38:21  INFO [ZkClient-EventThread-532-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:38:21  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SaslAuthenticated
16/12/02 00:38:21  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:21  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SaslAuthenticated)
16/12/02 00:38:21  INFO [ZkClient-EventThread-535-localhost:4700] (ZkEventThread.java:65) - Starting ZkClient event thread.
16/12/02 00:38:21  INFO [Test worker] (ZkClient.java:936) - Waiting for keeper state SyncConnected
16/12/02 00:38:21  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SyncConnected)
16/12/02 00:38:21  INFO [Test worker-EventThread] (ZkClient.java:713) - zookeeper state changed (SaslAuthenticated)
16/12/02 00:38:21  INFO [ZkClient-EventThread-535-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:38:21  INFO [ZkClient-EventThread-532-localhost:4700] (ZkEventThread.java:83) - Terminate ZkClient event thread.
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:155) - Shutting down ZkServer...
16/12/02 00:38:21  INFO [Test worker] (ZkServer.java:176) - Shutting down ZkServer...done
]]></system-out>
  <system-err><![CDATA[]]></system-err>
</testsuite>