JVM性能调优与堆外内存泄露排查实战

January 16, 2018 Java Jvm, Gc, Performance, Debugging 4350 字 9 分钟阅读

前言

JVM性能调优和内存问题排查一直是Java开发人员面临的重要挑战。本文将从GC调优的三个核心目标出发，结合一次实际的堆外内存泄露排查案例，为大家提供系统性的性能调优思路和实用的排查方法。

在复杂的分布式系统中，内存问题往往是最难定位的一类问题。特别是堆外内存泄露，由于发生在JVM堆之外，常规的GC监控工具很难发现，很容易导致系统在生产环境中突然崩溃。本文将分享一次完整的堆外内存泄露排查过程，希望能为读者提供有价值的参考。

GC调优三目标：延迟、吞吐量、容量

核心概念

GC调优和其他性能调优一样，需要遵循科学的方法论。在开始调优之前，我们需要明确三个核心性能目标：

1. 延迟（Latency）

延迟指的是GC暂停时间的上限要求。这类目标通常来自于业务需求：

所有用户交易必须在10秒内得到响应
90%的订单付款操作必须在3秒以内处理完成
推荐商品必须在 100 ms 内展示到用户面前

面对这类性能指标，需要确保在交易过程中，GC暂停不会超过延迟需求。

2. 吞吐量（Throughput）

吞吐量指的是单位时间内系统能够完成的工作量。常用指标包括：

每秒处理请求数
每小时完成操作数
系统资源利用率

吞吐量关注的是系统整体的性能表现，而不仅仅是单次操作的响应时间。

3. 容量（Capacity）

容量调优更多是从成本角度考虑，在满足延迟和吞吐量需求的前提下，尽量降低硬件配置，优化系统资源利用效率。

工厂流水线类比

为了更好地理解这三个概念，我们可以用一个工厂装配流水线的例子来说明：

延迟：从第一个车架零件进入流水线到组装好的自行车离开流水线总共需要4小时
吞吐量：每一分钟就有一辆自行车离开流水线，每小时能组装60辆自行车
容量：流水线最大能支持的生产能力，可以通过增加流水线数量来提升

这个类比告诉我们，调优可以是硬件升级（增加容量）也可以是软件优化（降低延迟），需要根据实际需求选择合适的方案。

调优参数详解与实验数据

基础示例程序

为了演示GC调优的实际效果，我们来看一个示例程序：

java
 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
public class Producer implements Runnable {
  private static ScheduledExecutorService executorService = Executors.newScheduledThreadPool(2);
  private Deque<byte[]> deque;
  private int objectSize;
  private int queueSize;

  public Producer(int objectSize, int ttl) {
    this.deque = new ArrayDeque<byte[]>();
    this.objectSize = objectSize;
    this.queueSize = ttl * 1000;
  }

  @Override
  public void run() {
    for (int i = 0; i < 100; i++) { 
      deque.add(new byte[objectSize]); 
      if (deque.size() > queueSize) {
        deque.poll();
      }
    }
  }

  public static void main(String[] args) throws InterruptedException {
    executorService.scheduleAtFixedRate(new Producer(200 * 1024 * 1024 / 1000, 5), 0, 100, TimeUnit.MILLISECONDS);
    executorService.scheduleAtFixedRate(new Producer(50 * 1024 * 1024 / 1000, 120), 0, 100, TimeUnit.MILLISECONDS);
    TimeUnit.MINUTES.sleep(10);
    executorService.shutdownNow();
  }
}

这个程序每100毫秒提交两个作业，模拟不同的对象生命周期。

GC日志配置

运行上述程序时，可以通过以下JVM参数打开GC日志记录：

1
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps

典型的GC日志如下：

1
2
3
2015-06-04T13:34:16.119-0200: 1.723: [GC (Allocation Failure) [PSYoungGen: 114016K->73191K(234496K)] 421540K->421269K(745984K), 0.0858176 secs] [Times: user=0.04 sys=0.06, real=0.09 secs] 
2015-06-04T13:34:16.738-0200: 2.342: [GC (Allocation Failure) [PSYoungGen: 234462K->93677K(254976K)] 582540K->593275K(766464K), 0.2357086 secs] [Times: user=0.11 sys=0.14, real=0.24 secs] 
2015-06-04T13:34:16.974-0200: 2.578: [Full GC (Ergonomics) [PSYoungGen: 93677K->70109K(254976K)] [ParOldGen: 499597K->511230K(761856K)] 593275K->581339K(1016832K), [Metaspace: 2936K->2936K(1056768K)], 0.0713174 secs] [Times: user=0.21 sys=0.02, real=0.07 secs]

实验配置对比

我们通过三种不同的配置运行相同的代码，得到不同的结果：

堆内存大小	GC算法	有效工作占比	最长停顿时间
-Xmx12g	-XX:+UseConcMarkSweepGC	89.8%	560 ms
-Xmx12g	-XX:+UseParallelGC	91.5%	1,104 ms
-Xmx8g	-XX:+UseConcMarkSweepGC	66.3%	1,610 ms

