Kafka failed to start using confluent command

Question

I'm facing some difficulties while trying to start ZooKeeper, Kafka and schema registry via :

$confluent start schema-registry

I'm running a cluster of 3 nodes, and for some reason when I run above command, Kafka is unable to start :

#root: /confluent/confluent-5.0.0/bin/confluent start schema-registry
This CLI is intended for development only, not for production
https://docs.confluent.io/current/cli/index.html

Using CONFLUENT_CURRENT: /tmp/confluent.h266AuQQ
Starting zookeeper
zookeeper is [UP]
Starting kafka
/Kafka failed to start
kafka is [DOWN]
Cannot start Schema Registry, Kafka Server is not running. Check your deployment

zookeeper.properties :

root: /confluent/confluent-5.0.0# cat ./etc/kafka/zookeeper.properties 

tickTime=2000
dataDir=/infrastructure/zookeeper/data/
clientPort=2181
initLimit=5
syncLimit=2
server.1=Hostname.DOMAIN.com:2888:3888
server.2=Hostname.DOMAIN.com:2888:3888
server.3=Hostname.DOMAIN.com:2888:3888

Kafka log :

root: /confluent/confluent-5.0.0# ./bin/confluent log kafka

[2018-08-16 14:09:02,830] INFO Socket connection established to localhost/127.0.0.1:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2018-08-16 14:09:02,830] INFO Unable to read additional data from server sessionid 0x0, likely server has closed socket, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
[2018-08-16 14:09:03,422] INFO [ZooKeeperClient] Closing. (kafka.zookeeper.ZooKeeperClient)
[2018-08-16 14:09:04,201] INFO Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2018-08-16 14:09:04,201] INFO Socket connection established to localhost/127.0.0.1:2181, initiating session (org.apache.zookeeper.ClientCnxn)
[2018-08-16 14:09:04,304] INFO Session: 0x0 closed (org.apache.zookeeper.ZooKeeper)
[2018-08-16 14:09:04,306] INFO EventThread shut down for session: 0x0 (org.apache.zookeeper.ClientCnxn)
[2018-08-16 14:09:04,307] INFO [ZooKeeperClient] Closed. (kafka.zookeeper.ZooKeeperClient)
[2018-08-16 14:09:04,310] ERROR Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
kafka.zookeeper.ZooKeeperClientTimeoutException: Timed out waiting for connection while in state: CONNECTING
        at kafka.zookeeper.ZooKeeperClient$$anonfun$kafka$zookeeper$ZooKeeperClient$$waitUntilConnected$1.apply$mcV$sp(ZooKeeperClient.scala:230)
        at kafka.zookeeper.ZooKeeperClient$$anonfun$kafka$zookeeper$ZooKeeperClient$$waitUntilConnected$1.apply(ZooKeeperClient.scala:226)
        at kafka.zookeeper.ZooKeeperClient$$anonfun$kafka$zookeeper$ZooKeeperClient$$waitUntilConnected$1.apply(ZooKeeperClient.scala:226)
        at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:251)
        at kafka.zookeeper.ZooKeeperClient.kafka$zookeeper$ZooKeeperClient$$waitUntilConnected(ZooKeeperClient.scala:226)
        at kafka.zookeeper.ZooKeeperClient.<init>(ZooKeeperClient.scala:95)
        at kafka.zk.KafkaZkClient$.apply(KafkaZkClient.scala:1580)
        at kafka.server.KafkaServer.kafka$server$KafkaServer$$createZkClient$1(KafkaServer.scala:348)
        at kafka.server.KafkaServer.initZkClient(KafkaServer.scala:372)
        at kafka.server.KafkaServer.startup(KafkaServer.scala:202)
        at io.confluent.support.metrics.SupportedServerStartable.startup(SupportedServerStartable.java:117)
        at io.confluent.support.metrics.SupportedKafka.main(SupportedKafka.java:66)
[2018-08-16 14:09:04,312] INFO shutting down (kafka.server.KafkaServer)
[2018-08-16 14:09:04,313] WARN  (kafka.utils.CoreUtils$)
java.lang.NullPointerException
        at kafka.server.KafkaServer$$anonfun$shutdown$5.apply$mcV$sp(KafkaServer.scala:579)
        at kafka.utils.CoreUtils$.swallow(CoreUtils.scala:86)
        at kafka.server.KafkaServer.shutdown(KafkaServer.scala:579)
        at kafka.server.KafkaServer.startup(KafkaServer.scala:329)
        at io.confluent.support.metrics.SupportedServerStartable.startup(SupportedServerStartable.java:117)
        at io.confluent.support.metrics.SupportedKafka.main(SupportedKafka.java:66)
[2018-08-16 14:09:04,315] INFO shut down completed (kafka.server.KafkaServer)
[2018-08-16 14:09:04,316] INFO shutting down (kafka.server.KafkaServer)

Not sure what this line tells me:

ERROR Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
kafka.zookeeper.ZooKeeperClientTimeoutException: Timed out waiting for connection while in state: CONNECTING

Seems like there is also something wrong regarding the Zookeeper as appear in logs:

java.net.ConnectException: Connection refused
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:589)
        at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:558)
        at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:610)
        at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:838)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:957)
[2018-08-16 14:32:26,540] INFO Resolved hostname: HOSTNAME1.DNS.com to address: HOSTNAME1.DNS.com/10.***.***.*** (org.apache.zookeeper.server.quorum.QuorumPeer)
[2018-08-16 14:32:26,540] WARN Cannot open channel to 3 at election address HOSTNAME1.DNS.com/10.***.***.***:3888 (org.apache.zookeeper.server.quorum.QuorumCnxManager)
java.net.ConnectException: Connection refused
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
        at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
        at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
        at java.net.Socket.connect(Socket.java:589)
        at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:558)
        at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectAll(QuorumCnxManager.java:610)
        at org.apache.zookeeper.server.quorum.FastLeaderElection.lookForLeader(FastLeaderElection.java:838)
        at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:957)
[2018-08-16 14:32:26,541] INFO Resolved hostname: HOSTNAME2.DNS.com to address: HOSTNAME2.DNS.com/10.***.***.*** (org.apache.zookeeper.server.quorum.QuorumPeer)
[2018-08-16 14:32:26,541] INFO Notification time out: 60000 (org.apache.zookeeper.server.quorum.FastLeaderElection)

Any idea what is wrong here?

Your help is appreciated.

Answer 1

Well I have a similar problem. When I started confluent got:

Starting zookeeper
zookeeper is [UP]
Starting kafka
Kafka failed to start
kafka is [DOWN]
Cannot start Schema Registry, Kafka Server is not running. Check your deployment

The problem was that I was running before Kafka locally, and the port 9092 was still listening a process. So first I check if the port was listening:

sudo lsof -i :9092 

Out:

COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME java
17150 savi01 97u IPv6 134739 0t0 TCP *:9092 (LISTEN) java
17150 savi01 113u IPv6 134741 0t0 TCP localhost:42368->savi01:9092 (CLOSE_WAIT)

Then I kill the process:

sudo kill -9 17150

Now I run confluent again and everything is working. Hope that helps for future consultant

Answer 2

you have a problem starting zookeper.

Below lines are not required in zookeeper properties because kafka property file contain zokkeeper address which connect all nodes.

server.1 Hostname.DOMAIN.com:2888:3888