记一次线上OOM异常解决过程

背景

事情是这个样子的,本部门维护了一个在线报表查询服务(简称为report),近一段时间,经常有用户向运营小伙伴反馈,report经常发生页面打不开,一段时间后自己恢复的问题。虽然不是交易系统,但给用户造成的困扰也很严重,浪费了大量资源,所以最近打算抽出时间精力,集中解决下。


过程

在这个现象再一次发生时,登陆到服务器发现JVM一直在进行fullGC,但始终回收不到内存,同时日志中报出了java.lang.OutOfMemoryError: Java heap space
无奈之下只能先重启服务保障正常访问。
随后,通过修改Tomcat启动脚本,在JVM启动参数中添加OOM dump:

vi catalina.sh 
#java jvm config
#JAVA_OPTS="-Xms1024m -Xmx4096m -Xss1024K -XX:PermSize=512m -XX:MaxPermSize=2048m"
JAVA_OPTS="-Xms1024m -Xmx4096m -Xss1024K -XX:PermSize=512m -XX:MaxPermSize=2048m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/opt/tomcat8999/temp"

一段时间后,再一次出现问题时登陆服务器发现OOM日志已经被dump出来了,24428就是当前JVM的进程号

clipboard.png

接下来把日志拷贝到本机,启动Eclipse Memory Analyzer,加载 java_pid24428.hprof,如图:

clipboard.png

打开Histogram查看各个类的对象情况

clipboard.png

除去char[],String等java基础对象外,没发现占用大量空间的自定义类,再看下DominatorTree, 这个视图列出了内存中最大的对象

clipboard.png

这里我们发现了一个异常现象,

clipboard.png

@0x6c3391470 pool-1-thread-3 这个线程占用了整个内存的97.5%,展开后问题定位到ReportQueryController这个类,这就好办了。
其实从Leak Suspects Report也可以印证这一点:

clipboard.png

然后我们看stack详情:

clipboard.png

OK!到这里问题已经准备定位到了,ReportQueryController.writeDownFile方法是提供报表数据下载的方法,问题就出在下载环节,接下来就是查找代码漏洞了。


// 输出报表内容
@Override
public void processRow(List<String> row) throws Exception {
    String value = "\n" + format.format(row.toArray());
    write(out, value, charset);
    atomicTotal.incrementAndGet();
}
...
if (atomicTotal.get() > DOWNLOAD_MAX) {
    throw new RuntimeException(DOWNLOAD_MAX_ERROR);
}

问题就出在这段代码里,程序本来想限制最大下载行数DOWNLOAD_MAX=100000行,所以定义了一个自增Integer,每读取一行数据则+1,最后判断这个AtomicInteger的值是否达到DOWNLOAD_MAX,进而决定是否抛出异常。
可问题是,如果读出的数据量远远超过DOWNLOAD_MAX,就有可能在判断atomicTotal.get() > DOWNLOAD_MAX前把内存占满。
而且我们看此时AtomicInteger的值已经是11066861

Class Name | Shallow Heap | Retained Heap | Percentage

java.util.concurrent.atomic.AtomicInteger @ 0x6df9c11e8  11066861 | 16 | 16 | 0.00%

一千多万条记录最终把内存占满。


接下来就是改造代码:

// 输出报表内容
@Override
public void processRow(List<String> row) throws Exception {
    String value = "\n" + format.format(row.toArray());
    write(out, value, charset);

    //每隔1000行flush
    flushPerOneThousand(flushSignal, out);
    //超过100000行检查
    if (checkOverFlow(atomicTotal)) {
        breakOut(out);
    }
}

改造后会在每1000行flush数据到文件,且检查达到DOWNLOAD_MAX后第一时间退出方法,并关闭流,抛出异常。
经测试,改造完成的版本,在下载之前会发生问题的记录集时不会造成OOM.

[ypdata@sjsa-hadooptest tomcat8999]$ jstat -gc 14754 1000 20000
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
44544.0 45568.0  0.0   14588.5 1300992.0 66862.7   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 66862.7   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 66955.7   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 66955.7   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 66957.8   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 66959.8   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 66966.4   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 67059.4   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 67105.6   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 67105.6   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694
44544.0 45568.0  0.0   14588.5 1300992.0 67105.6   848896.0   367583.8  78552.0 76517.4 8152.0 7735.1    349  231.509   5     57.185  288.694

至此,本次report稳定性问题得到解决。


总结

  • 线上系统应添加dump on oom选项,以便第一时间得到heap镜像
  • 出现OOM后,应及时利用内存分析工具排查泄露原因,定位到具体代码段
  • 平时写代码要时刻绷紧一根弦,不止关注业务逻辑的实现,更需要考虑程序对资源的调用(计算、内存、网络、磁盘)

enjoy yourself

阅读 1.1k

推荐阅读
手撸Java
用户专栏

让Java更快、更小、更精

0 人关注
5 篇文章
专栏主页