10 分钟掌握 Java 性能分析诀窍

概要

Java 性能分析是一门艺术和科学。科学指的是性能分析一般都包括大量的数字、测量和分析；艺术指的是知识、经验和直觉的使用。性能分析的工具或者手段各有千秋，但性能的分析的过程却都大相径庭。本文就已知适用的 Java 性能分析窍门进行一些分享，帮助用户更好的理解和运用。

窍门一：线程栈剖析

线程栈分析是对正在运行的 Java 线程的快照分析，是一种轻量级的分析手段，用户在不清楚应用存在什么性能问题的时候可优先尝试。虽然判定 Java 线程是否异常并没有统一的标准，但用户可以通过一些指标进行定量的评估。以下分享 4 个检测指标：

1)线程死锁检查线程死锁检查是一个非常有价值的检测指标。如果线程死锁，则一般存在系统资源的浪费或服务能力下降等问题，一旦发现就需要及时处理。线程死锁检测会展示线程死锁关系以及对应的栈信息，通过分析即可定位到触发死锁的代码。如图-1 所示死锁模型展示了一个复杂的 4 线程死锁场景。

2)线程统计检查状态统计是对运行的线程按照运行状态进行的统计和汇总。用户在不完全了解自己业务压力的情况下，对于可用线程数一般会配置一个非常充裕的范围，这样反而会因为过多的线程导致性能下降或者系统资源耗尽。如图-2 所示，可以发现超过 90%的线程处于阻塞和等待状态，那么适当优化线程数量是可以减少线程调度带来的开销以及不必要的资源浪费。

如图-3 所示，处于运行阶段的线程数已经超过 90%，进一步分析可能存在线程泄露的问题。同时，运行的线程太多，线程切换的开销也是非常大的。

3)线程 CPU 使用率检查对各 Java 线程 CPU 使用情况进行统计和排序，针对 CPU 使用率极高的线程线程栈进行分析，可以快速定位到程序热点。如图-4 所示，首个任务线程的 CPU 使用率达已经到 100%，则开发人员可根据业务逻辑确定是否进行代码优化。

4)GC 线程数检查 GC 线程数往往是容易被用户忽视的指标。用户在设置并行 GC 线程数的时候容易忽视系统的资源情况，或者随意将应用部署在 CPU 核数较多的物理机。如图-5 所示，我们发现在一个 4 核 8GB 的容器中 G1 的并发收集线程数为 9（一般情况下并行 GC 的线程数是 GC 任务线程数的 1/4），也就是在 GC 发生的时候可能会出现 9 个并行的 GC 线程，这种情况下 CPU 资源会被短时间直接耗尽而系统和业务阻塞。所以在使用 GC 收集器（如 CMS、 G1）的时候尽可能设置或者关注 GC 的线程数。

窍门二：GC 日志剖析

日志分析是对 Java 程序 GC 收集记录数据的分析，而这部分数据的收集是需要开启特定选项的。所以，在启动 Java 程序前一定要增加日志参数（如 JDK8：-Xloggc:logs/gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps；JDK11：-Xlog:gc*:logs/gc-%t.log:time,uptime）。GC 日志分析的结果描述的是在过去一段时间内 Java 程序就内存回收的状态。通过分析这些状态信息，用户可以非常方便的获得到 GC 参数甚至 Java 代码优化的指标数据。以下就 3 个分析指标进行展开：

1)GC 的吞吐率吞吐率描述的是在 JVM 运行时间段可用于业务处理的时间占比，即非 GC 占用时间。该值越大表示用户 GC 占用的时间越少，JVM 性能越好。JVM 内部指定该值不能低于 90%，否则 JVM 本身所带来的性能损耗就会严重影响业务性能。如图-6 所示是 JDK8 的 CMS 运行 3 小时左右的日志分析结果，分析结果显示其吞吐率超过 99.2%，JVM（GC）导致的性能损耗是比较低的。

2)暂停时间统计 GC 暂停时间指的是在 GC 过程中需要停止业务线程运行的时间，该时间需要在在一个合理的范围内。如果绝大部分的暂停时间超过预期（用户可以接受的范围），则很有需要去调整 GC 参数以及堆大小，甚至设置并行 GC 线程数。如图-7 所示，95%以上的 GC 暂停时间是在 40ms 以内；而超过 100ms 的暂停可能是导致业务请求时间毛刺的主要因素。为了消除暂停时间波动问题，可以选择如 G1 GC 或 ZGC，或者调整并行线程数或者 GC 参数等。

3)GC 阶段散点图散点图反映的是每一次 GC 操作释放的内存大小的分布情况。如图-8 所示，每次 GC 释放的内存大小基本一致，说明内存释放过程比较稳定。但如果出现比较大的波动或者出现比较多的 Full GC 则有可能是新生代区堆空间不足导致晋升量较大；如果每次 GC 的释放量比较少有可能是 G1 GC 自适应算法导致的新生代空间较小等等。因为散点图展示的数据有限，所以一般需要结合其它指标以及用户的 JVM 参数进行联合分析。

窍门三：JFR 事件剖析

