大水怪

一只专注技术的水怪

0%

JFR实战教程

本文基于JDK11,对于jdk14的 JFR Event Streaming 以及JDK16引入的 jdk.ObjectAllocationSample 事件等不作过多讨论

什么是JFR

JFR是 Java Flight Record(前身是JRocket Flight Record),是 JVM 内置的基于事件的JDK监控记录框架。这个起名就是参考了黑匣子对于飞机的作用,将Java进程比喻成飞机飞行。顾名思义,这个记录主要用于问题定位和持续监控。

官方描述 https://openjdk.org/jeps/328

JFR基于事件思想的起源 https://openjdk.org/jeps/167

JFR事件大全

JFR是一个开销不超过1%(对比profiler官方声称对系统影响不超过2%,实测远远不止,因此不推荐在线上系统长期跑profiler),目标是用于线上持续监控的特性,在jdk11以前是一个商业特性,在2018年 Java Flight Recorder 开源并作为 OpenJDK 11 的一部分发布。

jdk8u262后jfr被反向移植

https://mail.openjdk.org/pipermail/jdk8u-dev/2020-July/012143.html

https://bugs.openjdk.org/browse/JDK-8223147

https://hg.openjdk.org/jdk8u/jdk8u-jfr-incubator/

这意味着在jdk8u262以后的版本也可以自由使用jfr了。

当然,在某些供应商的open jdk8中可能更早被免费开放,比如Azul的openjdk。

JFR,具有以下关键的特性: - 低开销(在配置正确的情况下),可在生产环境核心业务进程中始终在线运行。当然,也可以随时开启与关闭。

- 可以查看出问题时间段内进行分析,可以分析 Java 应用程序,JVM 内部以及当前Java进程运行环境等多因素。

- JFR基于事件采集,可以分析非常底层的信息,例如对象分配,方法采样与热点方法定位与调用堆栈,安全点分析与锁占用时长与堆栈分析,GC 相关分析以及 JIT 编译器相关分析(例如 CodeCache )

- 完善的 API 定义,用户可以自定义事件生产与消费。

为什么要使用JFR

存在的问题

  1. 目前通过 JMX 对jvm的监控粒度比较粗,线上出现非业务逻辑问题后一般只能通过dump堆快照结合日志来进行分析,对jvm的详细把控只能通过dump来获得瞬时的状态进行分析(且dump操作需要拉出后再进行,可能dump到的数据并不准确)。

  2. 从业务层面看,目前业务线的代码业务逻辑比较复杂,且部分老代码存在可读性低的情况,常常难以直观感知到性能瓶颈。

  1. 从组件框架层面看,公司内部以及业务线的组件封装层次比较深,并且日常工作忙于需求开发,因此日常接触的层次主要集中在业务代码层面,导致难以定位到框架或组件代码中可能存在的性能瓶颈。

  2. 就业务研发团队与组件研发团队结合而言,组件开发人员感知集中在组件代码层面,容易忽视一些业务场景下的调用特征,可能导致一些业务场景独有的瓶颈。而业务开发人员的感知集中在业务层面,且由于业务复杂,框架封装层次深,难以直观感知到组件层面导致的瓶颈。导致二者难以形成整体的感知,只能各自为政。

  1. 目前对应用的优化以代码重构与架构重构为主,但重构代价大,周期长,往往难以推进。因此有时候通过消除代码层面的瓶颈来提升应用性能也是一个不错的选择。

