阅读 467

一次内存泄漏和Full GC的排查定位

事情是这样的,就在昨天,早上到公司上班,习惯性地到K8S上看看昨晚打出去的版本发了没。

在打开容器列表的时候,发现了一些不对劲的地方,我的那个应用,居然吃掉了6G的内存。

虽然我来公司不久,但是在之前一次上线的过程中,比较敏感的记住了线上设置的堆内存大小,1G

也就是说,堆外空间占用达5G,肉眼观察,大概率是内存泄漏了

也仅仅是猜测,没有怎么理这茬。。毕竟提测也有一段时间了,业务代码不大可能造成内存泄漏。

我还是太年轻了。。。过了一会,测试在群上说,接口的响应速度很慢。我看了一下,每次响应均在2S以上,结合刚刚的堆外空间泄漏判断,应该是频繁的Full GC导致停顿。

果然,觉得有问题的地方,一定会出现问题。。既然如此,那就得仔细排查排查了。

JVM参数分析

进入docker容器内,查看java进程的启动信息

ps -ef | grep java
复制代码

前几行为JVM 的参数

-Xmx1g -Xms1g 
-Xloggc:/opt/app/bin/../log/gc.log 
-XX:NCumberOfGLogFiles=5
-XX:GCLogFileSize=5M 
-XX:HeapDumpPath=/opt/app/bin/../log/HeapDumpOnOutOfMemoryError/
复制代码

从参数上可知,没有指定GC,服务器又是Java8版本,说明默认使用的是Parallel GC,不存在Concurrent Mode Fail

Concurrent Mode Fail时,会启动一个单线程、STW的垃圾回收器进行垃圾收集,在大堆情况下,会造成比较长的停顿。

而且配置的-Xmx1g,说明堆空间也不是很大。

GC日志分析

GC日志很重要!线上的应用,不是太差劲的运维,基本上都会配上这个参数-Xloggc

所以感谢运维的同事!

直接在容器中打开GC日志。

1.366: [GC (Allocation Failure)  262144K->13458K(1005056K), 0.0377596 secs]
2.061: [GC (Allocation Failure)  275602K->12506K(1005056K), 0.0303328 secs]
2.657: [GC (Allocation Failure)  274650K->12482K(1005056K), 0.0231478 secs]
3.150: [GC (Allocation Failure)  274626K->15146K(1005056K), 0.0332410 secs]
复制代码

前面的GC还比较和谐,没有出现Full GC,每次内存清理的耗时也比较短。

不甘心的我按了vi的快捷键shift + G,跳到了文档尾部,这下子不对劲的事情出现了。

349908.124: [Full GC (Ergonomics)  1041404K->1009967K(1044992K), 1.8348046 secs]
349909.987: [Full GC (Ergonomics)  1041399K->1010051K(1044992K), 1.8928675 secs]
349911.906: [Full GC (Ergonomics)  1041395K->1009637K(1044992K), 1.9980643 secs]
复制代码

可以看到,到了后期,每次GC都是Full GC,而且耗时都将近2s,关键是,每次清理后,仍然有大量的对象存活。

到了这里,基本上可以确定是内存泄漏了。

但是,究竟是哪个对象造成的内存泄漏?这就需要对应用的内存快照进行分析了。

DUMP生成

需要注意的是,运维的同事的确有设置了-XX:HeapDumpPath参数,意为在OOM时,记录下应用的内存快照。

然鹅,我到相应的目录中查找,却没有找到该文件,说明,没有发生OOM!

这里就需要提到内存泄漏和内存溢出的区别的,感兴趣的翻一下之前写的文章

直接说结论,在我排查这个问题的时候,此次的内存泄漏还未导致内存溢出,所以该参数还未生效。

这也从侧边佐证了此次的异常为内存泄漏!

ps:2020/12/30号补充:-XX:HeapDumpPath参数是指定内存快照输出的路径,但还需配合-XX:+HeapDumpOnOutOfMemoryError开启OOM时生成内存快照

所以,就得使用jmap工具来生成应用的内存快照了。

jmap -dump:file=filename,format=b pid
复制代码

jmap使用时,会去/tmp/hsperfdata_$user的目录下找到对应的进程信息,然后根据进程信息生成对应进程的内存快照。

这里也遇到一个坑。报了这么一个错。

Unable to open socket file: target process not responding or HotSpot VM not loaded
The -F option can be used when the target process is not responding
复制代码

我这里报错是因为(其他原因可能也会报这个错误),进入容器的时候,默认用户是root,而运维在部署应用的时候,创建了另外一个用户去启动应用。

那么自然,jmap去root的目录就找不到对应的进程信息了

切换用户后异常解决,生成了一个1G多的文件。

MAT工具分析

MAT就是,下载地址,其实我也不大会用,用自己浪过四级的粗略能看得懂。

摸索了一下之后,看到了以下的信息。

查看Top Consumers

可以看到,一个叫做ThreadLocalScope的类生成的对象,占用了84%的内存,大概率是这些对象引起的泄漏。

继续点进去。

可以看到,该类被创建了很多对象,但只有一部分是造成泄漏的。在其内部中,有一个叫做wrapped的元素,持有了一个logs的ArrayList,由这个对象导致的溢出。

继续排查,是一些业务问题了,在此简单说一下,是另外的一个同事,在使用jaeger组件的时候,部分逻辑没处理好,导致对象的堆积。后续将这个问题反馈给他,bug也指给他修改了。

分享一下排查过程,希望对你有所帮助。

文章分类
后端
文章标签