一次out of memory引发的思考

一、OOM场景分析

场景：A系统从B系统全量同步一个表的内容。通过定时任务30s同步一次，数据分页返回，每页100条。B系统同步表有数据40W+，且表内容有个字段“content”是text类型。

问题：测试发现同步一段时间后导致系统出现OOM使系统宕机（测试机器分配512M内存）。后台错误日志如下：

 

分析步骤如下：

1、猜想是error日志过多导致OOM

   原因：

     a、快速定位“NewsSyncClient.java:63”发现报错代码处于循环内，且每次打印所有错误信息

     

b、“GC overhead limit exceeded”Sun 官方对此的定义是：“并行/并发回收器在GC回收时间过长时会抛出OutOfMemroyError。过长的定义是，超过98%的时间用来做GC并且回收了不到2%的堆内存。用来避免内存过小造成应用不能正常工作。

   参考：

java.lang.OutOfMemoryError：GC overhead limit exceeded填坑心得

http://www.cnblogs.com/hucn/p/3572384.html

综上猜测，此时系统还未出现OOM，而是打印error日志才导致的OOM，日志改为只记录e.getMessage。但是事情没那么简单，还未找到点上。关键点是为什么会抛出异常... ...

 

 

2、猜想是循环更新数据库效率低下导致OOM

   原因：循环更新总是先查询，再来新增或更新，每次会多一次查询。

         

   处理：把单个saveOrUpdate改为replace into，之所以不用批量是因为开头说过的表内容字段“content”是text类型，而且一页数据有100条，而我们线上设置的sql查询允许最大内存40M左右。防止使用批量语句后查询占用内存超过限制导致失败。

   结果：修改后数据库更新效率提升不明显，问题仍然存在。还是没找到关键点... ...

 

3、猜想是定时任务没有做到单线程处理

原因：通过dump报表可以看到有多个线程（4个），而定时任务只允许同时只有一个线程的

 

处理：通过排查代码，发现如下红色框部分忘加导致一个线程在处理，由于数据量大未处理完，而定时任务又启动了另一个线程

 

 

结果：红色部分是人为疏忽导致漏加，这个bug还是被找了出来。但是问题还是没有解决... ...

4、猜想接口返回结果解析过慢且数据量大导致OOM

   原因：

   a、通过dump文件分析接口返回结果对象一直占有大量内存

   

 b、接口返回结果SyncResp要经过数据解密，GSON转换等一些列操作

 处理：把数据解密和GSON转换部分去掉，返回空对象，数据库保留更新操作。

 结果：问题还是存在，在数据解密，GSON转换前后加上时间，发现这段处理耗时很少（用的Google的Gson），那么问题的关键点还是没找到... ...

 

5、猜想递归导致OOM

   原因：分页查询使用了递归，每次查询会获得一个resp变量保存查到的数据(表有字段是text)，且同步页数较多（4000页），最终resp积累过多导致了OOM，

重写SyncResp的finalize方法，结果也发现未被调用。

  

   处理：用循环替代递归，观察重写SyncResp的finalize方法调用正常，自此问题得到解决，终于可以长舒一口气了。

   

教训：尽量不要使用递归

 

二、总结

1、递归坏处

   由于递归需要系统堆栈，所以空间消耗要比非递归代码要大很多。而且，如果递归深度太大，可能系统撑不住。

   耗空间：系统在每次递归前都要保护现场, 资源占用比其他调用高很多;

   耗时间：栈帧上下文切换，切换到最新的方法栈帧。

 

2、设置HeapDumpOnOutOfMemoryError生成dump文件

 2.1 、tomcat 生成dump文件：

 linux中  ：

  1.打开/tomcat_home/bin/catalina.sh文件 ，

  2.加上：JAVA_OPTS="$JAVA_OPTS -server -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home1/goct/logs/goct"

 Windows中：

  1.打开/tomcat_home/bin/catalina.bat文件；

2.加上：set JAVA_OPTS=%JAVA_OPTS% -server -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\heapdump

2.2 、JWS：打开项目的 /goct-dev3/eclipse/goct.launch设置，不指定dump文件位置默认位于项目根目录

 

3、mat分析outofmemory问题

最近用mat分析outofmemory问题，发现java对象占用的内存有两个指标，不是太明白，经过分析并查阅mat的官方文档弄明白了，总结一下：

1) shallow heap

    shallow是“肤浅的，表面的”的意思，从字面意思理解就是对象直接占用的堆内存空间。

 

2)retained heap

   表示由当前对象持有的堆内存空间，包括自身以及直接和间接引用指向的对象所占用的堆内存空间（这些被直接或间接引用的对象只能从当前对象可达，也就是说被引用对象的生命周期依赖于当前对象）。

   如果当前对象被GC了，将有retained heap数量的内存被释放。retained heap大于shallow heap。

 

 对于基本类型以及其数组对象，retained heap略大于(基本等于)shallow heap。

对于其他类型的对象，retained heap则由其引用的对象（或对象树）占用内存情况决定。

譬如char[]对象，属于基本类型的对象数组，无法再引用其他对象了，其自身占用的内存shallow heap就基本等于retained heap。

譬如String对象，shallow heap远小于retained heap,是由于String内部持有char[]数组对象，且char[]不会被其他的对象引用，真正的内容是存储在char[]中的，因此shallow heap和retained heap差别很大，如果String对象被GC，其内部char[]同时会被GC。

 

  

MA Histogram截图：

 

 

 

官方文档的详细描述：

 

 

---