[KAFKA-5751] Kafka cannot start; corrupted index file(s)

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Duplicate
• Affects Version/s: 0.11.0.0
• Component/s: log
• Environment: Linux (RedHat 7)
• Assignee: Unassigned
• Reporter: Martin M
• Created: 18/Aug/17 17:58
• Updated: 22/Aug/17 10:33
• Resolved: 22/Aug/17 10:33

Description

A system was running Kafka 0.11.0 and some applications that produce and consume events.
During the runtime, a power outage was experienced. Upon restart, Kafka did not recover.
Logs show repeatedly the messages below:

server.log

[2017-08-15 15:02:26,374] FATAL [Kafka Server 1001], Fatal error during KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
org.apache.kafka.common.protocol.types.SchemaException: Error reading field 'version': java.nio.BufferUnderflowException
	at org.apache.kafka.common.protocol.types.Schema.read(Schema.java:75)
	at kafka.log.ProducerStateManager$.readSnapshot(ProducerStateManager.scala:289)
	at kafka.log.ProducerStateManager.loadFromSnapshot(ProducerStateManager.scala:440)
	at kafka.log.ProducerStateManager.truncateAndReload(ProducerStateManager.scala:499)
	at kafka.log.Log.kafka$log$Log$$recoverSegment(Log.scala:327)
	at kafka.log.Log$$anonfun$loadSegmentFiles$3.apply(Log.scala:314)
	at kafka.log.Log$$anonfun$loadSegmentFiles$3.apply(Log.scala:272)
	at scala.collection.TraversableLike$WithFilter$$anonfun$foreach$1.apply(TraversableLike.scala:733)
	at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:33)
	at scala.collection.mutable.ArrayOps$ofRef.foreach(ArrayOps.scala:186)
	at scala.collection.TraversableLike$WithFilter.foreach(TraversableLike.scala:732)
	at kafka.log.Log.loadSegmentFiles(Log.scala:272)
	at kafka.log.Log.loadSegments(Log.scala:376)
	at kafka.log.Log.<init>(Log.scala:179)
	at kafka.log.Log$.apply(Log.scala:1580)
	at kafka.log.LogManager$$anonfun$loadLogs$2$$anonfun$5$$anonfun$apply$12$$anonfun$apply$1.apply$mcV$sp(LogManager.scala:172)
	at kafka.utils.CoreUtils$$anon$1.run(CoreUtils.scala:57)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)

kafkaServer.out

[2017-08-15 16:03:50,927] WARN Found a corrupted index file due to requirement failed: Corrupt index found, index file (/opt/nsp/os/kafka/data/session-manager.revoke_token_topic-7/00000000000000000000.index) has non-zero size but the last offset is 0 which is no larger than the base offset 0.}. deleting /opt/nsp/os/kafka/data/session-manager.revoke_token_topic-7/00000000000000000000.timeindex, /opt/nsp/os/kafka/data/session-manager.revoke_token_topic-7/00000000000000000000.index, and /opt/nsp/os/kafka/data/session-manager.revoke_token_topic-7/00000000000000000000.txnindex and rebuilding index... (kafka.log.Log)
[2017-08-15 16:03:50,931] INFO [Kafka Server 1001], shutting down (kafka.server.KafkaServer)
[2017-08-15 16:03:50,932] INFO Recovering unflushed segment 0 in log session-manager.revoke_token_topic-7. (kafka.log.Log)
[2017-08-15 16:03:50,935] INFO Terminate ZkClient event thread. (org.I0Itec.zkclient.ZkEventThread)
[2017-08-15 16:03:50,936] INFO Loading producer state from offset 0 for partition session-manager.revoke_token_topic-7 with message format version 2 (kafka.log.Log)
[2017-08-15 16:03:50,937] INFO Completed load of log session-manager.revoke_token_topic-7 with 1 log segments, log start offset 0 and log end offset 0 in 10 ms (kafka.log.Log)
[2017-08-15 16:03:50,938] INFO Session: 0x1000f772d26063b closed (org.apache.zookeeper.ZooKeeper)
[2017-08-15 16:03:50,938] INFO EventThread shut down for session: 0x1000f772d26063b (org.apache.zookeeper.ClientCnxn)

Issue Links

• is duplicated by: KAFKA-5747 Broker crashes on startup when trying to parse empty snapshot files