使用JFR的好处

  1. 定位问题直达本质。jfr的思想是万物皆为event,这些event可以是jvm的事件,例如进入safepoint,stw,锁争用,内存分配,线程上下文切换等,也可以是自定义事件。这些event直接反映了应用在jvm和操作系统等层面的根本开销。并且jfr对各类事件进行聚合,通过火焰图等方式让开发者能够从jvm和操作系统层面反向定位到代码层面,极大程度上消除了代码水平逻辑复杂,调用深度复杂导致性能与开销瓶颈定位困难的问题,在推动jdk升级的背景下,对JVM有更全面的监控是十分必要的。

  2. JFR监控开销很低。根据官方描述可以做到将开销控制在1%,是完全可以接受的。一些常用的监控手段,比如jstack和jmap,需要让JVM进入safepoint状态才能获取线程堆栈和内存使用情况等信息。而这样的操作会导致JVM暂停应用程序的执行,从而降低线上应用的性能。 对于JMX等外部监控来说存在网络开销的问题。JFR通过在JVM内部进行数据采集,可以实现非常低的性能开销。

  1. 使用JFR有助于形成对JVM更全面的认知。在日常开发中,JVM的情况往往是一个只暴露少数指标的黑盒,难以做到具体的感知。使用JFR有助于使用者形成对JVM更全面的认知。

JFR的使用场景

  1. 分析应用瓶颈。本地分析应用瓶颈可以通过jmeter模拟生产流量,或者在mirror中回放生产流量的方式来进行监控,这种方式下可以采用比较激进的jfc配置(下面会讲到),对应用进行更全面的事件采集。

  2. 线上性能监控、辅助问题定位。线上可以使用default.jfc或者自定义配置来进行低开销的事件采集。通过dump一段时间内的jfr记录来分析应用瓶颈和问题所在。

JFR历史

JFR 0.9 版本对应 JDK 7 和JDK 8:JDK 7u40 之后,实现了和 JRockit Flight Recorder 一样的功能,并添加了各项数据配置,用来打开或者关闭一些统计数据功能。而且,在 JDK 8u40 之后,可以在运行时灵活地打开关闭 JFR。
JFR 1.0 版本对应 JDK 9 和 JDK 10: 在这一版本之后,增加了 JFR 事件接口,用户可以生产或者消费某种事件。
JFR 2.0 版本对应 JDK 11,这一版本就是本文主要基于的版本。
JDK 14 推出了 JFR Event Streaming ,让用户处理 JFR 事件更加灵活方便 。

JDK相关

JDK下载

https://jdk.java.net/archive/

JDK源码下载

https://mirrors.omnios.org/openjdk/

https://github.com/openjdk/jdk/tags

JFR源码

https://github.com/AdoptOpenJDK/openjdk-jdk11/tree/master/src/jdk.jfr/share/classes/jdk/jfr

Tools

JMC安装

JMC是用于分析JFR事件的开源工具,可以帮助我们更好地分析各类事件,JFR页面如下所示。

https://github.com/openjdk/jmc

JMC源码

https://github.com/openjdk/jmc

JMC-JFR(WIN)

idea使用JFR(不推荐)注意要点

idea自带的jfr可能存在各种问题,包括事件采集不全面,功能较少等, 推荐使用JMC进行采集和分析

并且JFR在低版本的idea中并未得到支持,并且在开始支持的较低版本可能存在各种问题(比如使用idea自带的JFR看不到内存分析等,虽然可能是由于jfc配置导致的),可以在此下载2023.1版本的idea。

https://www.cnblogs.com/xxcbdhxx/archive/2023/03/30/17271151.html

idea自带的JFR似乎无法分析由应用容器直接启动的应用(未做进一步确定,可以自己尝试),建议使用SpringBoot启动。

idea中c对jfr的cpu火焰图似乎还不错。

JMC-JFR(MAC)

JMC安装到使用过程的问题

1.

解决:

电脑环境是Mac m2 ,macOS版本是Ventura 13.2.1。

mac默认使用/Library/JavaJavaVirtualMachines目录下的最新版本JDK,而系统原本最新JDK版本是11。

JDK在15以前只有Mac Linux Windows三种环境的版本,在15以后才有支持aarch64的版本,m系列芯片是aarch64(arm64)架构,因此报错。

2.

解决:

使用SpringBoot启动,使用JMC连接虚拟机时需要设置变量:

System . setProperty ( "java.rmi.server.hostname" , "Ip or DNS of the server" );

JFR具体使用

方式1 使用JVM参数启动

例如

-XX:StartFlightRecording=disk=true,dumponexit=true,name=profile_online,filename=/tmp/recording.jfr,maxsize=4096m,maxage=1d,settings=/path/to/custom.jfc,path-to-gc-roots=false

