Java飞行记录器(Flight Recorder)的用法

Java Flight Recorder(JFR)是一款商业软件,能够在台式机/笔记本电脑上免费使用它,对测试、开发和生产环境中的程序进行评估。

要在生产服务器上启用JFR ,需要商业许可证。在JDK上将JMC UI用于其他目的不需要商业许可证。典型的开销只有2%左右,因此,绝对可以在生产环境中运行分析记录(这是JFR的主要用例之一),除非对性能或延迟非常敏感。

JFR记录类型

以下是两种类型的飞行记录 - 连续记录和分析记录。

连续录制:连续录制是一种始终开启并保存的录制,例如,最近六小时的数据。如果应用程序遇到任何问题,可以从最后一小时转储的数据中,查看问题发生时的情况。

连续录制的默认设置,是使用开销极低的录制配置文件。此配置文件不会获得堆统计信息,或分配配置文件,但仍会收集大量有用的数据。

连续录制非常适合长期运行,并且,在调试极少发生的问题时非常有用。可以使用jcmd或JMC手动转储录制。还可以在JMC中设置触发器,以在满足某些特定条件时转储飞行记录。

分析记录:分析记录为打开后,运行一段时间,然后,停止的记录。通常,配置文件记录会启用更多事件,并且,可能会对性能产生更大的影响,根据对分析记录的使用情况,来修改打开的事件。

如何制作飞行记录

使用Java Mission Control生成飞行记录,Java Mission Control(JMC)能够轻松管理飞行记录。首先,在最左边的JVM浏览框中找到正在运行的服务,如图2-1 所示。

jmc-event

默认情况下,将列出本地运行的JVM,必须将远程JVM(作为与运行JMC的用户相同的有效用户运行)设置为使用JMX远程代理,然后,单击“ 新建JVM连接”按钮,并输入网络详细信息。

在JDK 8u40发布之前,JVM必须开启标志位:-XX:+UnlockCommercialFeatures -XX:FlightRecorder。自JDK 8u40发行版以来,可以在运行时启用Java Flight Recorder。以下是使用Java Mission Control生成飞行记录的三种方法。

检查正在运行的记录:在JVM浏览器中展开节点,以查看正在运行的记录。图2-2显示了正在运行的连续记录(带有无穷大符号)和定时分析记录。图2-2 Java Mission Control - 运行录制

图2-2 Java任务控制 - 运行记录的说明,右键单击记录文件以转储,编辑或停止录制,停止分析记录仍将产生记录文件,关闭分析记录则将记录丢弃。

转储连续录制:右键单击JVM浏览器中的连续录制,然后,选择将其转储到文件中。在出现的对话框中,选择转储所有可用数据,或仅转储录制的最后部分,如图2-3所示。

图2-3 Java任务控制 - 转储连续记录


“图2-3 Java任务控制 - 转储连续录制”的说明,开始新记录:要开始新记录,右键单击要录制的JVM,然后,选择开始录制,将显示一个窗口,如图2-4所示。

图2-4 Java任务控制 - 开始飞行记录


“图2-4 Java任务控制 - 开始飞行记录”的描述,选择时间固定录制(配置文件录制)或连续录制,如图2-4所示。对于连续录制,还可以指定要保存的事件的大小或年龄。

也可以选择“ 事件设置”,选择创建自己的模板,但对于99%的用例,通常会选择连续模板(用于非常低开销的录制)或分析模板(用于更多数据和更多开销)。

注意:分析记录的开销通常大约在2%。完成后,单击“ 下一步”,(如图2-5所示)给了修改用例模板默认值的机会。图2-5 Java Mission Control - 用于分析的事件选项


“图2-5 Java Mission Control - 用于分析的事件选项”的描述,默认设置可在数据和性能之间取得良好的平衡,在某些情况下,希望添加额外的事件。如:正在排查内存泄漏,或想要查看占用最多Java堆的对象,要启用堆统计信息。这将在记录的开始和结束时触发两个old GC,因此,这会产生一些额外的延迟,选择显示抛出的异常,甚至是捕获的异常。对于某些应用程序,这会生成更多的事件。

阈值是记录事件的长度,默认情况下,会收集同步超过10毫秒的事件,如果某个线程等待锁定的时间超过10毫秒,则会生成一个事件并记录下,可以降低此值,以获得竞争时间较短的详细数据。

线程转储设置,可以选择做定期的线程转储,将是正常的文本线程转储,如:使用诊断命令获得的Thread.print,或使用jstack工具,线程转储补充事件。

在命令行中启动标志生成飞行记录,有关JFR标志的完整说明,参阅高级运行时选项。下面是在命令行中启动标识位,以产生飞行记录的三种方法。

开始分析记录

可以使用-XX:StartFlightRecording选项在应用程序开始时配置时间。由于JFR是商业功能,因此必须指定-XX:+UnlockCommercialFeatures选项。

以下示例说明了如何在MyApp启动20秒后开启记录,记录时间为60秒,该记录将保存到名为myrecording.jfr的文件中:

