kafka-jira mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Igor Canadi (JIRA)" <j...@apache.org>
Subject [jira] [Created] (KAFKA-5971) Broker keeps running even though not registered in ZK
Date Mon, 25 Sep 2017 18:28:00 GMT
Igor Canadi created KAFKA-5971:
----------------------------------

             Summary: Broker keeps running even though not registered in ZK
                 Key: KAFKA-5971
                 URL: https://issues.apache.org/jira/browse/KAFKA-5971
             Project: Kafka
          Issue Type: Bug
          Components: core
    Affects Versions: 0.11.0.0
            Reporter: Igor Canadi


We had a curious situation happen to our kafka cluster running version 0.11.0.0. One of the
brokers was happily running, even though its ID was not registered in Zookeeper under `/brokers/ids`.

Based on the logs, it appears that the broker restarted very quickly and there was a node
under `/brokers/ids/2` still present from the previous run. However, in that case I'd expect
the broker to try again or just exit. In reality it continued running without any errors in
the logs.

Here's the relevant part of the logs: 
```
[2017-09-06 23:50:26,095] INFO Opening socket connection to server zookeeper.kafka.svc.cluster.local/100.66.99.54:2181.
Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,096] INFO Socket connection established to zookeeper.kafka.svc.cluster.local/100.66.99.54:2181,
initiating session (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,099] WARN Unable to reconnect to ZooKeeper service, session 0x15e4477405f1d40
has expired (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,099] INFO zookeeper state changed (Expired) (org.I0Itec.zkclient.ZkClient)
[2017-09-06 23:50:26,099] INFO Unable to reconnect to ZooKeeper service, session 0x15e4477405f1d40
has expired, closing socket connection (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,099] INFO Initiating client connection, connectString=zookeeper:2181
sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@2cb4893b (org.apache.zookeeper.ZooKeeper)
[2017-09-06 23:50:26,102] INFO EventThread shut down for session: 0x15e4477405f1d40 (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,107] INFO Opening socket connection to server zookeeper.kafka.svc.cluster.local/100.66.99.54:2181.
Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,108] INFO Socket connection established to zookeeper.kafka.svc.cluster.local/100.66.99.54:2181,
initiating session (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,111] INFO Session establishment complete on server zookeeper.kafka.svc.cluster.local/100.66.99.54:2181,
sessionid = 0x15e599a1a3e0013, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-09-06 23:50:26,112] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-09-06 23:50:26,114] INFO re-registering broker info in ZK for broker 2 (kafka.server.KafkaHealthcheck$SessionExpireListener)
[2017-09-06 23:50:26,115] INFO Creating /brokers/ids/2 (is it secure? false) (kafka.utils.ZKCheckedEphemeral)
[2017-09-06 23:50:26,123] INFO Result of znode creation is: NODEEXISTS (kafka.utils.ZKCheckedEphemeral)
[2017-09-06 23:50:26,124] ERROR Error handling event ZkEvent[New session event sent to kafka.server.KafkaHealthcheck$SessionExpireListener@699f40a0]
(org.I0Itec.zkclient.ZkEventThread)
java.lang.RuntimeException: A broker is already registered on the path /brokers/ids/2. This
probably indicates that you either have configured a brokerid that is already in use, or else
you have shutdown this broker and restarted it faster than the zookeeper timeout so it
    at kafka.utils.ZkUtils.registerBrokerInZk(ZkUtils.scala:417)
    at kafka.utils.ZkUtils.registerBrokerInZk(ZkUtils.scala:403)
    at kafka.server.KafkaHealthcheck.register(KafkaHealthcheck.scala:70)
    at kafka.server.KafkaHealthcheck$SessionExpireListener.handleNewSession(KafkaHealthcheck.scala:104)
    at org.I0Itec.zkclient.ZkClient$6.run(ZkClient.java:736)
    at org.I0Itec.zkclient.ZkEventThread.run(ZkEventThread.java:72)
[2017-09-06 23:51:42,257] INFO [Group Metadata Manager on Broker 2]: Removed 0 expired offsets
in 0 milliseconds. (kafka.coordinator.group.GroupMetadataManager)
[2017-09-07 00:00:06,198] INFO Unable to read additional data from server sessionid 0x15e599a1a3e0013,
likely server has closed socket, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn)
[2017-09-07 00:00:06,354] INFO zookeeper state changed (Disconnected) (org.I0Itec.zkclient.ZkClient)
[2017-09-07 00:00:07,675] INFO Opening socket connection to server zookeeper.kafka.svc.cluster.local/100.66.99.54:2181.
Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn)
[2017-09-07 00:00:07,676] INFO Socket connection established to zookeeper.kafka.svc.cluster.local/100.66.99.54:2181,
initiating session (org.apache.zookeeper.ClientCnxn)
[2017-09-07 00:00:07,680] INFO Session establishment complete on server zookeeper.kafka.svc.cluster.local/100.66.99.54:2181,
sessionid = 0x15e599a1a3e0013, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn)
[2017-09-07 00:00:07,681] INFO zookeeper state changed (SyncConnected) (org.I0Itec.zkclient.ZkClient)
[2017-09-07 00:01:42,257] INFO [Group Metadata Manager on Broker 2]: Removed 0 expired offsets
in 0 milliseconds. (kafka.coordinator.group.GroupMetadataManager)
[2017-09-07 00:11:42,257] INFO [Group Metadata Manager on Broker 2]: Removed 0 expired offsets
in 0 milliseconds. (kafka.coordinator.group.GroupMetadataManager)
[2017-09-07 00:21:42,257] INFO [Group Metadata Manager on Broker 2]: Removed 0 expired offsets
in 0 milliseconds. (kafka.coordinator.group.GroupMetadataManager)
[2017-09-07 00:31:42,257] INFO [Group Metadata Manager on Broker 2]: Removed 0 expired offsets
in 0 milliseconds. (kafka.coordinator.group.GroupMetadataManager)
```

The only message that appears after this point is the "Removed 0 expired offsets", which happens
every 10min.

Let me know if I can provide any more information!



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message