key 默认值 含义
delay 0 延迟多久后启动 JFR 记录,支持带单位配置, 例如 delay=60s(秒), delay=20m(分钟), delay=1h(小时), delay=1d(天),不带单位就是秒, 0就是没有延迟直接开始记录。一般为了避免框架初始化等影响,我们会延迟 1 分钟开始记录(例如Spring cloud应用,可以看下日志中应用启动耗时,来决定下这个时间)。
disk true 是否写入磁盘,这个就是上文提到的, global buffer 满了之后,是直接丢弃还是写入磁盘文件。
dumponexit false 程序退出时,是否要dump出 .jfr文件
duration 0 JFR 记录持续时间,同样支持单位配置,不带单位就是秒,0代表不限制持续时间,一直记录。
filename 启动目录/hotspot-pid-26732-id-1-2020_03_12_10_07_22.jfr,pid 后面就是 pid, id 后面是第几个 JFR 记录,可以启动多个 JFR 记录。最后就是时间。 | dump的输出文件
name 记录名称,由于可以启动多个 JFR 记录,这个名称用于区分,否则只能看到一个记录 id,不好区分。
maxage 0 这个参数只有在 disk 为 true 的情况下才有效。最大文件记录保存时间,就是 global buffer 满了需要刷入本地临时目录下保存,这些文件最多保留多久的。也可以通过单位配置,没有单位就是秒,默认是0,就是不限制
maxsize 250MB 这个参数只有在 disk 为 true 的情况下才有效。最大文件大小,支持单位配置, 不带单位是字节,m或者M代表MB,g或者G代表GB。设置为0代表不限制大小**。虽然官网说默认就是0,但是实际用的时候,不设置会有提示**: No limit specified, using maxsize=250MB as default. 注意,这个配置不能小于后面将会提到的 maxchunksize 这个参数。
path-to-gc-roots false 是否记录GC根节点到活动对象的路径,一般不打开这个,首先这个在我个人定位问题的时候,很难用到,只要你的编程习惯好。还有就是打开这个,性能损耗比较大,会导致FullGC一般是在怀疑有内存泄漏的时候热启动这种采集,并且通过产生对象堆栈无法定位的时候,动态打开即可。一般通过产生这个对象的堆栈就能定位,如果定位不到,怀疑有其他引用,例如 ThreadLocal 没有释放这样的,可以在 dump 的时候采集 gc roots
settings default.jfc 这个位于 `$JAVA_HOME/lib/jfr/default.jfc`| 采集 Event 的详细配置,采集的每个 Event 都有自己的详细配置。另一个 JDK 自带的配置是 profile.jfc,位于 `$JAVA_HOME/lib/jfr/profile.jfc`。

其他配置

-XX:FlightRecorderOptions

