Administrator
发布于 2018-10-15 / 3035 阅读
44

JVM 内存区域划分与第一次遇到 Java heap space

入职第三个月,我把线上服务搞 OOM 了

那是个导出报表的功能。测试环境数据量小,跑得飞快;上线之后运营点了一次"导出全部",三分钟后服务就挂了。监控上堆内存是一条 45 度的斜线,直接顶到天花板然后掉底。

我登机器捞日志,看到了人生中第一个这个:

Exception in thread "http-nio-8080-exec-12" java.lang.OutOfMemoryError: Java heap space
    at java.util.Arrays.copyOf(Arrays.java:3332)
    at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124)
    at java.lang.StringBuilder.append(StringBuilder.java:136)
    at com.xxx.ReportService.buildCsv(ReportService.java:87)
    at com.xxx.ReportController.export(ReportController.java:42)

当时我只知道"内存不够了",但到底是哪儿不够、该调什么参数,完全没概念。这篇把后来补的课整理一下。

先搞清楚 JVM 把内存分成了哪几块

JDK 8 的运行时数据区,能出问题的主要是这几块:

+-------------------------------------------+
|            堆 Heap (线程共享)               |  ← 对象实例、数组
|   +------------------+------------------+  |
|   |    Young (1/3)   |     Old (2/3)    |  |
|   | Eden | S0 | S1   |                  |  |
|   +------------------+------------------+  |
+-------------------------------------------+
|        Metaspace 元空间 (本地内存)          |  ← 类元数据、常量池
+-------------------------------------------+
|      直接内存 Direct Memory (本地内存)       |  ← NIO ByteBuffer
+-------------------------------------------+
|  虚拟机栈 (线程私有)  | 每个方法一个栈帧      |  ← 局部变量、操作数栈
|  本地方法栈           |                    |
+-------------------------------------------+
|  程序计数器           | 唯一不会 OOM 的区域   |
+-------------------------------------------+

注意 JDK 8 相比 JDK 7 有个重要变化:永久代(PermGen)被移除了,换成了 Metaspace,而且 Metaspace 用的是本地内存,不是 JVM 堆内存。这个变化导致我在看老资料时被误导过好几次——一堆 2015 年前的博客还在讲 -XX:PermSize,在 JDK 8 上设置会直接告警。

$ java -XX:PermSize=256m -version
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option PermSize=256m;
support was removed in 8.0

我那次事故的排查过程

服务挂了但没留下 dump 文件,所以我先加上参数再复现:

-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/data/dump/

在测试环境灌了 50 万条数据复现了一次,拿到一个 1.8G 的 hprof 文件。用 MAT(Memory Analyzer Tool)打开,第一页就写着:

Problem Suspect 1
One instance of "char[]" loaded by "<system class loader>" occupies 1,204,631,048 bytes
  (89.31% of the heap)

一个 char 数组占了 1.2G。点开 dominator tree 往下追,指向我那行代码:

// ReportService.java:87 附近
StringBuilder sb = new StringBuilder();
for (Order order : orderMapper.selectAll()) {     // 一次捞了 50 万条
    sb.append(order.getOrderNo()).append(",")
      .append(order.getAmount()).append("\n");    // 全部拼在一个 StringBuilder 里
}
return sb.toString();

根因就两个:selectAll() 一次性把 50 万条记录全加载进堆;StringBuilder 又把它们拼成一个巨大的字符串。数据量小的测试环境完全看不出来。

六种 OOM 报错信息,看到要能立刻对上号

报错信息出问题的区域常见原因
Java heap space内存泄漏,或一次性加载数据过多
GC overhead limit exceededGC 花了 98% 的时间只回收了不到 2% 的堆
Metaspace元空间动态生成类过多(CGLIB、Groovy、反射代理)
Direct buffer memory直接内存NIO 的 DirectByteBuffer 没被回收
unable to create new native thread栈 / 系统内存线程数超过系统限制
Requested array size exceeds VM limit申请的数组长度超过 Integer.MAX_VALUE

逐个说说我后来遇到的:

GC overhead limit exceeded

这个比 heap space 更"温柔"一点。它是说:JVM 连续多次 GC,每次耗时超过 98% 且回收不到 2% 的堆,JVM 判断"再 GC 下去也没意义了",于是提前抛异常。本质是堆几乎被占满且对象都不该死,属于内存泄漏的典型信号。

可以用 -XX:-UseGCOverheadLimit 关掉这个检查,但关掉之后你会得到 heap space OOM,问题一个没解决。我们那个服务当时就是加了这参数苟了两天,最后还是得改代码。

Metaspace

java.lang.OutOfMemoryError: Metaspace

我在本地跑一个批量生成代理类的测试时遇到过。JDK 8 默认 Metaspace 最大是无限制(受本地内存限制),所以一开始不好触发。要看实际用了多少:

$ jstat -gcmetacapacity 12345
   MCMN       MCMX        MC       CCSMN      CCSMX       CCSC
   0.0    1134592.0    98304.0        0.0  1048576.0    12288.0

我们项目用了大量的 CGLIB 动态代理(Spring AOP 默认对无接口的类用 CGLIB),加上 MyBatis 的 mapper 代理,Metaspace 稳定在 90M 左右。上线时给它配了:

-XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=256m

这里有个容易混淆的点:MetaspaceSize 不是初始大小,而是触发 Full GC 的阈值。达到这个值就会做一次 Metaspace 的 GC 并动态调整。如果不设 MaxMetaspaceSize,理论上能一直涨到本地内存耗尽。

Direct buffer memory

java.lang.OutOfMemoryError: Direct buffer memory

这个我们项目用 Netty 的时候碰到过。DirectByteBuffer 不在堆里,所以堆内存监控看着很正常,但进程 RSS 一直在涨。它靠 Cleaner 机制(虚引用)回收,而 Cleaner 要等 GC 触发,如果堆一直很空闲,GC 就不跑,直接内存就一直不释放。这是个死循环式的问题。

默认直接内存上限等于 -Xmx。要显式控制:

-XX:MaxDirectMemorySize=512m

从 JDK 8 开始可以用 BufferPoolMXBean 监控它,我加到了监控页面上:

BufferPoolMXBean direct = ManagementFactory.getPlatformMXBeans(BufferPoolMXBean.class)
        .stream()
        .filter(b -> b.getName().equals("direct"))
        .findFirst().orElse(null);
System.out.println("已用: " + direct.getMemoryUsed() / 1024 / 1024 + "MB");
System.out.println("上限: " + direct.getTotalCapacity() / 1024 / 1024 + "MB");

unable to create new native thread

java.lang.OutOfMemoryError: unable to create new native thread

这个跟堆没关系。每个线程要占 -Xss 指定的栈空间(默认 1M,注意这是虚拟内存的预留,不是实际占用),线程太多就会触达系统限制。

# 查系统限制
$ ulimit -u
4096

# 查当前进程的线程数
$ ps -o nlwp= -p 12345
1832

# 或者看 /proc
$ cat /proc/12345/status | grep Threads
Threads:	1832

这类问题的常见原因是线程池没设上限(用了 Executors.newCachedThreadPool()),或者每次请求都 new 一个线程池。newCachedThreadPool 的最大线程数是 Integer.MAX_VALUE,高 QPS 下会瞬间创建大量线程。我们项目统一改成了手动 new ThreadPoolExecutor,指定有界队列和拒绝策略。

StackOverflowError

严格说它不是 OOM,是栈空间不够。最常见的原因是递归没有终止条件,或者对象之间存在循环引用导致 toString / 序列化无限递归。我写部门树的时候踩过:

Exception in thread "main" java.lang.StackOverflowError
    at com.xxx.Dept.toString(Dept.java:45)
    at com.xxx.Dept.toString(Dept.java:45)
    at com.xxx.Dept.toString(Dept.java:45)

同一个方法重复出现几百行,一眼就能认出来。栈深度默认大概在 1 万左右(取决于 -Xss 和栈帧大小),调大 -Xss 只是延后报错,改递归才是正解。

实用的排查命令

# 1. 先看是不是真的快满了
$ jmap -heap 12345
Heap Usage:
PS Young Generation
Eden Space:  capacity = 1073741824 (1024.0MB)  used = 1073741824 (1024.0MB)   100% used
PS Old Generation
   capacity = 2147483648 (2048.0MB)  used = 2143289344 (2044.0MB)   99% used

# 2. 看实例数量排名(不用 dump,快)
$ jmap -histo 12345 | head -20
 num     #instances         #bytes  class name
----------------------------------------------
   1:        512304     1229529600  [C
   2:        511987       12287688  java.lang.String
   3:         50231        5625872  com.xxx.Order

# 3. 导出 dump(会 STW,生产环境慎用)
$ jmap -dump:format=b,file=/data/dump/heap.hprof 12345

# 4. 实时看 GC
$ jstat -gcutil 12345 1000
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT
  0.00  99.80  87.42  98.16  95.10  92.31   2145   62.341    38   45.203

最后那行 O 列是 98.16,FGC 是 38,FGCT 累计 45 秒——老年代快满了,Full GC 频繁,这是 OOM 前兆。我现在把这个指标配了告警,超过 90% 就发钉钉。

我那次最后怎么改的

两个改动:一是用 MyBatis 的流式查询替代 selectAll,二是边查边写不拼接。

@Options(resultSetType = ResultSetType.FORWARD_ONLY, fetchSize = 1000)
@Select("select order_no, amount from t_order where created_at >= #{start}")
void scanOrders(@Param("start") Date start, ResultHandler<Order> handler);
try (BufferedWriter writer = new BufferedWriter(new FileWriter(file), 64 * 1024)) {
    orderMapper.scanOrders(start, ctx -> {
        Order o = ctx.getResultObject();
        writer.write(o.getOrderNo());
        writer.write(",");
        writer.write(String.valueOf(o.getAmount()));
        writer.write("\n");
    });
}

改完之后,同样导出 50 万条,堆占用稳定在 210M 左右(之前峰值 2G),耗时从 3 分 12 秒降到 41 秒。

师傅后来跟我说的一句话我一直记着:内存问题的排查不难,难的是你有没有在出事前把 HeapDumpOnOutOfMemoryError 打开。没有 dump 的 OOM,跟没发生过一样,下次还会在同样的地方摔。

参考