[KAFKA-2236] offset request reply racing with segment rolling

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 0.8.2.0
• Fix Version/s: 0.10.0.0
• Component/s: core
• Labels: newbie
• Environment: Linux x86_64, java.1.7.0_72, discovered using librdkafka based client.
• Assignee: William Thurston
• Reporter: Alfred Landrum
• Reviewer: Guozhang Wang
• Created: 02/Jun/15 04:39
• Updated: 13/Oct/17 04:00
• Resolved: 04/May/16 21:56

Description

My use case with kafka involves an aggressive retention policy that rolls segment files frequently. My librdkafka based client sees occasional errors to offset requests, showing up in the broker log like:

[2015-06-02 02:33:38,047] INFO Rolled new log segment for 'receiver-93b40462-3850-47c1-bcda-8a3e221328ca-50' in 1 ms. (kafka.log.Log)
[2015-06-02 02:33:38,049] WARN [KafkaApi-0] Error while responding to offset request (kafka.server.KafkaApis)
java.lang.ArrayIndexOutOfBoundsException: 3
at kafka.server.KafkaApis.fetchOffsetsBefore(KafkaApis.scala:469)
at kafka.server.KafkaApis.fetchOffsets(KafkaApis.scala:449)
at kafka.server.KafkaApis$$anonfun$17.apply(KafkaApis.scala:411)
at kafka.server.KafkaApis$$anonfun$17.apply(KafkaApis.scala:402)
at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:244)
at scala.collection.TraversableLike$$anonfun$map$1.apply(TraversableLike.scala:244)
at scala.collection.immutable.Map$Map1.foreach(Map.scala:109)
at scala.collection.TraversableLike$class.map(TraversableLike.scala:244)
at scala.collection.AbstractTraversable.map(Traversable.scala:105)
at kafka.server.KafkaApis.handleOffsetRequest(KafkaApis.scala:402)
at kafka.server.KafkaApis.handle(KafkaApis.scala:61)
at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:59)
at java.lang.Thread.run(Thread.java:745)

quoting Guozhang Wang's reply to my query on the users list:

"I check the 0.8.2 code and may probably find a bug related to your issue.
Basically, segsArray.last.size is called multiple times during handling
offset requests, while segsArray.last could get concurrent appends. Hence
it is possible that in line 461, if(segsArray.last.size > 0) returns false
while later in line 468, if(segsArray.last.size > 0) could return true."

http://mail-archives.apache.org/mod_mbox/kafka-users/201506.mbox/%3CCAHwHRrUK-3wdoEAaFbsD0E859Ea0gXixfxgDzF8E3%3D_8r7K%2Bpw%40mail.gmail.com%3E

Issue Links

• blocks: FLINK-2735 KafkaProducerITCase.testCustomPartitioning sporadically fails