Java Flight Recorder飞行记录器用法图解(官方文档译)

Java Flight Recorder是JVM内置的记录引擎,能收集JVM和Java应用数据,帮助开发者诊断分析Java应用。

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

生产服务器使用JFR ,需要商业许可证。

开销约2%左右,可在生产环境中开启,除非对性能或延迟非常敏感。

记录类型

JFR飞行记录分两种:连续记录、分析记录。

连续录制

默认模式。始终开启并保存录制,应用程序遇到任何问题,从最后一小时转储数据中查看问题现场。

使用开销极低的录制配置项。配置项中不包括获得堆统计信息,但仍有大量有用数据。

连续录制适合长期运行,调试极少发生的问题。

可使用jcmd或JMC手动转储录制。

也可在JMC中设置触发器,在条件满足时转储飞行记录。

分析记录

打开后运行一段时间,然后,停止的记录。

通常,此模式配置文件会启动更多事件,会对性能产生影响,根据分析所需调整开启事件。

制作飞行记录

使用Java Mission Control生成飞行记录。

首先,在左侧JVM浏览框中找到正在运行的应用,如图所示:

jmc-event

默认列出本地运行的JVM。远程JVM需设置为使用JMX远程代理,单击“ 新建JVM连接”按钮,输入网络连接信息。

JDK 8u40发布前,JVM须开启标志位:

-XX:+UnlockCommercialFeatures
-XX:FlightRecorder

JDK 8u40以后能在运行时启用Java Flight Recorder。

使用Java Mission Control生成飞行记录的三种方法。

检查正在运行的记录

在JVM浏览器中展开节点,查看正在运行的记录。

下图显示了正在运行的连续记录(带有无穷大符号)和定时分析记录。

右键记录文件以转储、编辑或停止录制,停止分析记录仍将产生记录文件,关闭分析记录则将记录丢弃。

转储连续录制

右键JVM浏览器中的连续录制,选择将其转储到文件中。

在出现的对话框中,选择转储所有可用数据或仅转储最后录制数据,如下图所示:

开始新记录

右键要录制的JVM,选择开始录制,如下图所示:

选择时间固定录制或连续录制,如图2-4所示。

连续录制可指定要保存的事件年龄或大小。

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

注:分析记录开销大约为2%。完成后,点击“ 下一步”,如下图所示,有机会修改用例模板默认值。

默认设置可在数据和性能间取得良好平衡。

某些情况下,希望添加额外的事件,如:排查内存泄漏。

查看对堆内存占用最多的对象要启用堆统计信息。

这将在记录开始和结束时触发两个old GC,因此,会产生一些额外延迟,可选择显示抛出异常,甚至是捕获异常。

对于某些应用程序,这会生成更多事件。

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

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

在命令行中启动标志生成飞行记录,有关JFR标志的完整说明,参阅高级运行时选项。

下面是在命令行中启动标识位,以产生飞行记录的三种方法。

开始分析记录

-XX:StartFlightRecording

此选项在应用开始时配置。

JFR是商业功能,须指定如下选项:

-XX:+UnlockCommercialFeatures

示例:

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

说明:

MyApp启动20秒后开启记录,记录时间为60秒,记录将保存到名为myrecording.jfr文件中。

settings参数采用模板的路径和名称。

默认模板位于jre/lib/jfr文件夹中,有两个标准配置文件:

1、连续录制和低开销设置的配置文件。

2、收集更多分析记录数据的配置文件。

开始连续录制

-XX:FlightRecorderOptions

标识位会开启连续录制,根据需要转储。

示例:

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

说明:

连续录制,临时数据保存在磁盘的/tmp文件夹,存储最近6小时的数据。

使用诊断命令

执行诊断命令最简单方法:

使用位于Java安装目录的jcmd工具

使用触发器自动记录

将Java Mission Control设置为满足条件时自动启动/转储飞行记录,通过JMX控制台完成。

启动JMX控制台:

在JVM Browser中找到应用程序,右键选择Start JMX Browser。

选择屏幕底部Triggers选项卡,如下图所示:

在应用程序任意位置选择MBean创建触发器。

示例中设置了几个常见条件作为默认触发器,如:高CPU使用率、死锁线程、jvm GC过于频繁。

在应用程序中添加一个MBean触发器时,选择满足的条件,有关详细信息,点击右上角问号查看内置帮助。

点击触发器旁边的框以运行多个触发器。

选择条件后,点击“操作”选项卡,选择满足条件时执行的操作。

最后,选择转储连续记录/开始限时飞行记录,如下图所示 :

获取JFR样本数据

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

打开Mission Control选择JVM Browser选项卡,选择“JVM运行任务控制”选项以创建短记录。

另一种方法是下载演示示例,打开\missioncontrol\flightrecording \中的示例记录,wldf.jfr是来自应用服务器的一个示例记录,在后续部分将作为示例使用。

打开飞行记录查看几个主要选项卡,如:常规、内存、代码、线程、I/O,系统和事件。

如果安装了插件,也可使用其他主选项卡,每个主标签下都有子标签,点击问号查看主选项卡和子选项卡内置帮助。

范围导航器

每个选项卡在顶部视图中都有一个范围导航器,如下图所示:

