[
https://issues.apache.org/jira/browse/KAFKA-2082?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14395847#comment-14395847
]
Evan Huus commented on KAFKA-2082:
----------------------------------
Hmm, the test is configured to retry a message 5 times (including refetching
metadata) and to wait 2 seconds in between retries. The line # of that error
means that a message ran out of retries and was abandoned (the printed message
was just the last error reported against that particular message). I suspect
this is a case of a broker returning bad/stale metadata, so we try again on the
same broker even though leadership has moved.
Logs like "Fetching metadata for [TOPIC(s)] from broker ADDRESS" will tell you
which broker we are asking for metadata. Logs like "producer/leader selected
broker ID on TOPIC/PARTITION" will tell you (after fetching metadata) which
broker the metadata claimed was leader. Logs like "producer/flusher/BROKER
state change to [retrying] on TOPIC/PARTITION because ERROR", indicate that the
produce response contained the given error, so we are retrying some messages.
If we keep asking the same broker for metadata, selecting the same leader, and
then getting the same error back and repeating the cycle, then the broker we
are fetching metadata from is giving us back bad data, and I suppose that's
another bug.
Of course it's possible that we just need to increase the number of retries to
give the cluster more time to heal. I'll try myself with the patch on monday.
> Kafka Replication ends up in a bad state
> ----------------------------------------
>
> Key: KAFKA-2082
> URL: https://issues.apache.org/jira/browse/KAFKA-2082
> Project: Kafka
> Issue Type: Bug
> Components: replication
> Affects Versions: 0.8.2.1
> Reporter: Evan Huus
> Assignee: Sriharsha Chintalapani
> Priority: Critical
> Attachments: KAFKA-2082.patch
>
>
> While running integration tests for Sarama (the go client) we came across a
> pattern of connection losses that reliably puts kafka into a bad state:
> several of the brokers start spinning, chewing ~30% CPU and spamming the logs
> with hundreds of thousands of lines like:
> {noformat}
> [2015-04-01 13:08:40,070] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111094 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,1] failed due to Leader not local for partition
> [many_partition,1] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,070] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111094 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,6] failed due to Leader not local for partition
> [many_partition,6] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,070] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111095 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,21] failed due to Leader not local for partition
> [many_partition,21] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,071] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111095 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,26] failed due to Leader not local for partition
> [many_partition,26] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,071] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111095 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,1] failed due to Leader not local for partition
> [many_partition,1] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,071] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111095 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,6] failed due to Leader not local for partition
> [many_partition,6] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,072] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111096 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,21] failed due to Leader not local for partition
> [many_partition,21] on broker 9093 (kafka.server.ReplicaManager)
> [2015-04-01 13:08:40,072] WARN [Replica Manager on Broker 9093]: Fetch
> request with correlation id 111096 from client ReplicaFetcherThread-0-9093 on
> partition [many_partition,26] failed due to Leader not local for partition
> [many_partition,26] on broker 9093 (kafka.server.ReplicaManager)
> {noformat}
> This can be easily and reliably reproduced using the {{toxiproxy-final}}
> branch of https://github.com/Shopify/sarama which includes a vagrant script
> for provisioning the appropriate cluster:
> - {{git clone https://github.com/Shopify/sarama.git}}
> - {{git checkout test-jira-kafka-2082}}
> - {{vagrant up}}
> - {{TEST_SEED=1427917826425719059 DEBUG=true go test -v}}
> After the test finishes (it fails because the cluster ends up in a bad
> state), you can log into the cluster machine with {{vagrant ssh}} and inspect
> the bad nodes. The vagrant script provisions five zookeepers and five brokers
> in {{/opt/kafka-9091/}} through {{/opt/kafka-9095/}}.
> Additional context: the test produces continually to the cluster while
> randomly cutting and restoring zookeeper connections (all connections to
> zookeeper are run through a simple proxy on the same vm to make this easy).
> The majority of the time this works very well and does a good job exercising
> our producer's retry and failover code. However, under certain patterns of
> connection loss (the {{TEST_SEED}} in the instructions is important), kafka
> gets confused. The test never cuts more than two connections at a time, so
> zookeeper should always have quorum, and the topic (with three replicas)
> should always be writable.
> Completely restarting the cluster via {{vagrant reload}} seems to put it back
> into a sane state.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
