Java Flight Recordings (JFR) — part 2 用 JFR 定位性能问题

内容目录

• JFR 概览
• 找出瓶颈
• GC 性能
• 同步性能
• I/O 性能
• 代码执行性能

一、JFR 概览

二、找出瓶颈

不同的应用有不同的瓶颈。对于有些应用，瓶颈可能是等待 I/O 或网络，可能是线程之间的同步，或者是实际的 CPU 使用。对于其他，瓶颈可能是 GC 时间。很可能应用有不止一个瓶颈。

找出应用瓶颈的一个方法是查看 Events 选项卡。这是一个高级选项卡，可以做不少事情。如下图，可以选择自己感兴趣的事件：

生成的结果图示：

在“Graph”选项卡里，每一行是一个线程，每个线程可以有多行。在上图中，每个线程都有一行，表示 Java 应用程序的时间，在 “Event Types”选项卡里允许录制的。被选中的 Java 应用程序事件都有个重要的属性是线程失速事件。线程失速表明线程在事件期间没有运行你的应用程序，它们是持续事件。持续事件测量了应用程序没有运行的期间。

从“Event Types” 选项卡里每种颜色对应不同的事件。

Java Monitor Wait 事件表示线程在对象上等待，这通常意味着线程空闲，可能在等待任务；
如果 Java 应用程序的重要线程花费很多时间在阻塞上，表明应用的关键区域是单线程的，是个瓶颈。
花费时间越多的事件越可能是瓶颈。

绿色部分表示线程没有睡眠、等待、读或写套接字，也没有被阻塞。通常这是线程在允许应用代码。如果 Java 应用的重要线程花费大量时间而没有生成任何应用事件，那么应用的瓶颈可能代码或 CPU 自身。

注意：对于大多数 Java 应用事件类型，只有超过 20 ms 的事件将被记录（这个阀值可以在启动飞行记录时修改）。没有记录事件的区域可能是因为应用在做大量的短任务，例如读写文件（每次一小部分）或做很短时间的同步。

事件选项卡没有显示 GC 和 GC 是否可能成为瓶颈。

三、GC 性能

调优 HotSpot 垃圾收集器可以对性能有很大影响。更多信息见 Garbage Collection Tuning Guide。

启动飞行记录时最好不好包括堆统计，因为这会触发额外的年老代收集。为了得到更好的抽样，让记录时间尽量长。

选择 “Memory” 选项卡然后选择“GC Times”子选项卡。GC Times 是调查 GC 整体性能影响的很好选项卡。在右上角，看“All Collections Pause Time”区域的“Average Sum of Pauses”, “Maximum Sum of Pauses”, “Total Pause Time” 的记录。“Sum of Pauses” 是应用在 GC 期间暂停的所有时间。很多 GC 在后台做大部分工作，在这些情况下，GC 的长度不要紧，要紧的是应用必须停止多长时间。因此“Sum of Pauses”是对 GC 影响的很好衡量。

下图展示了 5 分钟的飞行记录，在这个时间内，暂停的平均时间是 16 ms，最大暂停时间是 49 ms，总的暂停时间是 2秒86毫秒。

通常，GC 的主要性能问题要么单次 GC 花了很长时间，要么是 GC 暂停花了很多时间（总的GC暂停）。

当单次 GC 花了太长时间时，你可能需要改变 GC 策略。不同的 GC 有不同的权衡，在暂停时间和吞吐量性能之间。更多信息见 Behavior-Based Tuning。

例如，你可能需要修复你的应用以减少使用 finalizer 和/或 semi-references。

当应用花了很多时间在暂停上时，有多种方法可以变通。

一种方法是增加 Java 堆的大小。在“Garbage Collection”子选项卡估计应用使用的 Java 堆大小，加大 Xms 和 Xmx 的值。Java 堆越大，GC 时间越长。小心 Java 应用的任何内存泄露，因为那可能导致更频繁的 GC 直至抛出 OutOfMemoryError。更多信息见 Debug a Memory Leak Using Java Flight Recorder。