图2-8中的垂直条表示录制中的事件,峰值越高,表示当时的事件越多。

拖动所选时间的边缘,以放大或缩小录制内容,双击范围导航器可缩小并查看整个录制内容,点击所有子选项卡的“同步选择”复选框,以使用相同的缩放。

详细信息参阅内置帮助中的范围导航器用法。

常规选项卡

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

另外,可查看一段时间内的CPU使用情况,应用程序使用情况及机器总数。

当应用程序出现问题时,此选项卡就变得很有用。如:CPU使用率接近100%,或CPU使用率过低,过长垃圾收集暂停时间。

其他子选项卡 - JVM Information显示JVM信息。

启动参数子选项卡 - “系统属性”,显示所有系统属性设置,“记录”显示有关特定记录的信息,如:打开的事件。

点击问号获取内置详细信息。

内存选项卡

“内存”选项卡包含:垃圾收集、分配模式、对象统计信息。

此选项卡有助于调试内存泄漏和GC,如下图所示:

图中堆使用的尖峰模式完全正常。

大多数应用程序,始终分配临时对象,满足条件后触发垃圾收集并删除不再使用的对象。

堆使用量会稳定增加,直到GC被触发,然后突然下降。

Java中大多数GC都是一些小规模垃圾收集操作,old GC会遍历整个Java堆。

其他GC只查看堆的一部分,old GC后的堆使用情况是应用程序正占用的内存。

启用堆统计信息生成的飞行记录,将以old GC开始和结束。

在GCs列表中选择old GC,选择General选项卡,以查看GC原因。

这些GC通常比其他GC要稍长一些。

为更好地处理内存泄漏,可查看第一个和最后一个old GC后的堆使用情况。当这个值随时间增加时,可能存在内存泄漏。

“GC时间”选项卡包含有关执行GC所花费的时间,以及应用程序因GC完全暂停的时间信息。

该GC配置选项卡包含GC的配置信息。

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

分配选项卡

下图中显示了内存分配选项,Java中小对象在TLAB中分配。

TLAB是一个分配新对象的小内存区域。

一旦TLAB占满,线程就会创建一个新的。

所有触发新TLAB分配的事件都被记录下来。

在TLAB之外分配较大的对象,这些对象也被记录下来。

评估每个类的内存分配,在“新TLAB”选项卡中选择“分配”,然后,选择“分配”选项卡。

图中char数组引发了最多的新TLABs,分配多少内存作为char数组是未知的,TLAB大小是对char数组内存分配的估计。

图中是char数组的最大内存分配示例,单击其中一个类,查看这些分配的堆栈跟踪。

示例记录显示:44%的分配压力来自char数组,27%来自Array.copyOfRange,

StringBuilder.toString依次调用Throwable.printStackTrace和StackTraceElement.toString,展开可了解这些方法的调用链。

注:应用程序分配临时对象越多,应用程序须回收的垃圾也越多。

“分配”选项卡可帮助查找到分配最多的类,以降低应用的GC压力。

查看TLAB选项卡外的Allocation,以查看大内存分配,相比New TLAB选项卡中的分配,它对内存的压力会小很多。

“对象统计”选项卡

“对象统计”选项卡显示实时收集最多的类。

从Memory选项卡中读取Garbage Collection子选项卡,以了解实时GC。

下图中显示了飞行记录统计的堆信息。

启用飞行记录的堆统计信息以显示数据,底部“Top Growers”选项卡,显示了在飞行记录期间每种对象的增加情况,特定类型对象数量增加,通常表示存在内存泄漏,但个小范围的变化是正常的,特别是研究非标准Java类的top growers。

代码选项卡

Code选项卡包含了应用程序在何处花费了大量时间。

在概述子选项卡中显示花费最多执行时间的包和类。

这些是抽样数据,JFR采用间隔运行的线程样本。只对实际运行代码的线程执行抽样,不会显示正在休眠、等待锁或I/O的线程。

了解应用程序时间的更多详细信息,可查看Hot Methods子选项卡。

图中显示采样次数最多的方法,展开示例,查看调用它们的调用链。

如果一个HashMap.getEntry调用很多次,展开这个节点,直到找出调用最多的方法。这是用于查找应用程序瓶颈的最佳选项卡。

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

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

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

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

有关这些选项卡的更多信息点击问号查看帮助。

线程选项卡

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

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

Hot Threads子选项卡:显示执行大部分代码的线程,此信息与Code选项卡中Hot Methods子选项卡,使用相同的抽样数据。

Contention争用标签对找出瓶颈非常有用,如下图所示:

图中显示了因同步而最等待的对象。

选择一个Class以查看每个对象的等待时间及堆栈跟踪,这些暂停通常由同步方法引起。

注:默认仅记录长度超过10毫秒的同步事件,可在开始录制时调整此阈值。

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

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

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

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

I/O选项卡

在I/O选项卡中显示文件读取和写入,socket读取和写入。此选项卡根据应用程序不同而有所不同。

注:默认只显示大于10毫秒的事件,可在创建新记录时调整阈值。

系统选项卡

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

事件选项卡

“Events”选项卡:显示录制中的所有事件是一个高级选项卡,能以多种方式使用。有关详细信息查看内置帮助。