java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:StartFlightRecording=delay=20s,duration=60s,name=myrecording,filename=C:\TEMP\myrecording.jfr,settings=profile MyApp

settings参数采用模板的路径或名称。默认模板位于jre/lib/jfr文件夹中。这两个标准配置文件是:

默认 - 主要用于连续录制和配置文件的低开销设置

收集更多数据,用于分析记录。

开始连续录制

可以在命令行使用-XX:FlightRecorderOptions开始连续录制,这些标识位会开启连续录制,可以根据需要转储。以下示例说明了连续录制,临时数据将保存到磁盘的/tmp文件夹,并存储最近6小时的数据。

java -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=defaultrecording=true,disk=true,repository=/tmp,maxage=6h,settings=default MyApp

使用诊断命令

还可以使用Java命令行,诊断命令控制录制,执行诊断命令的最简单方法是:使用位于Java安装目录中的jcmd工具

使用触发器进行自动记录

可以将Java Mission Control设置为,在满足条件时自动启动/转储飞行记录,这是从JMX控制台完成的,要启动JMX控制台,在JVM Browser中找到应用程序,右键单击它,然后,选择Start JMX Browser。选择屏幕底部的Triggers选项卡,如图2-6 所示 Java Mission Control - 自动录制:


“图2-6 Java任务控制 - 自动录制”的说明。可以在应用程序中的任何位置选择MBean创建触发器,设置了几个常见条件作为默认触发器,例如高CPU使用率,死锁线程或过多的垃圾收集。选择在应用程序中Add一个MBean触发器时,可以选择必须满足的条件,有关详细信息,单击右上角的问号以查看内置帮助。

单击触发器旁边的框以运行多个触发器。选择条件后,单击“ 操作”选项卡,然后,选择满足条件时要执行的操作,最后,选择转储连续记录/开始限时飞行记录,如图2-7所示 :


如何获取JFR样本以进行调查

创建Flight Recording后,可以在Mission Control中打开它,查看飞行记录的简便方法是:

打开Mission Control并选择JVM Browser选项卡。选择“JVM运行任务控制”选项以创建短记录。另一种方法是下载演示和示例,并打开\missioncontrol\flightrecording \中的一个示例记录,wldf.jfr是来自应用服务器的一个示例记录,在下面的部分中将作为示例使用。

打开飞行记录以查看几个主要选项卡,例如常规、内存、代码、线程、I/O,系统和事件,如果安装了插件,还可以使用其他主选项卡,每个主标签下都有子标签,单击问号以查看主选项卡和子选项卡的内置帮助。

范围导航器

每个选项卡在顶视图中都有一个范围导航器。图2-8检查飞行记录 - 范围导航器

图2-8中的垂直条表示录制中的事件,峰值越高,当时的事件就越多,可以拖动所选时间的边缘,以放大或缩小录制内容,双击范围导航器可缩小并查看整个录制内容,单击所有子选项卡的“ 同步选择”复选框,以使用相同的缩放级别。有关详细信息,参阅内置帮助中的范围导航器的使用。

常规选项卡

“常规”选项卡包含一些描述常规应用程序的子选项卡,第一个子选项卡是Overview,它显示了一些基本信息,如堆最大使用率,总CPU使用率和GC暂停时间,如图2-9 所示:

另外,查看一段时间内的CPU使用情况,以及应用程序使用情况和机器总数,当应用程序中出现问题时,此选项卡就变得很有用。例如,关注CPU使用率接近100%或CPU使用率过低,过长的垃圾收集暂停时间。

其他子选项卡 - JVM Information显示JVM信息。启动参数子选项卡 - “ 系统属性”,显示所有系统属性设置,“ 记录”显示有关特定记录的信息,例如:打开的事件。单击问号以获取有关所有选项卡和子选项卡的内置详细信息。

内存选项卡

“内存”选项卡包含有垃圾收集、分配模式和对象统计信息,此选项卡有助于调试内存泄漏及调整GC。图2-10检查飞行记录 - 垃圾收集

如图2-10所示,堆使用的尖峰模式完全正常。在大多数应用程序中,始终分配临时对象,满足条件后,将触发垃圾收集(GC)并删除不再使用的对象。因此,堆使用量会稳定增加,直到GC被触发,然后突然下降。

Java中的大多数GC都有一些较小的垃圾收集,old GC遍历整个Java堆,而另一个GC可能会查看堆的一部分,old GC后的堆使用情况,是应用程序正在使用的内存。

启用堆统计信息生成的飞行记录,将以old GC开始和结束。在GCs列表中选择old GC,然后,选择General选项卡,以查看GC原因——堆检查启动GC。这些GC通常比其他GC要稍长一些。为了更好地处理内存泄漏,请查看第一个和最后一个old GC之后的堆。当这个值随时间增加时,可能存在内存泄漏。

“GC时间”选项卡包含有关执行GC所花费的时间,以及应用程序因GC而完全暂停的时间信息。该GC配置选项卡有GC的配置信息。有关这些选项卡的更多详细信息,请单击右上角的问号以查看内置帮助。