JFR 是 Java Flight Record 的缩写，是 JVM 内置的基于事件的 JDK 监控记录框架。社区中，JFR 优先于 OpenJDK11 上发布，后移植到 OpenJDK8 的较高版本 260 上，且沿用了统一的使用接口与操作命令 jcmd。同时，由于 JFR 录制一般对应用影响很小（默认开启的性能影响在 1%以内），适合长时间开启；且 JFR 能收集到如 Runtime、GC、线程栈、堆、IO 等在内的丰富信息，非常方便用户了解 Java 程序的运行状况。JFR 录制的事件有 100 多种，如果程序复杂往往不到 10 分钟录制的 JFR 文件大小就会超过 500MB，所以用户在分析时往往并不是所有的信息都会关注。以下就业务性能中常见几个做一下分享：

1)进程 CPU 占用率 CPU 采样默认间隔是 1s，基本能及时反映当前进程的 CPU 平均使用情况。在出现 CPU 持续偏高，或者 CPU 出现类似图-9 所示的 CPU 偶发飙高的情况时，都可以进行一定的检测和分析。通过进一步定位，此处 CPU 飙高与 GC 触发时间一致，初步确认是 GC 导致的 CPU 变化。

2)GC 配置及暂停分布 GC 配置可以帮助我们了解到当前进程的 GC 收集器及其主要的配置参数，因为不用的收集器特性会不同，分析堆空间、触发控制等参数也是非常重要的。控制参数可以帮助我们理解 GC 收集过程，比如图-10 所示的 G1 收集器，设置的最大堆为 8GB，GC 暂停时间在 40ms 左右（默认预期 200ms），是远低于预期值的。进一步分析参数发现设置了 NewRatio 值为 2（对 G1 GC 不太熟悉的情况下，用户很容易设置该参数），导致新生代区的 GC 触发频繁，而且从数据看未触发混合 GC。为了增加对堆空间的利用，可以移除 NewRatio 参数，增加新生代区的最大值比例（因为未触发混合 GC，说明堆回收时晋升量非常低），降低回收块的回收门槛等，进而增加对整堆的使用。通过优化，堆空间的使用从原来的 4GB 提高到 7GB，YGC 频率从 20s/次提高到平均 40s/次，GC 暂停时间没有明显变化。

3)方法采样火焰图方法火焰图是对调用方法采样次数的统计，比例越大表示调用次数越多。因为采样过程中有栈的完整信息，对于用户来说是非常比较直观的，性能优化的帮助性大增。如图-11 所示，可以很清楚的看到 GroupHeap.match 执行次数比例接近 30%，可以作为性能优化点。

4)IO 读写性能检查 IO 性能多半是对程序处理性能出现突变的场景，比如下降或飙升。如从 socket 读入的数据量飙升，导致处理业务的 CPU 飙高；或者因为需要写出的数据变多，导致业务线程阻塞，处理能力下降等。如图-11 所示，可以通过读取/写入趋势图判断在监控时间段的 IO 能力。

窍门四：堆内容剖析

堆内容分析是分析 Java 堆 OOM（OutOfMemoryError）原因的常用手段。OOM 主要有堆空间溢出、元空间溢出、栈空间溢出和直接内存溢出等，但并不是所有溢出情况都可以通过堆内容分析获得。对于堆转储的文件而言，内存溢出的可能性是不确定的，但可以通过一些定量的指标或者约定的条件作出判断，再通过开发或者测试人员进行最后的确认。以下分享三个有价值的衡量指标：

1)大对象检查统计大对象分布信息可以帮助我们了解内存消耗在这部分对象上的比重，以及存在的大对象是否合理。过多的大对象无法释放会更快的耗尽内存而出现 OOM，相比全量的分析所有对象而言，大对象的检查是具有代表性的，如图-13 所示。

2)类加载检查类加载统计主要统计的是程序当前加载的全部类信息，是计算元空间占用的重要数据。过多的加载类信息也会导致元空间被大量占用，在类似 RPC 场景下，缓存加载类信息是容易触发 OOM 的。

3)对象泄露检查首先引入三个概念；浅堆：一个对象所占用的内存大小，和对象的内容无关，只和对象的结构有关。深堆：一个对象被 GC 回收后，可以真实释放的内存大小，即通过该对象访问到的所有对象的浅堆之和（支配树）。支配树：在对象的引用图中，所有指向对象 B 的路径都经过对象 A，则认为对象 A 支配对象 B；如果对象 A 是离对象 B 最近的一个支配对象，则认为对象 A 为对象 B 的直接支配者。按照 GC 策略，堆中的对象只可能有两种状态，一种是通过 GC 的根可达的对象；另一种是通过 GC 根不可达的对象。不可达的对象会被 GC 收集器回收，对应的内存就会返回到系统中去。而可达对象都是被用户直接或者间接引用的对象，所以对象泄露针对的就是被用户间接引用但永远不会被使用的对象，这些对象因为被引用而无法释放。对象泄露不是绝对的，而是相对的，一般没有确切的标准，但可以通过对对象的深堆大小进行评估。比如检测到 HashMap 存放了 4844 个对象（如图-14 所示），计算 HashMap 浅堆约 115KB，看到这里可能觉得没有什么问题；但通过计算对象的深堆发现其超过 500MB。这种情况下，如果无法释放 HashMap 而持续增加新的键值就有可能导致堆内存耗尽而出现 OOM。

作者简介：

Nianwu，高级后端工程师

主要负责 Java 性能平台和 JDK 支持，对缺陷检查和编译器也有深入研究。

获取更多精彩内容，请关注[OPPO 互联网技术]公众号