运维发现线上的Nifi实例挂了，内存OOM，gc线程占用cpu 100%， 重启后1~2分钟又会OOM。
在jvm发生OOM时候有把heap dump出来，查看内存占用排序：
image.png
从图片上看到Date和byte[]占用很多内存，后面包含binlog的Event对象，初步估计是binlog太多导致的。
看了导致OOM的线程栈：
image.png
竟然是InputStream.skip()，看这个方法的源码222行：
image.png
其中MAX_SKIP_BUFFER_SIZE是2048，也就是说此时申请一个不超过2k的byte[]都没空间了。
运维查了binlog日志（MySQL innodb），发现在出问题的时间段产生了比平常多很多的binlog日志，达到3G以上。
重启了好几次不行，只能跳过这一段时间的binlog消费，后面手动补数据算是暂时解决该问题。
问题排查步骤：
拿到mysql binlog文件，用linux命令查看binlog中是否有大事务，命令参考：https://www.jianshu.com/p/6c14ea0648e3
mysqlbinlog mysql-bin.000313 | grep "GTID$(printf '\t')last_committed" -B 1 | grep -E '^# at' | awk '{print $3}' | awk 'NR==1 {tmp=$1} NR>1 {print ($1-tmp);tmp=$1}' | sort -n -r | head -n 100
发现了其中有一个大事务，2个position之差达到3G，找到2个position后可以把这2个position之间的行打印出来看看是什么sql导致的，
mysqlbinlog mysql-bin.000313 --base64-output=decode-rows -v | awk '/at 12185705/{flag=1} flag; /at 3393631429/{flag=0}' | more
mysqlbinlog命令参考：https://dev.mysql.com/doc/refman/8.0/en/mysqlbinlog.html
shell命令输出2个pattern之间的内容参考：https://stackoverflow.com/questions/38972736/how-to-print-lines-between-two-patterns-inclusive-or-exclusive-in-sed-awk-or
基本到这基本定位了，是由于短时间产生大量的binlog导致的，后来业务上也证实了这一点，业务代码逻辑写的有问题，插入和更新无限次导致的。
在Nifi（用的1.9.2版本）中有背压机制，即下流的Processor速度慢了会反向限流上游的Processor处理速度。
如果说下游处理速度跟不上，消费binlog的Processor应该暂停消费，为什么会导致OOM呢？
带着疑问翻看源码（注：Nifi 1.9.2还不支持gtid消费方式，被我们改造支持了，不过和本文内容无关）：
image.png
可以看到，CaptureChangeMySQL这个processor会死循环从queue中把binlog event取出来消费，queue在哪定义的呢：
image.png
queue是一个无界的阻塞队列，到这里就可能知道queue这么定义有问题，不限制大小很容易出现OOM，能防止出现OOM的唯一可能就是生产者控制生产速度。在哪里往这个queue里offer数据呢：
image.png
在BinlogEventListener里只要接收到binlog内容就往里塞，由于这个queue是无界的，因此offer基本都会成功.
bug找到了，后续也就可以在分析的基础上改了，也有人提了patch，好像没有通过，参考：https://issues.apache.org/jira/browse/NIFI-6501
解决方案基本如下：
queue设置大小，在offer失败的情况下暂停binlog消费一段时间；如果下游处理实在太慢，需要报警，因为gtid是有时效性的，在我们这种情况下，事故是半夜发生的，等到发现时已经过去几个小时了，然后这些gtid竟然失效了，即使binlog还在，不清楚gtid的失效机制。
总结这次事故的教训：
1.加强系统监控，出现事故第一时间发邮件、短信、微信、电话，要通知到运维及时采取措施，运维解决不了要通知到开发，做好值班机制很重要，至少出问题了能立即找到人，打开电脑解决问题。
2.导出的heap dump达到15G,一般的开发电脑很难打开这么大的dump分析，即使能打开也需要半小时。为什么有这么大的内存呢，因为这个nifi上面跑了很多流程，只要一个库的binlog太大就会造成所有流程都不能跑了。应该一个nifi实例上跑一个流程，内存不需要设置太大，分开实例还有一个好处，一个库的binlog挂了不影响其他库的正常消费。
4.业务代码，不能全量插入、更新数据，至少要分成多个事务，不过对于本次事故，即使分成多个事务也于事无补，还是产生大量的binlog，但保持小事务是必要的。
网友评论