kafka适配kerberos后启动失败

1、参照配置文档https://www.orchome.com/270

2、zk报错

2017-01-10 11:20:02,853 [myid:1] - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@349] - caught end of stream exception
EndOfStreamException: Unable to read additional data from client sessionid 0x359865739000004, likely client has closed socket
at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
at java.lang.Thread.run(Thread.java:745)
2017-01-10 11:20:02,856 [myid:1] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1001] - Closed socket connection for client /192.168.20.99:39791 which had sessionid 0x359865739000004

3、kafka报错

[2017-01-10 11:19:47,313] INFO Client environment:java.vendor=Oracle Corporation (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:47,313] INFO Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:47,313] INFO Client environment:java.io.tmpdir=/tmp (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:47,313] INFO Client environment:os.arch=amd64 (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:47,313] INFO Client environment:os.version=3.10.0-327.el7.x86_64 (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:47,313] INFO Client environment:user.name=root (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:47,495] INFO TGT refresh thread started. (org.apache.zookeeper.Login)
[2017-01-10 11:19:47,497] INFO Client will use GSSAPI as SASL mechanism. (org.apache.zookeeper.client.ZooKeeperSaslClient)
[2017-01-10 11:19:47,504] INFO TGT valid starting at: Tue Jan 10 11:19:50 CST 2017 (org.apache.zookeeper.Login)
[2017-01-10 11:19:47,504] INFO TGT expires: Wed Jan 11 12:19:50 CST 2017 (org.apache.zookeeper.Login)
[2017-01-10 11:19:47,504] INFO TGT refresh sleeping until: Wed Jan 11 07:55:09 CST 2017 (org.apache.zookeeper.Login)
[2017-01-10 11:19:47,505] INFO Socket connection established to ws-node02.shunyi06.test/192.168.20.98:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:47,524] INFO Session establishment complete on server ws-node02.shunyi06.test/192.168.20.98:2181, sessionid = 0x25986574ba10001, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:47,525] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:47,649] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,311] INFO Client will use GSSAPI as SASL mechanism. (org.apache.zookeeper.client.ZooKeeperSaslClient)
[2017-01-10 11:19:48,313] INFO Socket connection established to ws-node01.shunyi06.test/192.168.20.99:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,341] INFO Session establishment complete on server ws-node01.shunyi06.test/192.168.20.99:2181, sessionid = 0x25986574ba10001, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,341] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,374] INFO zookeeper state changed (SaslAuthenticated) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,386] INFO Created zookeeper path /kafka (kafka.server.KafkaServer)
[2017-01-10 11:19:48,386] INFO Terminate ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
[2017-01-10 11:19:48,405] INFO Session: 0x25986574ba10001 closed (org.apache.zookeeper.ZooKeeper)
[2017-01-10 11:19:48,405] INFO JAAS File name: /opt/kafka/kafka/config/kafka_server_jaas.conf (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,406] INFO Starting ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
[2017-01-10 11:19:48,406] INFO Waiting for keeper state SaslAuthenticated (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,407] INFO EventThread shut down for session: 0x25986574ba10001 (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,407] INFO Client will use GSSAPI as SASL mechanism. (org.apache.zookeeper.client.ZooKeeperSaslClient)
[2017-01-10 11:19:48,409] INFO Socket connection established to ws-node03.shunyi06.test/192.168.20.97:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,423] INFO Session establishment complete on server ws-node03.shunyi06.test/192.168.20.97:2181, sessionid = 0x359865739000004, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,423] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,531] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,748] INFO Client will use GSSAPI as SASL mechanism. (org.apache.zookeeper.client.ZooKeeperSaslClient)
[2017-01-10 11:19:48,750] INFO Socket connection established to ws-node01.shunyi06.test/192.168.20.99:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,754] INFO Session establishment complete on server ws-node01.shunyi06.test/192.168.20.99:2181, sessionid = 0x359865739000004, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-01-10 11:19:48,754] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,764] INFO zookeeper state changed (SaslAuthenticated) (org.I0Itec.zkclient.ZkClient)
[2017-01-10 11:19:48,895] INFO Cluster ID = bn35oV0mQKSNwTP3Rb9gww (kafka.server.KafkaServer)
[2017-01-10 11:19:48,922] INFO Loading logs. (kafka.log.LogManager)
[2017-01-10 11:19:48,927] INFO Logs loading complete in 4 ms. (kafka.log.LogManager)
[2017-01-10 11:19:48,965] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager)
[2017-01-10 11:19:48,966] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager)
[2017-01-10 11:19:48,991] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2017-01-10 11:19:48,999] INFO Awaiting socket connections on ws-node01:9092. (kafka.network.Acceptor)
[2017-01-10 11:19:49,173] INFO Creating /brokers/ids/0 (is it secure? false) (kafka.utils.ZKCheckedEphemeral)
[2017-01-10 11:19:49,189] INFO Result of znode creation is: OK (kafka.utils.ZKCheckedEphemeral)
[2017-01-10 11:19:49,190] INFO Registered broker 0 at path /brokers/ids/0 with addresses: SASL_PLAINTEXT -> EndPoint(ws-node01,9092,SASL_PLAINTEXT) (kafka.utils.ZkUtils)
[2017-01-10 11:19:49,198] INFO Kafka version : 0.10.1.0 (org.apache.kafka.common.utils.AppInfoParser)
[2017-01-10 11:19:49,198] INFO Kafka commitId : 3402a74efb23d1d4 (org.apache.kafka.common.utils.AppInfoParser)
[2017-01-10 11:19:49,199] INFO [Kafka Server 0], started (kafka.server.KafkaServer)
[2017-01-10 11:19:49,253] WARN Unexpected error from ws-node01/192.168.20.99; closing connection (org.apache.kafka.common.network.Selector)
java.lang.NullPointerException
at org.apache.kafka.common.security.authenticator.SaslClientAuthenticator.sendSaslToken(SaslClientAuthenticator.java:209)
at org.apache.kafka.common.security.authenticator.SaslClientAuthenticator.authenticate(SaslClientAuthenticator.java:178)
at org.apache.kafka.common.network.KafkaChannel.prepare(KafkaChannel.java:64)
at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:338)
at org.apache.kafka.common.network.Selector.poll(Selector.java:291)
at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:260)
at kafka.utils.NetworkClientBlockingOps$.awaitReady$1(NetworkClientBlockingOps.scala:86)
at kafka.utils.NetworkClientBlockingOps$.blockingReady$extension(NetworkClientBlockingOps.scala:93)
at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:230)
at kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:182)
at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:181)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)

