[ 
https://issues.apache.org/jira/browse/KAFKA-3102?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15098512#comment-15098512
 ] 

Mohit Anchlia edited comment on KAFKA-3102 at 1/15/16 12:38 AM:
----------------------------------------------------------------

I enabled debug and still not much info:

[2016-01-14 19:36:40,052] ERROR An error: 
(java.security.PrivilegedActionException: javax.security.sasl.SaslException: 
GSS initiate failed [Caused by GSSException: No valid credentials provided 
(Mechanism level: Server not found in Kerberos database (7) - UNKNOWN_SERVER)]) 
occurred when evaluating Zookeeper Quorum Member's  received SASL token. This 
may be caused by Java's being unable to resolve the Zookeeper Quorum Member's 
hostname correctly. You may want to try to adding 
'-Dsun.net.spi.nameservice.provider.1=dns,sun' to your client's JVMFLAGS 
environment. Zookeeper Client will go to AUTH_FAILED state. 
(org.apache.zookeeper.client.ZooKeeperSaslClient)
[2016-01-14 19:36:40,052] ERROR SASL authentication with Zookeeper Quorum 
member failed: javax.security.sasl.SaslException: An error: 
(java.security.PrivilegedActionException: javax.security.sasl.SaslException: 
GSS initiate failed [Caused by GSSException: No valid credentials provided 
(Mechanism level: Server not found in Kerberos database (7) - UNKNOWN_SERVER)]) 
occurred when evaluating Zookeeper Quorum Member's  received SASL token. This 
may be caused by Java's being unable to resolve the Zookeeper Quorum Member's 
hostname correctly. You may want to try to adding 
'-Dsun.net.spi.nameservice.provider.1=dns,sun' to your client's JVMFLAGS 
environment. Zookeeper Client will go to AUTH_FAILED state. 
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 19:36:40,052] DEBUG Received event: WatchedEvent state:AuthFailed 
type:None path:null (org.I0Itec.zkclient.ZkClient)
[2016-01-14 19:36:40,052] INFO zookeeper state changed (AuthFailed) 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 19:36:40,052] DEBUG Leaving process event 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 19:36:44,057] WARN caught end of stream exception 
(org.apache.zookeeper.server.NIOServerCnxn)
EndOfStreamException: Unable to read additional data from client sessionid 
0x15242b64cf80000, 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-01-14 12:52:47,541] DEBUG sessionid:0x1524142e5c20000 type:closeSession 
cxid:0x1 zxid:0x2 txntype:-11 reqpath:n/a 
(org.apache.zookeeper.server.FinalRequestProcessor)
[2016-01-14 12:52:47,543] INFO Closed socket connection for client 
/0:0:0:0:0:0:0:1:52904 which had sessionid 0x1524142e5c20000 
(org.apache.zookeeper.server.NIOServerCnxn)
[2016-01-14 12:52:47,543] DEBUG Reading reply sessionid:0x1524142e5c20000, 
packet:: clientPath:null serverPath:null finished:false header:: 1,-11  
replyHeader:: 1,2,0  request:: null response:: null 
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,543] DEBUG Disconnecting client for session: 
0x1524142e5c20000 (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,544] INFO Session: 0x1524142e5c20000 closed 
(org.apache.zookeeper.ZooKeeper)
[2016-01-14 12:52:47,544] DEBUG Closing ZkClient...done 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG ignoring event '{None | null}' since shutdown 
triggered (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG Leaving process event 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG Received event: WatchedEvent 
state:SyncConnected type:None path:null (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG ignoring event '{None | null}' since shutdown 
triggered (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG Leaving process event 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] INFO EventThread shut down 
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,545] FATAL Fatal error during KafkaServer startup. Prepare 
to shutdown (kafka.server.KafkaServer)
org.I0Itec.zkclient.exception.ZkTimeoutException: Unable to connect to 
zookeeper server within timeout: 6000
        at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1223)



was (Author: mohitanchlia):
I enabled debug and still not much info:

[2016-01-14 18:57:25,346] DEBUG JAAS loginContext is: Client 
(org.apache.zookeeper.client.ZooKeeperSaslClient)
[2016-01-14 18:57:25,445] WARN SASL configuration failed: 
javax.security.auth.login.LoginException: Checksum failed Will continue 
connection to Zookeeper server without SASL authentication, if Zookeeper server 
allows it. (org.apache.zookeeper.ClientCnxn)
[2016-01-14 18:57:25,447] INFO Opening socket connection to server 
localhost/127.0.0.1:2181 (org.apache.zookeeper.ClientCnxn)
[2016-01-14 18:57:25,447] DEBUG Received event: WatchedEvent state:AuthFailed 
type:None path:null (org.I0Itec.zkclient.ZkClient)
[2016-01-14 18:57:25,447] INFO zookeeper state changed (AuthFailed) 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 18:57:25,447] DEBUG Leaving process event 
(org.I0Itec.zkclient.ZkClient)

