前言
在我前面写的一篇文章中(线上cpu过高的排查思路),提到了网关项目由于抗不住大量数据导致疯狂GC的问题。
在解决这个问题之后,我在项目调用下游系统逻辑后加了一段逻辑————往自己搭建的kafka发送数据。
问题
刚开始启动的时候,通过日志发现数据能发送kafka,过了一段时间后,日志没有再打印了。
而且每次重新启动都是这个现象。
原以为是外部没有再发送监控数据,所以kafka也不会收到。但是奇怪的是,为什么只有在刚启动那段时间才发送后面,就不发送了?
断点分析
通过打远程断点发现如下现象:
刚开始启动那会,断点还能不停地进入队列对应的线程,且队列的数据也在不停地变化,现象正常。 过了一段时间后,断点没有再进入线程了。
dump分析
虽然不知道是否是GC导致的,但是为了查明原因,我决定将dump日志导出来。
果然在项目运行一段时间后,堆内存溢出了。
分析dump文件步骤如下。先查看leak suspects
可以发现大概有5.4GB的数据导致内存泄漏。点击下面的details,
再点击Biggest Instances
可以看到有16个队列,每个队列的深堆大小惊人
点击其中一个队列,看看outgoing references
查看队列中的某个监控数据,发现这种数据没有带token,所以网关里的逻辑不会对其做过滤。
至此,我们能知道是外部没有token的数据量太大,导致网关的队列撑爆了,最终出现内存溢出。
但是,为什么会导致上面分析过程中的断点进不来呢?队列数据过大,为什么会导致kafka收不到呢?
加日志分析
1.判断线程是否运行
从队列获取数据的线程是while死循环,于是我在while下面一行,加了一行日志锚点。
由于线程是死循环,所以不管怎样,只要线程未死亡,那么最终肯定会不停打印这个锚点。
刚开始启动时,还能打印锚点,过了一段时间后就不再打印了。
2.判断线程是否死亡
不打印的原因,要么是线程的run方法结束运行,要么是线程卡住。
先判断线程的run方法是否结束运行,于是我在while之外加了一行日志锚点。
结果项目重启后,一直没有打印,说明线程没有结束。
3.判断线程是否卡住
那么可能就是线程卡住了。
由于run方法里调用链很多,所以我用排除法定位:
注释后面的方法,让最前面的逻辑生效,同时加锚点,重启后观察是否打印。
如果能打印,说明前面的方法不会导致线程卡住;反之,放开一行注释,再观察,依次类推。
最终定位到,是我新加的kafka逻辑最终导致线程卡住。
问题原因
线程在运行一段时间后,新加的发送到kafka的逻辑由于某种原因导致线程卡住,线程不再去处理队列中的数据,而外部数据在不停地存入队列,最终导致堆内存溢出。
这也是为什么远程断点最终无法再进来地原因。
问题解决
为什么kafka会导致线程卡住了呢?参考之前别人的一篇博客
发现运行网关项目的机器,无法ping通kafka的某个broker。
于是试着将broker加入机器的hosts文件,结果观察网关日志,kafka能正常发送数据了。
后续疑问
在ping不通某个broker之前,为什么刚开始kafka能发送?