4、kerberos日志

1月 10 11:19:50 ws-node04.shunyi06.test krb5kdc20844: AS_REQ (4 etypes {18 17 16 23}) 192.168.20.99: ISSUE: authtime 1484018390, etypes {rep=18 tkt=18 ses=18}, kafka/ws-node01.shunyi06.test@SY.COM for krbtgt/SY.COM@SY.COM
1月 10 11:19:51 ws-node04.shunyi06.test krb5kdc20844: TGS_REQ (4 etypes {18 17 16 23}) 192.168.20.99: ISSUE: authtime 1484018390, etypes {rep=18 tkt=18 ses=18}, kafka/ws-node01.shunyi06.test@SY.COM for zookeeper/ws-node02.shunyi06.test@SY.COM
1月 10 11:19:51 ws-node04.shunyi06.test krb5kdc20844: TGS_REQ (4 etypes {18 17 16 23}) 192.168.20.99: ISSUE: authtime 1484018390, etypes {rep=18 tkt=18 ses=18}, kafka/ws-node01.shunyi06.test@SY.COM for zookeeper/ws-node01.shunyi06.test@SY.COM
1月 10 11:19:52 ws-node04.shunyi06.test krb5kdc20844: TGS_REQ (4 etypes {18 17 16 23}) 192.168.20.99: ISSUE: authtime 1484018390, etypes {rep=18 tkt=18 ses=18}, kafka/ws-node01.shunyi06.test@SY.COM for zookeeper/ws-node03.shunyi06.test@SY.COM
1月 10 11:19:52 ws-node04.shunyi06.test krb5kdc20844: AS_REQ (4 etypes {18 17 16 23}) 192.168.20.99: ISSUE: authtime 1484018392, etypes {rep=18 tkt=18 ses=18}, kafka/ws-node01.shunyi06.test@SY.COM for krbtgt/SY.COM@SY.COM

5、server.properties与kerberos相关

zookeeper.connect=ws-node01:2181,ws-node02:2181,ws-node03:2181/kafka
listeners=SASL_PLAINTEXT://ws-node01:9092
security.inter.broker.protocol=SASL_PLAINTEXT
sasl.mechanism.inter.broker.protocol=Kerberos
sasl.enabled.mechanisms=Kerberos

6、kafka_server_jaas.conf

KafkaServer {
     com.sun.security.auth.module.Krb5LoginModule required
     useKeyTab=true
     storeKey=true
     keyTab="/opt/kafka/kafka/config/kafka.keytab"
     principal="kafka/ws-node01.shunyi06.test@SY.COM";
};

Client {
    com.sun.security.auth.module.Krb5LoginModule required
    useKeyTab=true
    storeKey=true
    keyTab="/opt/kafka/kafka/config/kafka.keytab"
    principal="kafka/ws-node01.shunyi06.test@SY.COM";
};

7、principal

kafka-client/ws-node01.shunyi06.test@SY.COM
kafka-client/ws-node02.shunyi06.test@SY.COM
kafka-client/ws-node03.shunyi06.test@SY.COM
kafka/ws-node01.shunyi06.test@SY.COM
kafka/ws-node02.shunyi06.test@SY.COM
kafka/ws-node03.shunyi06.test@SY.COM
zkcli/ws-node01.shunyi06.test@SY.COM
zkcli/ws-node02.shunyi06.test@SY.COM
zkcli/ws-node03.shunyi06.test@SY.COM
zookeeper/ws-node01.shunyi06.test@SY.COM
zookeeper/ws-node02.shunyi06.test@SY.COM
zookeeper/ws-node03.shunyi06.test@SY.COM

8、其他配置

1、JCE替换了
2、java版本1.8
3、kafka-run-class.sh

if [ -z "$KAFKA_JVM_PERFORMANCE_OPTS" ]; then
  KAFKA_JVM_PERFORMANCE_OPTS="-server -XX:+UseG1GC -XX:MaxGCPauseMillis=20 -XX:InitiatingHeapOccupancyPercent=35 -XX:+DisableExplicitGC -Djava.awt.headless=true -Djava.security.auth.login.config=/opt/kafka/kafka/config/kafka_server_jaas.conf"
fi

9、问题

1、找不到问题出在哪里了。。
2、kafka_server_jaas.conf配置中KafkaServer和Client一模一样，那为什么还要配置两遍呢？