allow_threadbuffers_to_disk false 是否允许 在 thread buffer 线程阻塞的时候,直接将 thread buffer 的内容写入文件。默认不启用,一般没必要开启这个参数,只要你设置的参数让 global buffer 大小合理不至于刷盘很慢,就行了
globalbuffersize 如果不设置,根据设置的 memorysize 自动计算得出 单个 global buffer 的大小,一般通过 memorysize 设置,不建议自己设置
maxchunksize 12M 存入磁盘的每个临时文件的大小。默认为12MB,不能小于1M。可以用单位配置,不带单位是字节,m或者M代表MB,g或者G代表GB。注意这个大小最好不要比 memorySize 小,更不能比 globalbuffersize 小,否则会导致性能下降
memorysize 10M JFR的 global buffer 占用的整体内存大小,一般通过设置这个参数,numglobalbuffers 还有 globalbuffersize 会被自动计算出。可以用单位配置,不带单位是字节,m或者M代表MB,g或者G代表GB。
numglobalbuffers 如果不设置,根据设置的 memorysize 自动计算得出 global buffer的个数,一般通过 memorysize 设置,不建议自己设置
old-object-queue-size 256 对于Profiling中的 Old Object Sample 事件,记录多少个 Old Object,这个配置并不是越大越好。一般应用256就够,时间跨度大的,例如 maxage 保存了一周以上的,可以翻倍
repository 等同于 - Djava.io .tmpdir 指定的目录 JFR 保存到磁盘的临时记录的位置
retransform true 是否通过 JVMTI 转换 JFR 相关 Event 类,如果设置为 false,则只在 Event 类加载的时候添加相应的 Java Instrumentation,这个一般不用改,这点内存 metaspace 还是足够的
samplethreads true 这个是是否开启线程采集的状态位配置,只有这个配置为 true,并且在 Event 配置中开启线程相关的采集(这个后面会提到),才会采集这些事件。
stackdepth 64 采集事件堆栈深度,有些 Event 会采集堆栈,这个堆栈采集的深度,统一由这个配置指定。注意这个值不能设置过大,如果你采集的 Event种类很多,堆栈深度大很影响性能。比如你用的是 default.jfc 配置的采集,堆栈深度64基本上就是不影响性能的极限了。你可以自定义采集某些事件,增加堆栈深度。
threadbuffersize 8KB threadBuffer 大小,最好不要修改这个,如果增大,那么随着你的线程数增多,内存占用会增大。过小的话,刷入 global buffer 的次数就会变多。8KB 就是经验中最合适的。

方式2 使用jcmd

1.启动 JFR 记录

jcmd <pid> JFR.start

例如jcmd 85 JFR.start name=profile_online filename=/tmp/recording.jfr maxage=1d maxsize=2g settings=opt/app/WEB-INF/tars/fat/custom.jfc

参数 与上面通过JVM参数启动的方式一致,如果使用JVM参数开启了记录的话dump指定时间的记录就行

2.dumpJFR记录

jcmd <pid> JFR.dump

例如jcmd 83 JFR.dump begin=16:06 end=16:08 name=profile_online filename=/tmp/profile- `hostname`-`date +%Y_%m_%d_%H_%M_%S`.jfr

参数 默认值 描述
name 指定要查看的 JFR 记录名称
filename 指定文件输出位置
maxage 0 dump最多的时间范围的文件,可以通过单位配置,没有单位就是秒,默认是0,就是不限制
maxsize 0 dump最大文件大小,支持单位配置, 不带单位是字节,m或者M代表MB,g或者G代表GB。设置为0代表不限制大小
begin dump开始位置, 可以这么配置:09:00, 21:35:00, 2018-06-03T18:12:56.827Z, 2018-06-03T20:13:46.832, -10m, -3h, or -1d
end dump结束位置,可以这么配置: 09:00, 21:35:00, 2018-06-03T18:12:56.827Z, 2018-06-03T20:13:46.832, -10m, -3h, or -1d (STRING, no default value)
path-to-gc-roots false 是否记录GC根节点到活动对象的路径,一般不记录,dump 的时候打开这个肯定会触发一次 fullGC,对线上应用有影响。最好参考之前对于 JFR 启动记录参数的这个参数的描述,考虑是否有必要

下载dump文件

【推荐】方式1:

jcmd 72 JFR.dump begin=19:59 end=20:01 name=profile_online filename=/tmp/profile_ `hostname`-`date +%Y_%m_%d_%H_%M_%S`.jfr

方式2:

在跳板机切到sftp,下载指定jfr文件即可(dump文件建议dump到tmp目录,这样可以在sftp页面直接看到对应文件)

3.停止JFR记录

jcmd <pid> JFR.stop

4.查看正在执行的JFR记录

jcmd <pid> JFR.check

5.查看或修改JFR配置参数

jcmd <pid> JFR.configure

如果不传入参数,则是查看当前配置,传入参数就是修改配置。

更多jcmd使用可以查看 https://docs.oracle.com/javacomponents/jmc-5-5/jfr-runtime-guide/run.htm#JFRRT172

对于参数的介绍也可以查看redHat的文档 https://access.redhat.com/documentation/zh-cn/openjdk/11/html/using_jdk_flight_recorder_with_openjdk/index

