Does broker 100 keeps acting as the controller afterwards? What you observe
is possible and should be transient since "unsubscribeChildChanges" on
ZkClient and listener fired procedure are executed on different threads and
they are not strictly synchronized. But if you continuously see broker
100's listener fires and it acts like a controller then there may be an
issue with 0.9.0.1 version.
Guozhang
On Wed, Nov 23, 2016 at 7:28 AM, Json Tu <kafka...@126.com> wrote:
> Hi,
> We have a cluster of kafka 0.9.0.1 with 3 nodes, and we found a
> strange controller log as below.
>
> [2016-11-07 03:14:48,575] INFO [SessionExpirationListener on 100], ZK
> expired; shut down all controller components and try to re-elect
> (kafka.controller.KafkaController$SessionExpirationListener)
> [2016-11-07 03:14:48,578] DEBUG [Controller 100]: Controller resigning,
> broker id 100 (kafka.controller.KafkaController)
> [2016-11-07 03:14:48,579] DEBUG [Controller 100]: De-registering
> IsrChangeNotificationListener (kafka.controller.KafkaController)
> [2016-11-07 03:14:48,579] INFO [delete-topics-thread-100], Shutting down
> (kafka.controller.TopicDeletionManager$DeleteTopicsThread)
> [2016-11-07 03:14:48,579] INFO [delete-topics-thread-100], Stopped
> (kafka.controller.TopicDeletionManager$DeleteTopicsThread)
> [2016-11-07 03:14:48,579] INFO [delete-topics-thread-100], Shutdown
> completed (kafka.controller.TopicDeletionManager$DeleteTopicsThread)
> [2016-11-07 03:14:48,580] INFO [Partition state machine on Controller
> 100]: Stopped partition state machine (kafka.controller.
> PartitionStateMachine)
> [2016-11-07 03:14:48,580] INFO [Replica state machine on controller 100]:
> Stopped replica state machine (kafka.controller.ReplicaStateMachine)
> [2016-11-07 03:14:48,583] INFO [Controller-100-to-broker-101-send-thread],
> Shutting down (kafka.controller.RequestSendThread)
> [2016-11-07 03:14:48,584] INFO [Controller-100-to-broker-101-send-thread],
> Stopped (kafka.controller.RequestSendThread)
> [2016-11-07 03:14:48,584] INFO [Controller-100-to-broker-101-send-thread],
> Shutdown completed (kafka.controller.RequestSendThread)
> [2016-11-07 03:14:48,586] INFO [Controller-100-to-broker-100-send-thread],
> Shutting down (kafka.controller.RequestSendThread)
> [2016-11-07 03:14:48,587] INFO [Controller-100-to-broker-100-send-thread],
> Stopped (kafka.controller.RequestSendThread)
> [2016-11-07 03:14:48,587] INFO [Controller-100-to-broker-100-send-thread],
> Shutdown completed (kafka.controller.RequestSendThread)
> [2016-11-07 03:14:48,587] INFO [Controller 100]: Broker 100 resigned as
> the controller (kafka.controller.KafkaController)
> [2016-11-07 03:14:48,652] DEBUG [IsrChangeNotificationListener] Fired!!!
> (kafka.controller.IsrChangeNotificationListener)
> [2016-11-07 03:14:48,668] INFO [BrokerChangeListener on Controller 100]:
> Broker change listener fired for path /brokers/ids with children 101,100
> (kafka.controller.ReplicaStateMachine$BrokerChangeListener)
> [2016-11-07 03:14:48,683] DEBUG [DeleteTopicsListener on 100]: Delete
> topics listener fired for topics to be deleted (kafka.controller.
> PartitionStateMachine$DeleteTopicsListener)
> [2016-11-07 03:14:48,687] INFO [AddPartitionsListener on 100]: Add
> Partition triggered {"version":1,"partitions":{"4"
> :[102,101],"5":[100,102],"1":[102,100],"0":[101,102],"2":[100,101],"3":[101,100]}}
> for path /brokers/topics/movie.gateway.merselllog.syncCinema
> (kafka.controller.PartitionStateMachine$AddPartitionsListener)
> [2016-11-07 03:14:48,694] INFO [AddPartitionsListener on 100]: Add
> Partition triggered {"version":1,"partitions":{"4"
> :[102,101],"5":[100,102],"1":[102,100],"0":[101,102],"2":[100,101],"3":[101,100]}}
> for path /brokers/topics/push_3rdparty_high (kafka.controller.
> PartitionStateMachine$AddPartitionsListener)
> [2016-11-07 03:14:48,707] INFO [AddPartitionsListener on 100]: Add
> Partition triggered {"version":1,"partitions":{"4"
> :[101,102],"5":[102,100],"1":[101,100],"0":[100,102],"2":[102,101],"3":[100,101]}}
> for path /brokers/topics/icb_msg_push_high_02 (kafka.controller.
> PartitionStateMachine$AddPartitionsListener)
> [2016-11-07 03:14:48,715] INFO [AddPartitionsListener on 100]: Add
> Partition triggered {"version":1,"partitions":{"4"
> :[102,100],"5":[100,101],"1":[102,101],"0":[101,100],"2":[100,102],"3":[101,102]}}
> for path /brokers/topics/movie.gateway.merselllog.unlockSeat
> (kafka.controller.PartitionStateMachine$AddPartitionsListener)
>
>
> From the log we can see that old controller 100 resigned as the
> controller successfully，but what confused me is that it can also receive
> Fired!!! from IsrChangeNotificationListener which have beed de-register
> before,
> and we can see broker 100 not elect as new controller next time. but we
> can see
> IsrChangeNotificationListener、DeleteTopicsListener、AddPartitionsListener
> all fired after ressign，does it seems something run with zookeeper.
> Any suggestion is appreciated, thanks in advance.
>
>
>
>
--
-- Guozhang
