You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@kafka.apache.org by "thomas norden (JIRA)" <ji...@apache.org> on 2014/08/29 20:37:53 UTC

[jira] [Commented] (KAFKA-1554) Corrupt index found on clean startup

    [ https://issues.apache.org/jira/browse/KAFKA-1554?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14115631#comment-14115631 ] 

thomas norden commented on KAFKA-1554:
--------------------------------------

We experienced this today, it happened when we upgraded from java 1.6 to 1.7.

kafka 0.8.1
CentOS release 5.9 (Final)
java version "1.7.0_65"
OpenJDK Runtime Environment (rhel-2.5.1.2.el5_10-x86_64 u65-b17)
OpenJDK 64-Bit Server VM (build 24.65-b04, mixed mode)

> Corrupt index found on clean startup
> ------------------------------------
>
>                 Key: KAFKA-1554
>                 URL: https://issues.apache.org/jira/browse/KAFKA-1554
>             Project: Kafka
>          Issue Type: Bug
>          Components: core
>    Affects Versions: 0.8.1
>         Environment: ubuntu 12.04, oracle jdk 1.7
>            Reporter: Alexis Midon
>            Priority: Critical
>
> On a clean start up, corrupted index files are found.
> After investigations, it appears that some pre-allocated index files are not "compacted" correctly and the end of the file is full of zeroes.
> As a result, on start up, the last relative offset is zero which yields an offset equal to the base offset.
> The workaround is to delete all index files of size 10MB (the size of the pre-allocated files), and restart. Index files will be re-created.
> {code}
> find $your_data_directory -size 10485760c -name *.index #-delete
> {code}
> This is issue might be related/similar to https://issues.apache.org/jira/browse/KAFKA-1112
> {code}
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,696 INFO main kafka.server.KafkaServer.info - [Kafka Server 847605514], starting
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,698 INFO main kafka.server.KafkaServer.info - [Kafka Server 847605514], Connecting to zookeeper on zk-main0.XXX:2181,zk-main1.XXX:2181,zk-main2.XXXX:2181/production/kafka/main
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,708 INFO ZkClient-EventThread-14-zk-main0.XXX.com:2181,zk-main1.XXX.com:2181,zk-main2.XXX.com:2181,zk-main3.XXX.com:2181,zk-main4.XXX.com:2181/production/kafka/main org.I0Itec.zkclient.ZkEventThread.run - Starting ZkClient event thread.
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,714 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:zookeeper.version=3.3.3-1203054, built on 11/17/2011 05:47 GMT
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,714 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:host.name=i-6b948138.inst.aws.airbnb.com
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,714 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.version=1.7.0_55
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,715 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.vendor=Oracle Corporation
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,715 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.home=/usr/lib/jvm/jre-7-oracle-x64/jre
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,715 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.class.path=libs/snappy-java-1.0.5.jar:libs/scala-library-2.10.1.jar:libs/slf4j-api-1.7.2.jar:libs/jopt-simple-3.2.jar:libs/metrics-annotation-2.2.0.jar:libs/log4j-1.2.15.jar:libs/kafka_2.10-0.8.1.jar:libs/zkclient-0.3.jar:libs/zookeeper-3.3.4.jar:libs/metrics-core-2.2.0.jar
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,715 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,716 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.io.tmpdir=/tmp
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,716 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:java.compiler=<NA>
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,716 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:os.name=Linux
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,716 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:os.arch=amd64
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,717 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:os.version=3.2.0-61-virtual
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,717 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:user.name=kafka
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,717 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:user.home=/srv/kafka
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,717 INFO main org.apache.zookeeper.ZooKeeper.logEnv - Client environment:user.dir=/srv/kafka/kafka_2.10-0.8.1
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,718 INFO main org.apache.zookeeper.ZooKeeper.<init> - Initiating client connection, connectString=zk-main0.XXX.com:2181,zk-main1.XXX.com:2181,zk-main2.XXX.com:2181,zk-main3.XXX.com:2181,zk-main4.XXX.com:2181/production/kafka/main sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@4758af63
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,733 INFO main-SendThread() org.apache.zookeeper.ClientCnxn.startConnect - Opening socket connection to server zk-main1.XXX.com/10.12.135.61:2181
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,738 INFO main-SendThread(zk-main1.XXX.com:2181) org.apache.zookeeper.ClientCnxn.primeConnection - Socket connection established to zk-main1.XXX.com/10.12.135.61:2181, initiating session
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,745 INFO main-SendThread(zk-main1.XXX.com:2181) org.apache.zookeeper.ClientCnxn.readConnectResult - Session establishment complete on server zk-main1.XXX.com/10.12.135.61:2181, sessionid = 0x646838f07761601, negotiated timeout = 6000
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,747 INFO main-EventThread org.I0Itec.zkclient.ZkClient.processStateChanged - zookeeper state changed (SyncConnected)
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,961 INFO main kafka.log.LogManager.info - Found clean shutdown file. Skipping recovery for all logs in data directory '/mnt/kafka_logs'
> 2014-07-11T00:53:17+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:17,962 INFO main kafka.log.LogManager.info - Loading log 'flog-30'
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg 2014-07-11 - 00:53:18,349 FATAL main kafka.server.KafkaServerStartable.fatal - Fatal error during KafkaServerStable startup. Prepare to shutdown
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg java.lang.IllegalArgumentException: - requirement failed: Corrupt index found, index file (/mnt/kafka_logs/flog-30/00000000000121158146.index) has non-zero size but the last offset is 121158146 and the base offset is 121158146
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.Predef$.require(Predef.scala:233)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.OffsetIndex.sanityCheck(OffsetIndex.scala:352)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.Log$$anonfun$loadSegments$5.apply(Log.scala:159)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.Log$$anonfun$loadSegments$5.apply(Log.scala:158)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.Iterator$class.foreach(Iterator.scala:727)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.AbstractIterator.foreach(Iterator.scala:1157)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.AbstractIterable.foreach(Iterable.scala:54)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.Log.loadSegments(Log.scala:158)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.Log.<init>(Log.scala:64)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.LogManager$$anonfun$loadLogs$1$$anonfun$apply$4.apply(LogManager.scala:118)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.LogManager$$anonfun$loadLogs$1$$anonfun$apply$4.apply(LogManager.scala:113)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:33)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.mutable.ArrayOps$ofRef.foreach(ArrayOps.scala:105)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.LogManager$$anonfun$loadLogs$1.apply(LogManager.scala:113)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.LogManager$$anonfun$loadLogs$1.apply(LogManager.scala:105)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:33)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at scala.collection.mutable.WrappedArray.foreach(WrappedArray.scala:34)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.LogManager.loadLogs(LogManager.scala:105)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.log.LogManager.<init>(LogManager.scala:57)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.server.KafkaServer.createLogManager(KafkaServer.scala:275)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.server.KafkaServer.startup(KafkaServer.scala:72)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.server.KafkaServerStartable.startup(KafkaServerStartable.scala:34)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.Kafka$.main(Kafka.scala:46)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.emerg  -    at kafka.Kafka.main(Kafka.scala)
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:18,351 INFO main kafka.server.KafkaServer.info - [Kafka Server 847605514], shutting down
> 2014-07-11T00:53:18+00:00 i-6b948138 local3.info 2014-07-11 - 00:53:18,353 INFO ZkClient-EventThread-14-zk-main0.XXX.com:2181,zk-main1.XXX.com:2181,zk-main2.XXX.com:2181,zk-main3.XXX.com:2181,zk-main4.XXX.com:2181/production/kafka/main org.I0Itec.zkclient.ZkEventThread.run - Terminate ZkClient event thread.
> {code}



--
This message was sent by Atlassian JIRA
(v6.2#6252)