[
https://issues.apache.org/jira/browse/KAFKA-3042?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15237383#comment-15237383
]
Flavio Junqueira commented on KAFKA-3042:
-----------------------------------------
I had a look at the zookeeper logs, and I couldn’t see anything unusual. There
are session expirations, but it is expected that sessions expire.
Using the same topic-partition I used in my last comment,
[tec1.en2.frontend.syncPing,7], I found that the reason seems to be that
controller 5 is telling broker 1 that the partition leader is 4, but neither 5
nor 1 think that broker 4 is up. Here are some relevant log lines from broker 5:
{noformat}
[2016-04-09 00:37:54,079] INFO [BrokerChangeListener on Controller 5]: Broker
change listener fired for path /brokers/ids with children 1,2,3,5
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2016-04-09 00:37:53,709] DEBUG [Partition state machine on Controller 5]:
After leader election, leader cache is updated to Map….
[tec1.en2.frontend.syncPing,7] ->
(Leader:2,ISR:2,LeaderEpoch:361,ControllerEpoch:410)
[2016-04-09 00:37:53,765] INFO [Partition state machine on Controller 5]:
Started partition state machine with initial state -> Map…
[tec1.en2.frontend.syncPing,7] -> OnlinePartition
[2016-04-09 00:40:58,415] DEBUG [Partition state machine on Controller 5]:
After leader election, leader cache is updated to Map…
[tec1.en2.frontend.syncPing,7] ->
(Leader:4,ISR:4,LeaderEpoch:364,ControllerEpoch:415)
[2016-04-09 00:41:35,442] INFO [BrokerChangeListener on Controller 5]: Broker
change listener fired for path /brokers/ids with children 1,4,5
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
{noformat}
Interestingly, broker 3 is the controller for epoch 415, see the last leader
cache update, and this is the information that broker 1 receives from broker 5
(see the previous comment). It looks like broker 5 ignored the fact that broker
4 is down or at least not in its list of live brokers.
Broker 3 seems to behave correctly with respect to the partition, here are some
relevant log lines:
{noformat}
[2016-04-09 00:39:57,004] INFO [Controller 3]: Controller 3 incremented epoch
to 415 (kafka.controller.KafkaController)
[2016-04-09 00:40:46,633] INFO [BrokerChangeListener on Controller 3]: Broker
change listener fired for path /brokers/ids with children 3,4,5
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)
[2016-04-09 00:40:46,638] INFO [BrokerChangeListener on Controller 3]: Newly
added brokers: 4, deleted brokers: , all live brokers: 3,4,5
(kafka.controller.ReplicaStateMachine
[2016-04-09 00:40:50,911] DEBUG [OfflinePartitionLeaderSelector]: No broker in
ISR is alive for [tec1.en2.frontend.syncPing,7]. Pick the leader from the alive
assigned replicas: 4 (kafka.controller.OfflinePartitionLeaderSelector)
[2016-04-09 00:40:50,911] WARN [OfflinePartitionLeaderSelector]: No broker in
ISR is alive for [tec1.en2.frontend.syncPing,7]. Elect leader 4 from live
brokers 4. There's potential data loss.
(kafka.controller.OfflinePartitionLeaderSelector)
[2016-04-09 00:40:50,911] INFO [OfflinePartitionLeaderSelector]: Selected new
leader and ISR {"leader":4,"leader_epoch":364,"isr":[4]} for offline partition
[tec1.en2.frontend.syncPing,7] (kafka.controller.OfflinePartitionLeaderSelector)
State-change log
[2016-04-09 00:40:50,909] TRACE Controller 3 epoch 415 started leader election
for partition [tec1.en2.frontend.syncPing,7] (state.change.logger)
[2016-04-09 00:40:50,911] TRACE Controller 3 epoch 415 elected leader 4 for
Offline partition [tec1.en2.frontend.syncPing,7] (state.change.logger)
[2016-04-09 00:40:50,930] TRACE Controller 3 epoch 415 changed partition
[tec1.en2.frontend.syncPing,7] from OfflinePartition to OnlinePartition with
leader 4 (state.change.logger)
{noformat}
To summarize, the problems seems to be that controller 5 tells broker 1 that
the partition leader is an unavailable broker, and broker 1 fails to change the
partition leader. As it fails to update the leader to broker 4, broker 1
remains the leader, which causes it to keep trying to update the ISR and
printing out the “Cached zkVersion…” messages. Broker 1 does not receive any
controller update that enables it to correct the problem later on and
consequently it is stuck with itself as partition leader incorrectly.
> updateIsr should stop after failed several times due to zkVersion issue
> -----------------------------------------------------------------------
>
> Key: KAFKA-3042
> URL: https://issues.apache.org/jira/browse/KAFKA-3042
> Project: Kafka
> Issue Type: Bug
> Affects Versions: 0.8.2.1
> Environment: jdk 1.7
> centos 6.4
> Reporter: Jiahongchao
> Attachments: controller.log, server.log.2016-03-23-01,
> state-change.log
>
>
> sometimes one broker may repeatly log
> "Cached zkVersion 54 not equal to that in zookeeper, skip updating ISR"
> I think this is because the broker consider itself as the leader in fact it's
> a follower.
> So after several failed tries, it need to find out who is the leader
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
