Summer Blog

内存溢出排查：sharding-jdbc+tomcat datasource + mybatis

问题描述

不停的请求项目中的搜索接口，项目运行一段时间后，出现内存溢出问题。现象是每次YGC后，老年代内存就会增加内存0.02%（2G内存，1G堆内存），而且这些老年代的内存很难被回收，即使手动调用了FGC，依然存在内存中。基本上，只能无奈的看着老年代内存不断增长，却无能为力。

排查

  1. 不停调用搜索接口，直到内存溢出导出内存情况，使用MAT进行分析。发现内存溢出的原因是存在一个很大的URLClassLoader对象。怀疑公司定制的spring boot有问题。
  2. 因为怀疑是系统原因，所以改调用其他接口，验证是否会有现象。发现确实有现象，并且现象一致。这里走了弯路，因为搜索接口不仅是会完成搜索的工作，同时会把搜索的过程调用kafka发送日志，之后会再接收日志存储进数据库和es。调用其他接口依旧有现象的原因是，之前日志没有处理完依旧在处理日志。这里卡住了很久，一直在研究框架问什么会有URLClassLoader大对象。
  3. 幡然醒悟不是框架原因是，过了一天时间，系统调用其他接口，不会内存溢出了，没有导出想要的内存信息。发现还是和搜索接口有关。这里有另一坑，就是我的内存是导出的本机，但是本机可能本身内存也比较小，所以URLClassLoader并不是溢出的根本因素。只有继续调用搜索接口，复现问题，更多的日志进行分析。
  4. 这次联系了平台，在平台上复现的时候的日志导出了。这里有用到jvm启动参数-XX:GCTimeLimit，当发现GC花费时间超过上限时会抛出异常，但保持jvm的运行，方便保留现场。因为用到的是docker，jvm挂了就会重启，无法从平台上导出日志。
  5. 从平台导出的日志，帮助找到了真凶，老年代驻留了很大ConnectionPool对象，顺藤摸瓜找到了对象持有了一堆ClientPreparedStatement对象没有被close，找到其中的sql语句，是存储日志到数据库的语句。这里用到了sharding-jdbc做了分表存储，数据库源是tomcat datasource，orm是mybatis。于是将这个地方的存储注释掉，继续跑脚本复现问题。
  6. 依旧会有每次YGC后的老年代占用比增加，但手动调用FGC后内存会被回收。果断移除了sharding-jdbc，再试，还是会被回收。继续跑脚本复现。

原因

还没有想明白为什么不关闭ClientPreparedStatement。猜测因为事务配置直接使用了Spring支持的，但是去掉事务后没有明显的改变，还是有很多这样的对象堆积。

总结

  1. 对于自己不熟悉的组件一定要研究透彻了再使用，否则可能埋下隐患
  2. JVM内存问题排查，一定要先收集到足够多的信息，不要急于验证猜想

命令

jstat -gcutil 1 10000 # 每10秒打印一次进程1的gc情况

jmap -histo:live 1 | head -100 # 列出进程1的jvm中当前存活的对象，head是指前100行

jmap -dump:format=b,file=/opt/jvm-06-29 1 # 导出进程1的jvm状态

jvm启动参数

-XX:GCTimeLimit=time-limit

花费在GC上的时间上限，默认是98，当超过上限时，会抛出OutOfMemory(HeapSpace)的异常

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/opt/jvm-06-29

内存溢出时导出堆内存到/opt/jvm-06-29

衍生

虚引用

不同的引用类型，主要体现的是对象不同的可达性（reachable）状态和对垃圾收集的影响。强引用指向一个对象，就表明它一直活着，不能被回收。软引用，可以豁免一些回收，只有在jvm认为内存不足时回收。弱引用不能豁免垃圾回收，仅仅提供一种访问弱引用对象的途径。

对于幻象引用，有时候也翻译成虚引用，你不能通过它访问对象。幻象引用仅仅是提供了一种确保对象被 finalize 以后，做某些事情的机制，比如，通常用来做所谓的 Post-Mortem 清理机制，我在专栏上一讲中介绍的 Java 平台自身 Cleaner 机制等，也有人利用幻象引用监控对象的创建和销毁。

小结：

comments powered by Disqus