消费kafka数据的时候, 总是有几个partition会停住不消费, 有时候过十分钟, 或者2小时, 又开始消费了…

用框架的kafka框架(hermes)已经有段时间了, hermes client是他们对kakfa client封装的. 我们主要是从kafka消费数据后放到ES索引.

上上上周的时候, ES升级了一次, 上上周的时候, ES的结构调整了一下, 上周五的时候, 把client升级了一次.

###周一

周一到公司, 收到hermes同事发来的邮件, 说周末的时候有两个 topic 时不时就会有堆积.

我们并没有收到ES无数据的告警, 到ES看了一下, 数据量看起来还很平稳. 到Hermes页面简单查看了一下, 20个partitons里, 有几个会卡住不动, Lag 特别大.

先是查看日志, 然后查看代码, 发现snakeyaml这个库加载7W行的一个字典, 需要5分钟 (1W行的只要5秒, 非线性增长). 我们设置了5分钟就重新加载一次字典(外部数据). 导致一半时间并没有消费数据.

把时间增大, 1小时加载一次吧. 但问题好像并没有解决… 有时候好像是缓解了, 数据在快速消费, 有时候上来看一下, 发现堆积又在增加…

###周二

周二晚上, 看了一下日志, 发现有个进程已经2小时没有消费了, 但是还占着那个partiton并没有让给别人. 正在我查原因的时候, 它, 居然又突然开始消费了…

###周三

consumber 看起来已经挂掉了, 但还霸占着partition不释放. 以前碰到这种情况, 都是因为某个线程jvm OOM 了, 后来修改了代码, 如果有OOM , 整个进程直接退出, 就再也没有出现过.

和hermes同事沟通, 他认为是处理流程block, 我一听有道理啊. 以前别人问我, “我的消费程序怎么突然就不消费了”, 一般都是进程在哪里卡住了.

然后就打印日志, 其实也没多少好打的, 每次消费就是调用ES bulk client的add方法, 然后每10000条发往ES之后, 有个回调.

也不是马上就能重现. 慢慢跑着吧. 等问题出来之后, 查看日志, 好像都很正常. 最后一笔数据发送之后, 就再也没有下文了.

同事发现最后一笔数据总是不能10000条就发送了, 看起来是bulk client的定时器到时间了(我们配置的30秒). 所以认为是最后30秒的后面一段时间其实有问题, 不再消费数据了.

同事说的都好有道理啊, 问题转向了查hermes client.

周四

我tcpdump抓包看一下, 本意是想看一下, 是client没有发送请求, 还是server对请求没有返回数据. 结果却让我大吃一惊.

从tcpdump的结果来看, client不停的在发送fetch request, 但是,,, 请求的topic列表却是空列表..

问题很诡异, 但至少有一点已经明确了, 并不是处理流程卡住. 现在要确定的就是为什么会请求空的topic列表.

我决定不用hermes client, 而是直接用kafka client去消费.

周五

我们是用hangout来处理数据的, 规范一点, 我还是要写一个新的input plugin.

做为java新手, 写起来真是慢. 同事说应该不是这个问题, 我写完其实就是另外一人herems client. 闲着也是闲着, 写着吧.

另外在同时, 也在一边调整线程数量打印更多日志等.

有次我把所有线程关掉, 只启动一个. 好像一切正常. 这时候另外一个哥们C又在docker里面启动了一个消费者(他在观察另外一个问题), tcpdump里面就刷刷的输出错误信息.

然后就发现了, 是只要有rebalance, 这个现象马上出现.

我这边程序还没有写完, 同事又发来一个重磅好消费. 说可能是kafka的一个BUG. https://issues.apache.org/jira/browse/KAFKA-2978. 0.9.0.1已经解决.

看了一下, 和我们的症状简直一样一样.

同事升级了server到0.9.0.1(好像是不用, 因为patch只涉及client代码), 然后建议我先把依赖手工换成kafka-clients 0.9.0.1

问题解决了.

后续

  1. 我还是写了一个新的插件, 使用新的kafka consumer api. 并且写了一下hermes的反序列化类.

  2. 写完之后, 发现同事前面说的对, 我写了之后, 其实就是另外一个hermes client, 问题一样会有. (之前以为会用到hermes meta信息, 写完后觉得 hermes client 就是做了[反]序列化.)

  3. hermes消息(至少我们消费的这些数据)在序列/反序列化的时候, 多做了一次Json load/dupm.json.dumps(json.dumps(object)) json序列化应该还是挺费CPU的. 后续再测试具体性能.

  4. 即使是有问题的0.9.0.0, 用老的api消费好像并没有问题, 我们自己的kafka集群也是这个版本, 已经用了至少半年的吧, 到现在还没有问题.

  5. 在整个问题发现/解决过程中, 我好像都是跟着同事的思路在走. 哎, 老了, 脑子不动了.

  6. 期间还伴随着别的问题, 比如docker里面的时区不对, 导致不能消费(还不知道为什么). 比如同事建议我把session.timeout增加, 希望避免rebalance(当然这个不治本), 但是依照hermes的方法提供这个参数之后, 程序完全不动, 日志也没有任何输出. 总而言这, 一个星期就这么过来的, 它对我造成了10000点的伤害.