kafka-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mohit Anchlia (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (KAFKA-3102) Kafka server unable to connect to zookeeper
Date Fri, 15 Jan 2016 00:01:39 GMT

    [ 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:00 AM:
----------------------------------------------------------------

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)



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

[2016-01-14 12:51:17,404] DEBUG zookeeper.disableAutoWatchReset is false (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:51:17,418] DEBUG Awaiting connection to Zookeeper server (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:51:17,418] INFO Waiting for keeper state SaslAuthenticated (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:51:17,420] DEBUG JAAS loginContext is: Client (org.apache.zookeeper.client.ZooKeeperSaslClient)
[2016-01-14 12:51:23,419] DEBUG Closing ZkClient... (org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:51:23,419] INFO Terminate ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
[2016-01-14 12:51:23,419] DEBUG Closing ZooKeeper connected to localhost:2181 (org.I0Itec.zkclient.ZkConnection)
[2016-01-14 12:51:23,419] DEBUG Closing session: 0x0 (org.apache.zookeeper.ZooKeeper)
[2016-01-14 12:51:23,419] DEBUG Closing client for session: 0x0 (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,501] WARN SASL configuration failed: javax.security.auth.login.LoginException:
Receive timed out Will continue connection to Zookeeper server without SASL authentication,
if Zookeeper server allows it. (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,503] INFO Opening socket connection to server localhost/0:0:0:0:0:0:0:1:2181
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,503] DEBUG Received event: WatchedEvent state:AuthFailed type:None path:null
(org.I0Itec.zkclient.ZkClient)
[2016-01-14 12:52:47,509] INFO Accepted socket connection from /0:0:0:0:0:0:0:1:52904 (org.apache.zookeeper.server.NIOServerCnxnFactory)
[2016-01-14 12:52:47,514] INFO Socket connection established to localhost/0:0:0:0:0:0:0:1:2181,
initiating session (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,515] DEBUG Session establishment request sent on localhost/0:0:0:0:0:0:0:1:2181
(org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,519] DEBUG Session establishment request from client /0:0:0:0:0:0:0:1:52904
client's lastZxid is 0x0 (org.apache.zookeeper.server.ZooKeeperServer)
[2016-01-14 12:52:47,521] INFO Client attempting to establish new session at /0:0:0:0:0:0:0:1:52904
(org.apache.zookeeper.server.ZooKeeperServer)
[2016-01-14 12:52:47,524] INFO Creating new log file: log.1 (org.apache.zookeeper.server.persistence.FileTxnLog)
[2016-01-14 12:52:47,528] DEBUG Processing request:: sessionid:0x1524142e5c20000 type:createSession
cxid:0x0 zxid:0x1 txntype:-10 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor)
[2016-01-14 12:52:47,533] DEBUG sessionid:0x1524142e5c20000 type:createSession cxid:0x0 zxid:0x1
txntype:-10 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor)
[2016-01-14 12:52:47,537] INFO Established session 0x1524142e5c20000 with negotiated timeout
6000 for client /0:0:0:0:0:0:0:1:52904 (org.apache.zookeeper.server.ZooKeeperServer)
[2016-01-14 12:52:47,539] INFO Session establishment complete on server localhost/0:0:0:0:0:0:0:1:2181,
sessionid = 0x1524142e5c20000, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2016-01-14 12:52:47,541] INFO Processed session termination for sessionid: 0x1524142e5c20000
(org.apache.zookeeper.server.PrepRequestProcessor)
[2016-01-14 12:52:47,541] DEBUG Processing request:: sessionid:0x1524142e5c20000 type:closeSession
cxid:0x1 zxid:0x2 txntype:-11 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor)
[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,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.175@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.175@EXAMPLE.COM";
> };
> 2) Principles from krb admin
> kadmin.local:  list_principals
> K/M@EXAMPLE.COM
> kadmin/admin@EXAMPLE.COM
> kadmin/changepw@EXAMPLE.COM
> kadmin/ip-10-24-251-175.us-west-2.compute.internal@EXAMPLE.COM
> kafka/10.24.251.175@EXAMPLE.COM
> krbtgt/EXAMPLE.COM@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)

Mime
View raw message