Re: Trying to debug a kafka failure

[Rajiv Kurian <ra...@signalfuse.com>]

Given that the kafka-bytes-out metric fell to zero I am guessing that the
broker was not able to replicate the partitions it was the leader for some
reason and hence the data loss. What I can't figure out is why the Producer
clients didn't get any errors from the broker. Still no clue as to why the
restart fixed it either.

On Wed, Aug 12, 2015 at 1:52 PM, Rajiv Kurian <ra...@signalfuse.com> wrote:

> We run around 10 kafka brokers running 0.8.1.
>
> This morning we had a failure were some of the partitions were under
> replicated. We narrowed the problem down to the following metrics on that
> one problem broker:
>
> i) Its CPU went down from a steady state of 26% to 15-17%.
> ii) The under-replicated partitions metric for all brokers (9 in total)
> besides the one stuck broker went up very high.
> iii) The kafka-bytes-in metric on the bad broker fell quite a bit. The
> kafka-bytes-out metric went do zero.
> iv) The kafka-messages-in metric on the bad broker remained the same,
> meaning our producers were able to successfully send it messages. This was
> also confirmed by checking the error metrics on the producers.
> v) The number of follower-fetches metric fell to zero.
>
> Further the log on the bad broker had instances of this message everywhere
> -
>
> 2015-08-12T15:06:37.616Z ERROR [kafka-request-handler-5            ]
> [kafka.server.KafkaApis              ]: [KafkaApi-8] Error when processing
> fetch request for partition [my-topic,1] offset 10224110951 from consumer
> with correlation id 72274709
>
> kafka.common.OffsetOutOfRangeException: Request for offset 10224110951
> but we only have log segments in the range 10224615730 to 10225014779.
>
>         at kafka.log.Log.read(Log.scala:377)
>
>         at
> kafka.server.KafkaApis.kafka$server$KafkaApis$$readMessageSet(KafkaApis.scala:401)
>
>         at
> kafka.server.KafkaApis$$anonfun$kafka$server$KafkaApis$$readMessageSets$1.apply(KafkaApis.scala:347)
>
>         at
> kafka.server.KafkaApis$$anonfun$kafka$server$KafkaApis$$readMessageSets$1.apply(KafkaApis.scala:343)
>
>         at
> scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
>
>         at
> scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:206)
>
>         at scala.collection.immutable.Map$Map1.foreach(Map.scala:105)
>
>         at
> scala.collection.TraversableLike$class.map(TraversableLike.scala:206)
>
>         at scala.collection.immutable.Map$Map1.map(Map.scala:93)
>
>         at
> kafka.server.KafkaApis.kafka$server$KafkaApis$$readMessageSets(KafkaApis.scala:343)
>
>         at kafka.server.KafkaApis.handleFetchRequest(KafkaApis.scala:309)
>
>         at kafka.server.KafkaApis.handle(KafkaApis.scala:71)
>
>         at
> kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:42)
>
>         at java.lang.Thread.run(Thread.java:744)
>
>
> I do know when the problem started based on when the metrics went crazy
> but sadly the logs rolled over because of the volume of these messages so I
> don't have the log entries for when the problem started.
>
> Also worth noting - the broker was listed in zk the whole time. It was
> also getting requests from other brokers and producers and consumers, which
> means it was not partitioned away. All the problems went away when we
> restarted this one bad broker and the metrics went back to normal values
> too. I can't quite figure out what would cause this problem and why a
> restart of the faulty broker fixed the problem. In the meanwhile we lost a
> lot of messages that landed on this broker. The producers (both Java and
> Golang) did not get any errors but the consumers did not get any of the
> enqueued messages on partitions that fell on this broker.
>
>
> Any help on why such a problem might happen and why the restart fixed it?
> Any known bugs in 0.8.1  that might have been fixed in a later version?
> Also I am not certain whether the partitions that this broker was a replica
> for were affected, or the partitions it was a leader for. My best guess is
> that partitions that it was the leader for were the actual ones which lost
> data.
>
>
> Thanks in advance!
>