记一次JAVA FULL GC问题处理【2】
1: 线上发生几次Full GC, 一直关注中:
1):YGC几本没有作用(正常的一次YGC会让EU减少, S0U,S01 中的一个清零,另一个变为非零), S0U1, S1U 都还是零的状态。
2): 可以看出老年代堆已经几乎满了,即使发生一个Full GC内存也没有释放多少。
3):可以判断基本上是发生了内存泄露
2: 导出内存信息
现网生成直方图可以用命令: jmap -histo 8 发现内存中,确实存在一些不应该存在的对象。工具不怎么强大, 没有分析出有效的结论。
4: MemoryAnalyzer 工具查看,MAT工具有支配树(dominator_tree) 这个视图,这个视图可以看出那个对象所持有的关联对象最大。
5: 从服务上看,内存占用最多的是tomcat处理请求线程占用最多。
里面有较多的ThreadLocalMap 对像。第一个是最大的对象为StringBuilder 。
6: 从支配树并不能直接看出问题的所在,这里从StringBuilder对象的内容查问题,内容有如下特点。
1): 发现里面的内容主要为日志内容。
2): 日志的长度较大,都是200-20M大小。支配树显示大的小,就已经可以打内存爆满。
3):日志内容,不是一次的,是多次日志,而且日志关联性不大。
4) 进一步查询日志还发现,后面的日志的前面部分不全。
7:现清这这个问题,我们回过头来看代码在log4j 2.6.0 的代码
网上有这种说说法: https://blog.csdn.net/jslcylcy/article/details/104371137
分析发现原理与上述博客中的是一样的。【搜索Log4j2在什么地方使用了StringBuilder,排查发现org.apache.logging.log4j.message.ParameterizedMessage这个类中有一个复用StringBuilder的代码】
但经过调式,上述的结论不是事实全部,但思路是正确的。
8: 于是重新做个调试: 但启动一个线程,减少干扰。在没有打印日志时,没有Thread没有对应的持有一个Entry没有关于StringBuilder的对象。
经过一次log输出: 线程通过ThreadLocal$ThradLocalMap持有了两个StringBuilder对象。
问题是在这里的: 上述的数组对象【17位】 实际上占用1024个对象空间。 Entry【19】占用的对象才255
两个对象的来原分别是PatternLayout extends AbstractStringLayout 的threadLocal 这个threadLocal 是重要的在输出前的threadLocal在日志文件中的行数据。
这个threadLocal是个内存复用,用之后除非线程消亡。
另一个是ParameterizedMessage 这里的使用场景是使用log.info("my name is {}", name) 这种参数代码,才会使用这个StringBuilder做为内存复用。
至此本问题原因解决,是由于日志一次性输出过多,导至线程持有的的一个数组对象过大。一个线程持有近100-200M数据,我们处理线程几十个,内存总归不能用。
解决本问题的办法,减少单次日志的输出。
关联问题请阅读:
https://i.cnblogs.com/posts/edit;postId=14785571