SASL error when tring to connect kafka to kerberos server

[HE Ye <Ye...@alcatel-lucent.com>]

Hello expert,

I need help with the following error. I was tring to connect kafka to kerveros server to verify SASL. I see this error when ZkClient tries to authenticate with the zookeeper server. In the Kerberos logs I see tickets being exchanged. I followed everything in documentation. Couldn't figure out why it failed.

zookeeper log:

[2016-11-03 09:01:01,149] INFO Accepted socket connection from /127.0.0.1:55176 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2016-11-03 09:01:01,154] INFO Client attempting to establish new session at /127.0.0.1:55176 (org.apache.zookeeper.server.ZooKeeperServer)
[2016-11-03 09:01:01,159] INFO Established session 0x1582a4ef33d0005 with negotiated timeout 6000 for client /127.0.0.1:55176 (org.apache.zookeeper.server.ZooKeeperServer)
[2016-11-03 09:01:01,182] ERROR cnxn.saslServer is null: cnxn object did not initialize its saslServer properly. (org.apache.zookeeper.server.ZooKeeperServer)
[2016-11-03 09:01:01,550] WARN caught end of stream exception (org.apache.zookeeper.server.NIOServerCnxn)
EndOfStreamException: Unable to read additional data from client sessionid 0x1582a4ef33d0005, likely client has closed socket
        at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
        at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
        at java.lang.Thread.run(Thread.java:745)
[2016-11-03 09:01:01,551] INFO Closed socket connection for client /127.0.0.1:55176 which had sessionid 0x1582a4ef33d0005 (org.apache.zookeeper.server.NIOServerCnxn)
[2016-11-03 09:01:09,004] INFO Expiring session 0x1582a4ef33d0005, timeout of 6000ms exceeded (org.apache.zookeeper.server.ZooKeeperServer)
[2016-11-03 09:01:09,006] INFO Processed session termination for sessionid: 0x1582a4ef33d0005 (org.apache.zookeeper.server.PrepRequestProcessor)

kafka log:
[2016-11-03 09:01:01,118] INFO TGT valid starting at:        Thu Nov 03 09:00:54 CDT 2016 (org.apache.zookeeper.Login)
[2016-11-03 09:01:01,119] INFO TGT expires:                  Fri Nov 04 09:00:54 CDT 2016 (org.apache.zookeeper.Login)
[2016-11-03 09:01:01,119] INFO TGT refresh sleeping until: Fri Nov 04 04:53:02 CDT 2016 (org.apache.zookeeper.Login)
[2016-11-03 09:01:01,151] INFO Socket connection established to localhost.localdomain/127.0.0.1:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2016-11-03 09:01:01,161] INFO Session establishment complete on server localhost.localdomain/127.0.0.1:2181, sessionid = 0x1582a4ef33d0005, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2016-11-03 09:01:01,163] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2016-11-03 09:01:01,182] ERROR SASL authentication failed using login context 'Client'. (org.apache.zookeeper.client.ZooKeeperSaslClient)
[2016-11-03 09:01:01,183] INFO zookeeper state changed (AuthFailed) (org.I0Itec.zkclient.ZkClient)
[2016-11-03 09:01:01,183] INFO Terminate ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
[2016-11-03 09:01:01,184] FATAL Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
org.I0Itec.zkclient.exception.ZkAuthFailedException: Authentication failure
        at org.I0Itec.zkclient.ZkClient.waitForKeeperState(ZkClient.java:946)
        at org.I0Itec.zkclient.ZkClient.waitUntilConnected(ZkClient.java:923)
        at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1230)
        at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:156)
        at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:130)
        at kafka.utils.ZkUtils$.createZkClientAndConnection(ZkUtils.scala:75)
        at kafka.utils.ZkUtils$.apply(ZkUtils.scala:57)
        at kafka.server.KafkaServer.initZk(KafkaServer.scala:294)
        at kafka.server.KafkaServer.startup(KafkaServer.scala:180)
        at kafka.server.KafkaServerStartable.startup(KafkaServerStartable.scala:37)
        at kafka.Kafka$.main(Kafka.scala:67)
        at kafka.Kafka.main(Kafka.scala)
[2016-11-03 09:01:01,193] INFO shutting down (kafka.server.KafkaServer)
[2016-11-03 09:01:01,199] INFO shut down completed (kafka.server.KafkaServer)

Kerberos logs

Nov 03 09:00:54 YeTarget51-0-0-1 krb5kdc[1178](info): AS_REQ (4 etypes {18 17 16 23}) 10.160.32.151: ISSUE: authtime 1478181654, etypes {rep=18 tkt=18 ses=18}, kafka/kafka1@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM
Nov 03 09:00:54 YeTarget51-0-0-1 krb5kdc[1178](info): TGS_REQ (4 etypes {18 17 16 23}) 10.160.32.151: ISSUE: authtime 1478181654, etypes {rep=18 tkt=18 ses=18}, kafka/kafka1@EXAMPLE.COM for zookeeper/localhost.localdomain@EXAMPLE.COM<ma...@EXAMPLE.COM>


Thanks,
Ye