方式3 使用JMC直接连接

本地分析时非常推荐使用这种方式,操作比较简单,就不展开了

JFR自定义配置文件

建议关闭 OldObjectSample事件采集,它可能导致内存泄漏(如果需要开启的话建议在mirror上开启后接入流量观察几天,查看RSS使用率是否正常)

JDK中自带了两份jfc配置文件

  • default.jfcdefault配置文件是一种低开销配置,可以安全地在生产环境中连续使用。开销通常小于 1%。

  • profile.jfcprofile配置文件是一种低开销配置,非常适合用于分析瓶颈。开销通常低于 2%(官方宣称)。

对于profile.jfc,经过实测,性能开销不止官方宣称的2%, 不适合用于生产环境长期开启

JFR中有一些指标监控已经在JMX中存在,对于一些异常和ERROR的记录也能通过现有的log进行分析,因此不必重复记录。

另外对于一些事件的记录开销比较大,例如ObjectAllocationInNewTLAB和ObjectAllocationOutsideTLAB,也一些事件对应用问题的排查参考意义不大,因此需要调整或关闭这部分事件的采集,在需要采集时再动态开启。

此外有一部分事件的采集频率需要根据应用情况适当调整。

进行上述调整后得到了自定义配置文件(V1.0),在启动JFR监控时使用这份jfc配置用于线上长期采集。

这份配置文件采取了 比较保守的配置,可以根据自己的应用需求具体调整。

Jeyzer 的 jfc 配置参考

JFR文件拆分

我们可能一次性dump了比较多的记录,或者想要一次性dump一段比较长时间的记录进行分析,但是jmc对jfr记录的分析十分消耗cpu和内存,所以对于比较大的jfr记录我们需要对其进行拆分

我们可以使用jdk自带的命令来完成这个需求

官方文档 The jfr Command

用法例如

/Library/Java/JavaVirtualMachines/jdk-17.jdk/Contents/Home/bin/jfr disassemble –max-chunks 1 –output ./ ./profile_data.jfr

开启JFR对性能的影响测试(todo)

本测试的条件是在使用JVM参数开启JFR记录,已经平稳运行的应用上测试dump文件的影响、停止JFR的影响、以及开启JFR的影响。

主要通过查看执行JFR指令时cpu load和response time的抖动情况来评估

一个缓存型服务

一个缓存型服务是一个缓存应用,接口响应时间快、性能高,能承受比较大的并发。如果JFR会导致比较大的开销,比较容易能在响应时间上看出来。

对一个缓存型服务设置每分钟24k左右的单机流量请求,远高于线上的请求量,一方面JFR会记录到更多事件,放大JFR的开销,另一方面可以测试出在系统压力较大情况下JFR对系统的影响

测试期间的监控指标如下

1.dump测试

在23:25的时候dump了5分钟的数据,从监控可以看出来并没有导致系统出现明显的抖动

从原理角度也很好解释,因为JFR是持续记录的,我们dump文件时JFR只需要拉取一段时间内已有的记录给我们,而不需要在dump时再进行太多分析。

2.stop测试

在23:36时stop JFR,并未观察到明显抖动

3.start 测试

在23:55时开启了JFR,开启时也没有观察到系统明显的抖动,或是开启后性能的降低

待完成部分

Cryostat:容器化的JFR

Cryostat官网

Automating JDK Flight Recorder in containers

Announcing Cryostat 2.0: JDK Flight Recorder for containers

推荐阅读

JFR事件大全

JFR教程-redhat-jdk11

JFR专题-hashcon

JFR编程与使用入门-video

JFR-JVM进程最全面低消耗持续线上监控-video

自定义事件

拓展阅读

Jeyzer:the incident analysis solution for Java

Jeyzer 的 jfc 配置参考

jeyzer and jfr

其他阅读

JMC教程(有点过时)

参考

自定义JFR事件

JFR讨论

JFR使用

重点看看

JFR-JMC教程

new Relic集成JFR监控

data dog

grafana集成JFR

grafana集成JFR-redhat

JVM监控指南(包括JFR)