记一次JAVA FULL GC问题处理【2】

1： 线上发生几次Full GC， 一直关注中：

1）：YGC几本没有作用（正常的一次YGC会让EU减少， S0U，S01 中的一个清零，另一个变为非零）， S0U1, S1U 都还是零的状态。

 2）： 可以看出老年代堆已经几乎满了，即使发生一个Full GC内存也没有释放多少。 

 3）：可以判断基本上是发生了内存泄露

 2：  导出内存信息 

jmap -dump:format=b,file=heap.binnew 8 

 

3：于是使用工具jvisualvm 工具查看， 可看查到如下的直方图:

现网生成直方图可以用命令： 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