kafka运维事故处理一则

问题的起因

最近做一次Kafka的副本数调整,从双副本调整为三副本时出现了一次副本不同步的问题,我们使用的kafka的版本为1.0.0,刚开始调整其他的topic时一起都工作正常,突然调整到其中一个不常用的topic时,这里假设为t1,调整指令为:

./kafka-reassign-partitions.sh --zookeeper localhost:2181 --reassignment-json-file /tmp/t1.json --execute

发现调整总是不成功,通过verify指令查看:

./kafka-reassign-partitions.sh --zookeeper localhost:2181 --reassignment-json-file /tmp/t1.json --verify
Status of partition reassignment:
Reassignment of partition t1-3 is still in progress

提示其中某个分区一直处于复制状态。

问题发展

刚开始以为只是数据没追上,没有意识到问题的严重性。等待观察了很长一段时间以后,

结果发现越来越多的分区开始副本脱离Isr,最严重的有很多分区Isr中只有一个成员了。

好在业务处理一直是正常的,没有受到影响。

问题与分析

整个问题处理和分析过程分为几个步骤:

第一步:尝试重新分配

操作步骤:

1)删除zk节点

rmr /admin/reassign_partitions

2)重新调用命令

./kafka-reassign-partitions.sh --zookeeper localhost:2181 --reassignment-json-file /tmp/t1.json --execute

在这个过程中,发现有部分分区能够通过调整正常工作,但是有些分区无论怎么调整也无法正常工作。

这里我们开始怀疑是某几个节点有问题,有考虑重启这些节点来恢复kafka的想法。

由于这个是线上系统,并且数据量巨大,而且有好多分区Isr中只有一个,那么重启的风险不小。

第二步:发现问题

仔细查看每个节点的Kafka的日志文件内容,发现有部分broker上的日志中有以下错误日志:

2018-06-05 10:33:50,037|ERROR|ReplicaFetcherThread-1-4|kafka.utils.Logging$class.error:107|[ReplicaFetcher replicaId=0, leaderId=4, fetcherId=1] Error due to|
kafka.common.KafkaException: Error processing data for partition ycloud_cvod-4 offset 184090
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2$$anonfun$apply$mcV$sp$1$$anonfun$apply$2.apply(AbstractFetcherThread.scala:204)
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2$$anonfun$apply$mcV$sp$1$$anonfun$apply$2.apply(AbstractFetcherThread.scala:172)
at scala.Option.foreach(Option.scala:257)
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2$$anonfun$apply$mcV$sp$1.apply(AbstractFetcherThread.scala:172)
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2$$anonfun$apply$mcV$sp$1.apply(AbstractFetcherThread.scala:169)
at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59)
at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48)
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2.apply$mcV$sp(AbstractFetcherThread.scala:169)
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2.apply(AbstractFetcherThread.scala:169)
at kafka.server.AbstractFetcherThread$$anonfun$processFetchRequest$2.apply(AbstractFetcherThread.scala:169)
at kafka.utils.CoreUtils$.inLock(CoreUtils.scala:217)
at kafka.server.AbstractFetcherThread.processFetchRequest(AbstractFetcherThread.scala:167)
at kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:113)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:64)

同时我们发现controller.log文件长时间没有更新了,刚开始是怀疑可能是controller出问题了,在网上找了一下,发现kafka确实有一个bug:https://issues.apache.org/jira/browse/KAFKA-6666,这个bug需要把kafka升级到最新版本kafka1.1.0才能解决问题。由于线上已经有很多分区ISR成员只有一个,并且我们无法接受系统停止,所以无法接受关停Kafka进程进行升级的方案。

于是考虑调整controller,来尝试让同步工作恢复,我们进行了以下的操作步骤:

  • 删除zk节点: /controller
    很快,kafka集群重新分配了一个新的controller。

继续观察Isr中不全的副本的数据情况,发现数据仍然没有更新:

yuxianbing@KafkaMsg01:/data1/kafka/log4js$ ls -lrt /data*/kafka/logs/t1-9
total 16520620
-rw-rw-r-- 1 kafka kafka 0 Mar 22 15:11 leader-epoch-checkpoint
......
-rw-rw-r-- 1 kafka kafka 10485756 Jun 5 05:09 00000000189479366726.timeindex
-rw-rw-r-- 1 kafka kafka 10 Jun 5 05:09 00000000189479366726.snapshot
-rw-rw-r-- 1 kafka kafka 0 Jun 5 05:09 00000000189450811184.timeindex
-rw-rw-r-- 1 kafka kafka 60080 Jun 5 05:09 00000000189450811184.index
-rw-rw-r-- 1 kafka kafka 10485760 Jun 5 10:33 00000000189479366726.index
-rw-rw-r-- 1 kafka kafka 815836756 Jun 5 10:33 00000000189479366726.log

可以看到t1-9这个分区的副本文件一直没有变化,说明复制还是不正常;

第三步:再次重新分配

修改一下分区的副本所在的brokers,不要跟之前一致,然后执行

./kafka-reassign-partitions.sh --zookeeper localhost:2181 --reassignment-json-file /tmp/t1.json --execute

验证分配结果:

./kafka-reassign-partitions.sh --zookeeper localhost:2181 --reassignment-json-file /tmp/t1.json --verify
Status of partition reassignment:
Reassignment of partition t1-9 completed successfully

发现分配工作正常了。
于是按照这个思路,先把所有未跟上的分区重新进行分配。

第四步:均衡处理

由于第三步的工作只是让每个分区的副本能够重新与leader同步起来,但是整个kafka的分区分配就不均衡了,所以这里还需要重新对所有的分区进行均衡处理。

等待复制正常以后,所有分区的ISR都变成3个了,我们把kafka升级到1.1.0版本,整个处理过程结束。

问题总结

本次操作应该是触发了kafka的这个bug,不过从整个处理过程来看,遇事不能太着急,从各个方面去分析问题点,再加上各种可控范围内的尝试,最终达到了理想的处理结果。

另外对于开源的产品一定要及时跟进相关的issue list,及时针对有重大影响的问题就是修复和升级。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 217,406评论 6 503
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 92,732评论 3 393
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 163,711评论 0 353
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,380评论 1 293
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,432评论 6 392
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,301评论 1 301
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,145评论 3 418
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,008评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,443评论 1 314
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,649评论 3 334
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,795评论 1 347
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,501评论 5 345
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,119评论 3 328
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,731评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,865评论 1 269
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,899评论 2 370
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,724评论 2 354

推荐阅读更多精彩内容