延迟调优

假设需求：每次作业必须在 1000ms 内处理完成。已知实际作业处理只需要100ms，因此GC暂停不能超过900ms。

从实验结果可以看到，使用ConcMarkSweepGC配置满足了这个要求：

1
java -Xmx12g -XX:+UseConcMarkSweepGC Producer

对应的GC日志中，暂停时间最大为560ms，达到了延迟指标900ms的要求。

吞吐量调优

假定吞吐量指标为：每小时完成1300万次操作处理。

通过分析实验数据，发现ParallelGC配置满足需求：

1
java -Xmx12g -XX:+UseParallelGC Producer

对应的有效工作占比为91.5%，计算过程：

1
10 * 60 * 1000 * 91.5% = 5,490,000 ms = 5490s

容量调优

在满足延迟和吞吐量需求的前提下，我们可以尝试降低硬件配置。从实验数据可以看到，8GB内存的配置虽然满足延迟要求，但有效工作占比只有66.3%，说明硬件资源不足。

实战：一次堆外内存泄露的完整排查过程

现象发现

一个线上稳定运行了三年的系统，从物理机迁移到Docker环境后，运行一段时间突然被监控系统发出实例不可用的报警。通过负载均衡自动下掉故障节点。

1
-Xmx1792m -Xms1792m -Xmn900m -XX:PermSize=256m -XX:MaxPermSize=256m -server -Xss512k

查看操作系统监控，发现内存使用情况异常：

蓝色线表示总内存使用量，一直涨到4G后超出系统限制
设置的最大堆内存是1792M，明显是堆外内存泄露导致

应急措施

紧急重启应用实例，启动后内存占用正常，一切正常。

初步排查

GC日志分析

首先查看GC日志，发现内存始终回落到170M左右，并无明显增加。要知道JVM进程本身占用的内存接近4G，进一步确认是堆外内存导致。

代码排查

检查线上服务代码，发现：

没有地方显式使用堆外内存
没有依赖额外的native方法
网络IO代码托管给Tomcat，Tomcat不太可能有堆外内存泄露

深入排查

JVM堆内存Dump

由于线上出问题的Server已经被kill，幸亏还有其它几台机器。发现它们也占用了很大的堆外内存，只是还没到触发OOM的临界点。

使用jmap dump JVM堆：

1
jmap -dump:format=b,file=heap.bin [pid]

MAT分析

使用MAT分析heap文件，堆的使用情况显示总共用了200多M，和GC日志打印出来的170M相差不大，远远没有到4G的程度。

MAT提示可能的内存泄露点：CachedBnsClient类有12452个实例，占用了整个堆的61.92%。

代码检查

系统中大部分对于CachedBnsClient的调用都是通过注解Autowired的，这部分实例数很少。唯一频繁产生此类实例的代码如下：

java
1
2
3
4
5
6
@Override
public void fun() {
    BnsClient bnsClient = new CachedBnsClient();
    // do something
    return ;
}

查看CachedBnsClient类：

java
1
2
3
4
5
6
public class CachedBnsClient {
    private ConcurrentHashMap<String, List<String>> authCache = new ConcurrentHashMap<String, List<String>>();
    private ConcurrentHashMap<String, List<URI>> validUriCache = new ConcurrentHashMap<String, List<URI>>();
    private ConcurrentHashMap<String, List<URI>> uriCache = new ConcurrentHashMap<String, List<URI>>();
    ......
}

看起来没有任何可能导致内存泄露的地方。

线程信息分析

使用jstack dump线程信息，发现现场信息越多越能找出蛛丝马迹。除了正常的IO线程以及框架本身的一些守护线程外，竟然多出来了12563个线程：

