记一次FastJson使用不当导致频繁Full GC排查

  具体原因为：https://www.cnblogs.com/liqipeng/p/11665889.html 与这篇文章的情况类似，可以直接按这篇文章的解决方案进行调整，此处只记录下排查过程。

  近期，测试压测某个查询接口时，发现压测的开始一段时间TPS比较稳定，在压测进行多了几次后，TPS开始出现巨大波动。

  进服务器利用TOP命令查看机器基本情况，发现业务层CPU的占用已经达到93%，但数据库层的CPU占用却仅在25%，说明数据库压力并不大，而这个业务只是单纯的查询用户是否处于黑名单状态中的单表查询，也没有看到有慢SQL的记录。

  又发现JVM进程的内存占用已经达6.3g，十分异常，但没有oom的情况出现（也有可能有，当时没注意）。于是转而利用jstat -gcutil命令查看jvm中各区占用内存情况。发现olden区占用在100%，并且在频繁的fullgc，fullgc完olden区的占用又变成100%。

  将项目重启后，继续利用 jstat -gcutil  pid 1000 重新观察各区内存使用情况，发现压测开始后 olden区 的占用在慢慢的爬升，但这个查询接口不应该有什么对象可以晋升到老年代，其中并没有做任何的本地缓存。JVM参数 -Xmx5866m -Xms5866m -Xss256K，那么按照新老年代占用比例为1:2，也不应出现Survivor区内存不足频繁分配到 olden区 的情况，应该说从业务代码来分析进入Survivor区的对象应该是没有的或极少的。（排查过业务代码，并没有死循环new对象情况）

 

  在没有任何头绪的情况下，只能考虑dump下内存进行分析了。这里用了jvisualvm在本地进行模拟。

  在本地将项目的堆内存调至128M，方便快速复现。在本地用20个线程进行并发，跑了1、2分钟就复现出了问题。

 可以看到运行几分钟后，老年代内存就占满了，并且在频繁的GC操作，复现了问题，本地看日志报出了oom。

 dump下内存发现，大量的String对象其内容为 ApiResultxxx，查看其引用对象，发现是Type对象，再往上找发现是com.alibaba.fastjson.parser.deserializer.JavaBeanDeserializer 对象

  由于我们业务层和数据库层是分离的，通过feign客户端进行调用，decode采用fastjson进行处理，这时候只能怀疑到平台组对这一层的decode封装是否有问题。

  排查平台组写的decode源码发现，在ms层直接返回非ApiResult封装的对象时，每次解析都会new一个ParameterizedTypeImpl进行处理。

  其实这时候并不觉得有什么问题，因为就算是new一个对象出来，解析完也可以回收。但是在本地单抽这段代码出来for循环然后Thread.sleep(10)执行，发现问题复现，olden区内存占用持续升高，开始觉得不对劲。debug了下fastjson的源码，发现fastjson是会将解析过的type对象进行缓存，并放到一个IdentityHashMap中，其中计算hash值是利用了 System.identityHashCode()，这个方法会直接返回对象的内存映射地址，然后以Type类型对象作为key值，那么也就是说每次new一个对象时，不管对象内容是否是一样的都会往IdentityHashMap里存放一条缓存，然后频繁逃过 young gc，进入survivor区，最后晋升变成老年代，或者是young gc回收一次后，survivor区不够放（因为这一个对象其实牵连着众多对象，涉及的内存面就较大），直接往老年代里扔。（从结果来看）

  

  至此，问题定位完毕，将数据库层的返回值用ApiResult封装后，在本地运行了下gc结果变为正常。

  第二天调整完后上压测，测试反馈接口已正常，查看jvm各区内存使用情况也已正常。通知经理可以按正常排期上线。

总结：

1.jstat命令 jmap命令 ，以及jvisualvm等工具的使用要熟练。

2.对JVM的分区以及垃圾回收的流程要有一定的了解，厚积薄发，多看多学，总有用到的地方。

3.使用别人的东西前需要对这个东西有一个大概的了解，这次就是事先有review过一部分平台组的代码，对结构有大概的了解才定位起来比较快。