另一种方法，为了减少 GC 次数，分配更少的临时对象。在“Allocation”选项卡，查看在记录过程中已分配了多少内存。小对象是在 TLAB 内分配，大对象在 TLAB 外分配。经常，主要的分配发生在 TLAB 内。

最后但不是最少的减少 GC 需要的方法是减少分配频率。选择“Alloc in new TLAB”选项卡，然后选择“Allocations”选项卡，查看分配的大小和有最多内存压力的栈轨迹。你可以按类查看，也可以选择“Allocation by Thread”来看哪个线程消耗了最多分配。

更多关于 JFR Allocation 选项卡的细节见 Inspect a Flight Recording。

其他的一些设置可能也增加应用的 GC 性能。 Garbage Collection Tuning Guide 章节大部分都是讨论 GC 性能的。

四、同步性能

为了调试 Java 应用的同步问题，或者说是应用线程在哪里花了最多的时间来进入监视器，查看”线程“选项卡组的 “争用”选项卡。看看哪些锁上的竞争最多和 等待获得锁的线程的栈轨迹。如下图：

上图的范围选择让你可以看到事件在哪里发生。在选中时间范围内放大范围选择器来查看竞争事件。

典型地，查找你不认为是问题的竞争可能是个问题。有的应用，日志是不被认为是应用瓶颈的常见区域。

当你程序更新或应用的任何时间看到性能退化，在事情还好的情况下获得一个记录，在事情看起来不好时获取另一个记录（，做对比）。

注意：在范围选择器里显示的事件不是所有的同步事件。默认地，竞争事件的持续时间超过 20 ms 才会被记录（这个阀值在开启记录时可以修改）。缩短这个阀值会得到更多的事件，也潜在地带来更多的开销。如果你认为竞争是个问题，你可以缩短记录的时间，设置很小的阀值（仅仅几毫秒）。当这些在存活应用上完成时，确保记录时间很短并监视性能开销。

五、I/O 性能

当 Java 应用花了大量时间在读写套接字或文件上时，那么 I/O 或网络可能是瓶颈。

上图显示了应用有 100 个对远程地址 198.51.100.0 的读操作。读取的总字节数是 356 字节，用于等待的总时间是 1 分 57 秒。选择左上角的 “By Event” 选项卡查看每个事件来分析花费的时间和读取的数据。

文件或网络 I/O 问题的诊断用同样的方式。

在 I/O 里的所有选项卡默认显示持续时间超过 20ms 的事件，可以在启动时调整阀值。

六、代码执行性能

当没有很多 Java 应用事件时，主要的瓶颈可能在你的应用运行代码上。首先，在“the Threads”选项卡选择“Overview”选项卡，看 “CPU Usage Over Time”。这显示了记录下的 JVM CPU 使用情况和机器的总的 CPU 使用情况。如果 JVM CPU 使用低，但机器的 CPU 使用高，这意味着其他应用占用了很多 CPU。然后在“System”选项卡组的“Processes”选项卡查看系统里其他应用。然而，你可能看不到它们的 CPU 使用情况，所以，通常用 OS 的工具如 top 或任务管理器来找出使用了很多 CPU 的进程。

选择“Code”选项卡组，查看“Hot Threads”选项卡以防你的应用使用了很多 CPU 时间。这个选项卡显示了使用 CPU 时间最多的线程。然而，这个信息是基于方法抽样的，因此这可能不是百分百精确的，如果抽样数量低。当 JFR 运行时，JVM 抽样线程。默认地，一个持续记录只进行方法抽样，而一个性能记录会尽可能多做。方法抽样只收集实际运行代码的线程的数据。这些等待 I/O、睡眠、等待锁等是不会被抽样的。因此，因此，有很多方法抽样的线程是使用 CPU 时间最多的；然而，每个线程使用了多少 CPU 是不知的。

“Code”选项卡组里的“Hot Methods”选项卡帮助找出应用在哪里花了最多的执行时间。这个选项卡显示了栈里按顶层方法分组的抽样。用“Call Tree”选项卡，从栈轨迹的最低端方法开始，然后向上。