转载

记一次线上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的进程号

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

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

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

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

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

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

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

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

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

@0x6c3391470 pool-1-thread-3 这个线程占用了整个内存的97.5%,展开后问题定位到 ReportQueryController 这个类，这就好办了。

其实从 Leak Suspects Report 也可以印证这一点：

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

然后我们看stack详情：

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

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稳定性问题得到解决。