1
2
3
4
"Thread-5" daemon prio=10 tid=0x00007fb79426e000 nid=0x7346 waiting on condition [0x00007fb7b5678000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
   at java.lang.Thread.sleep(Native Method)
   at com.xxxxx.CachedBnsClient$1.run(CachedBnsClient.java:62)

而且这些正好是运行在CachedBnsClient的run方法上！这些特定线程的数量正好是12452个，和cachedBnsClient数量一致！

重新检查代码

重新查看CachedBnsClient代码时，发现了一个关键的遗漏点：

java
 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
public CachedBnsClient(BnsClient client) {
    super();
    this.backendClient = client;
    new Thread() {
        @Override
        public void run() {
            for (;;) {
                refreshCache();
                try {
                    Thread.sleep(60 * 1000);
                } catch (InterruptedException e) {
                    logger.error("出错", e);
                }
            }
        }
    }
}

这段代码是CachedBnsClient的构造函数，其在里面创建了一个无限循环的线程，每隔60s启动一次刷新缓存！

关键发现

在看到12452个等待在CachedBnsClient.run的业务线程的一瞬间就意识到，肯定是这边的线程导致堆外内存泄露了。下面需要计算泄露的内存量是不是确实能够引起OOM。

内存计算问题

由于设置的Xss是512K，即一个线程栈大小是512K，进行如下计算：

1
12563 * 512K = 6331M = 6.3G

整个环境一共4G，加上JVM堆内存1.8G(1792M)，已经明显超过了4G：

1
(6.3G + 1.8G) = 8.1G > 4G

但这个计算显然有问题，因为如果按照此计算，应用早就被OOM了。

深入分析

Java线程底层实现

JVM的线程在Linux上底层是调用NPTL(Native Posix Thread Library)来创建的，一个JVM线程就对应Linux的lwp(轻量级进程)，一个thread.start就相当于do_fork了一把。

在JVM启动时设置了-Xss=512K(线程栈大小)，这512K中然后有8K是必须使用的，这8K是由进程的内核栈和thread_info公用的。用户态栈可用内存是：

1
512K - 8K = 504K

Linux实际物理内存映射

Linux对物理内存的使用非常抠门，一开始只是分配了虚拟内存的线性区，并没有分配实际的物理内存，只有推到最后使用的时候才分配具体的物理内存，即所谓的请求调页。

查看smaps进程内存使用信息

使用如下命令查看实际物理内存使用信息：

1
cat /proc/[pid]/smaps > smaps.txt

实际物理内存使用信息如下：

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
7fa69a6d1000-7fa69a74f000 rwxp 00000000 00:00 0 
Size:                504 kB
Rss:                  92 kB
Pss:                  92 kB
Shared_Clean:          0 kB
Shared_Dirty:          0 kB
Private_Clean:         0 kB
Private_Dirty:        92 kB
Referenced:           92 kB
Anonymous:            92 kB
AnonHugePages:         0 kB
Swap:                  0 kB
KernelPageSize:        4 kB
MMUPageSize:           4 kB

搜索504KB，正好是12563个，对应12563个线程。其中Rss表示实际物理内存92KB，Pss表示实际物理内存(按比例共享库)92KB(由于没有共享库，所以Rss==Pss)。

挑选符合条件的几十组查看，基本都在92K-152K之间，再加上内核栈8K：

1
(92 + 152)/2 + 8K = 130K

取整为128K，即反映此应用平均线程栈大小。

重新进行内存计算

JVM一开始申请了：

1
-Xmx1792m -Xms1792m

即1.8G的堆内内存，这里是即时分配，一开始就用物理页框填充。

12563个线程，每个线程栈平均大小128K：

1
128K * 12563 = 1570M = 1.5G的堆外内存

加上JVM的1.8G，就已经达到了3.3G，再加上kernel和日志传输进程等使用的内存数量，确实已经接近了4G，这样内存就对应上了！

物理机验证

登录原来物理机，发现同样有堆外内存泄露现象，其物理内存使用已经达到了5个多G。Dump了物理机上应用的线程：

1
一共有28737个线程，其中28626个线程等待在CachedBnsClient上。

同样用smaps查看进程实际内存信息，其平均大小依旧为128K。继续进行物理内存计算：

1
1.8 + (28737 * 128k)/1024K = (3.6 + 1.8) = 5.4G

进一步验证了我们的推理。

为什么没有卡顿

因为基本所有的线程都睡眠在：

1
Thread.sleep(60 * 1000); //一次睡眠60s

上，所以仅仅占用了内存，实际占用的CPU时间很少。

总结与工具清单

经验教训

现场信息越多越好：在排查Bug时，尽可能收集更多的现场信息
定量分析是关键：内存泄露需要用推测的模型进行定量分析
深入分析：当定量和实际对不上的时候，深挖下去，会发现不一样的风景

工具清单

JVM调优工具

jstat：JVM统计监控工具
1
jstat -gcutil [pid] 1s
jinfo：查看JVM运行时参数
1
jinfo -flags [pid]

jmap：内存映射工具

1
2
jmap -heap [pid]          # 查看堆信息
jmap -dump:format=b [pid] # Dump堆内存

jstack：线程堆栈工具
1
jstack [pid] > thread.txt

GC分析工具

GCViewer：可视化GC日志分析工具
GCEasy：在线GC日志分析平台
JConsole：JVM监控控制台
VisualVM：JVM性能分析工具

系统级分析工具

/proc/[pid]/smaps：查看进程内存详细使用情况
top：系统进程监控
free：内存使用情况
vmstat：虚拟内存统计

调优原则

明确目标：先确定延迟、吞吐量、容量三个目标的优先级
逐步优化：一次只调整一个参数，对比效果
充分测试：在生产环境变更前，在测试环境充分验证
监控先行：建立完善的监控体系，及时发现异常

最佳实践

避免过度调优：不是所有的应用都需要复杂的GC调优
关注业务指标：GC调优的最终目标是提升用户体验和业务价值
持续监控：建立长期的监控和告警机制
文档化：记录调优过程和结果，便于后续维护

通过这次堆外内存泄露的排查过程，我们不仅学会了具体的排查方法，更重要的是建立了系统性的问题分析思路。在复杂的系统中，任何一个看似简单的配置都可能引发严重的问题，唯有深入理解原理，才能快速定位和解决问题。