分配选项卡: 图2-11显示了内存分配选项,Java中的小对象在TLAB(线程局部区域缓冲区)中分配。TLAB是一个分配新对象的小内存区域。一旦TLAB满了,线程就会创建一个新的,所有触发新TLAB的分配都被记录下来。在TLAB之外分配较大的对象,这些对象也被记录下来。图2-11检查飞行记录 - 分配选项卡


要估计每个类的内存分配,在“新TLAB”选项卡中选择“分配”,然后,选择“分配”选项卡。这些分配是碰巧触发新TLAB的对象分配,char数组引发了最多的新TLABs,分配多少内存作为char数组是未知的,TLAB的大小是对char数组内存分配的估计。

图2-11是char数组的最大内存分配示例,单击其中一个类,以查看这些分配的堆栈跟踪。示例记录显示,44%的分配压力来自char数组,27%来自Array.copyOfRange,StringBuilder.toString依次调用Throwable.printStackTrace和StackTraceElement.toString,展开进一步以了解这些方法是如何调用的。

注意:应用程序分配的临时对象越多,应用程序必须垃圾回收的越多。“分配”选项卡可帮助找到最多的分配,并降低应用程序中的GC压力。查看TLAB选项卡外的Allocation,以查看大内存分配,这通常比New TLAB选项卡中的分配,具有更少的内存压力。

“对象统计”选项卡

“对象统计”选项卡显示实时收集最多的类。从Memory选项卡中读取Garbage Collection子选项卡以了解实时GC。图2-12显示了用于飞行记录的堆统计信息。启用飞行记录的堆统计信息以显示数据,底部的“Top Growers”选项卡,显示了在飞行记录期间每种对象的增加情况,特定类型对象的数量增加,通常表示存在内存泄漏,但一个小的变化是正常的,特别是,研究非标准的Java类的top growers。图2-12检查飞行记录 - 对象统计选项卡

代码选项卡

Code选项卡包含有关应用程序,在何处花费大部分时间的信息,在概述子选项卡显示,花费最多执行时间的包和类。这些数据来自抽样,JFR采用间隔运行的线程样本。只对实际运行代码的线程进行抽样,不会显示正在休眠、等待锁或I/O的线程。要了解应用程序时间的更多详细信息,可以查看Hot Methods子选项卡。图2-13检查飞行记录 - 代码选项卡

图2-13显示了采样次数最多的方法,展开这些示例,以查看调用它们的位置。如果一个HashMap.getEntry调用很多,然后展开这个节点,直到找到调用最多的方法。这是用于查找应用程序瓶颈的最佳选项卡。

“Call Tree”子选项卡:显示相同的事件,但从底部开始,例如,来自Thread.run。

Exceptions子选项卡:显示发生的异常,默认情况下,只记录错误,但在启动新记录时更改此设置以包含所有异常。

Compilations子选项卡:显示应用程序运行时实时编译的方法。

Class Loading选项卡:显示已加载的类的数量、实际加载的类和随时间推移的卸载类,此子选项卡仅包含在录制开始时,启用“Class Loading”事件时所显示的信息。

有关这些选项卡的更多详细信息,请单击右上角的问号以查看内置帮助。

线程选项卡

“线程”选项卡包含有关线程,锁争用和其他延迟的信息。

Overview 子选项卡:显示了CPU的使用情况和随着时间推移的线程数量。

Hot Threads子选项卡:显示执行大部分代码的线程,此信息与Code选项卡中的Hot Methods子选项卡使用相同的抽样数据。Contention争用标签对于找到瓶颈非常有用。图2-14检查飞行记录 - 争用选项卡:

图2-14显示了由于同步而最等待的对象。选择一个Class以查看每个对象的等待时间的堆栈跟踪,这些暂停通常由同步方法引起。注意:默认情况下,仅记录长度超过10毫秒的同步事件,但可以在开始录制时设置此阈值。

Latencies 子选项卡:显示其他延迟源,例如,调用sleep或wait、从socket读取或等待文件I/O。

Thread Dumps 子选项卡:显示可以在记录中触发的周期性线程转储。

Lock Instances 子选项卡:显示由于同步而等待最多的对象。

有关这些选项卡的更多详细信息,单击右上角的问号以查看内置帮助。

 I/O选项卡

在I/O选项卡中显示了文件读取,文件写入,socket读取,socket写入信息。这个选项卡根据应用程序的不同而有所帮助,特别是I/O操作时间很长时。

注意:认情况下,只显示大于10毫秒的事件,在创建新记录时可以修改阈值。

系统选项卡

“System”选项卡:提供有关运行应用程序的计算机的CPU,内存和操作系统的详细信息。它还显示环境变量,以及与JVM同时运行的其他进程。

事件选项卡

“Events”选项卡:显示录制中的所有事件,这是一个高级选项卡,能够以多种方式使用。有关这些选项卡的更多详细信息,单击右上角的问号以查看内置帮助。