[2016-01-14 12:52:47,541] DEBUG sessionid:0x1524142e5c20000 type:closeSession 
cxid:0x1 zxid:0x2 txntype:-11 reqpath:n/a 
(org.apache.zookeeper.server.FinalRequestProcessor)
[2016-01-14 12:52:47,543] INFO Closed socket connection for client 
/0:0:0:0:0:0:0:1:52904 which had sessionid 0x1524142e5c20000 
(org.apache.zookeeper.server.NIOServerCnxn)
[2016-01-14 12:52:47,543] DEBUG Reading reply sessionid:0x1524142e5c20000, 
packet:: clientPath:null serverPath:null finished:false header:: 1,-11  
replyHeader:: 1,2,0  request:: null response:: null 
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,543] DEBUG Disconnecting client for session: 
0x1524142e5c20000 (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,544] INFO Session: 0x1524142e5c20000 closed 
(org.apache.zookeeper.ZooKeeper)
[2016-01-14 12:52:47,544] DEBUG Closing ZkClient...done 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG ignoring event '{None | null}' since shutdown 
triggered (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG Leaving process event 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG Received event: WatchedEvent 
state:SyncConnected type:None path:null (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG ignoring event '{None | null}' since shutdown 
triggered (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] DEBUG Leaving process event 
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,544] INFO EventThread shut down 
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,545] FATAL Fatal error during KafkaServer startup. Prepare 
to shutdown (kafka.server.KafkaServer)
org.I0Itec.zkclient.exception.ZkTimeoutException: Unable to connect to 
zookeeper server within timeout: 6000
        at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1223)


> Kafka server unable to connect to zookeeper
> -------------------------------------------
>
>                 Key: KAFKA-3102
>                 URL: https://issues.apache.org/jira/browse/KAFKA-3102
>             Project: Kafka
>          Issue Type: Bug
>          Components: security
>         Environment: RHEL 6
>            Reporter: Mohit Anchlia
>
> Server disconnects from the zookeeper with the following log, and logs are 
> not indicative of any problem. It works without the security setup however. 
> I followed the security configuration steps from this site: 
> http://docs.confluent.io/2.0.0/kafka/sasl.html
> In here find the list of principals, logs and Jaas file:
> 1) Jaas file 
> KafkaServer {
>     com.sun.security.auth.module.Krb5LoginModule required
>     useKeyTab=true
>     storeKey=true
>     keyTab="/mnt/kafka/kafka/kafka.keytab"
>     principal="kafka/10.24.251....@example.com";
> };
> Client {
>     com.sun.security.auth.module.Krb5LoginModule required
>     useKeyTab=true
>     storeKey=true
>     keyTab="/mnt/kafka/kafka/kafka.keytab"
>     principal="kafka/10.24.251....@example.com";
> };
> 2) Principles from krb admin
> kadmin.local:  list_principals
> K/m...@example.com
> kadmin/ad...@example.com
> kadmin/chang...@example.com
> kadmin/ip-10-24-251-175.us-west-2.compute.inter...@example.com
> kafka/10.24.251....@example.com
> krbtgt/example....@example.com
> [2016-01-13 16:26:00,551] INFO starting (kafka.server.KafkaServer)
> [2016-01-13 16:26:00,557] INFO Connecting to zookeeper on localhost:2181 
> (kafka.server.KafkaServer)
> [2016-01-13 16:27:30,718] FATAL Fatal error during KafkaServer startup. 
> Prepare to shutdown (kafka.server.KafkaServer)
> org.I0Itec.zkclient.exception.ZkTimeoutException: Unable to connect to 
> zookeeper server within timeout: 6000
>         at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1223)
>         at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:155)
>         at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:129)
>         at kafka.utils.ZkUtils$.createZkClientAndConnection(ZkUtils.scala:89)
>         at kafka.utils.ZkUtils$.apply(ZkUtils.scala:71)
>         at kafka.server.KafkaServer.initZk(KafkaServer.scala:278)
>         at kafka.server.KafkaServer.startup(KafkaServer.scala:168)
>         at 
> kafka.server.KafkaServerStartable.startup(KafkaServerStartable.scala:37)
>         at kafka.Kafka$.main(Kafka.scala:67)
>         at kafka.Kafka.main(Kafka.scala)
> [2016-01-13 16:27:30,721] INFO shutting down (kafka.server.KafkaServer)
> [2016-01-13 16:27:30,727] INFO shut down completed (kafka.server.KafkaServer)
> [2016-01-13 16:27:30,728] FATAL Fatal error during KafkaServerStartable 
> startup. Prepare to shutdown (kafka.server.KafkaServerStartable)
> org.I0Itec.zkclient.exception.ZkTimeoutException: Unable to connect to 
> zookeeper server within timeout: 6000
>         at org.I0Itec.zkclient.ZkClient.connect(ZkClient.java:1223)
>         at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:155)
>         at org.I0Itec.zkclient.ZkClient.<init>(ZkClient.java:129)
>         at kafka.utils.ZkUtils$.createZkClientAndConnection(ZkUtils.scala:89)
>         at kafka.utils.ZkUtils$.apply(ZkUtils.scala:71)
>         at kafka.server.KafkaServer.initZk(KafkaServer.scala:278)
>         at kafka.server.KafkaServer.startup(KafkaServer.scala:168)
>         at 
> kafka.server.KafkaServerStartable.startup(KafkaServerStartable.scala:37)
>         at kafka.Kafka$.main(Kafka.scala:67)
>         at kafka.Kafka.main(Kafka.scala)
> [2016-01-13 16:27:30,729] INFO shutting down (kafka.server.KafkaServer)
> "server.log" 156L, 6404C                                                      
>      



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

Reply via email to