me/JFR/0_初识Java Flight Record.md

204 lines
11 KiB
Markdown
Raw Permalink Normal View History

2025-03-11 16:04:48 +08:00
### 写在前面
2025-03-11 13:55:26 +08:00
- 文章出处https://zhuanlan.zhihu.com/c_1264859821121355776
- 关注大佬https://www.zhihu.com/people/zhxhash
2025-03-11 16:04:48 +08:00
我只是对大佬的专栏文章内容做一个笔记,加深记忆和理解。
2025-03-11 13:55:26 +08:00
2025-03-11 11:04:19 +08:00
### 什么是JFR
JFR是**Java Flight Record**Java飞行记录的缩写是JVM内置的基于事件的监控记录框架。这个起名参考了黑匣子对于飞机的作用将Java进程比喻成飞机飞行。顾名思义JFR主要用于问题定位和持续监控。
### JFR版本
**JFR 0.9**版本对应**JDK7和8**在8u40之后可以在运行时开启/关闭。**JFR 1.0**版本对应**JDK9和10**在这一版本之后增加了JFR事件接口用户可以生产或者消费某种事件。**JFR 2.0**版本对应**JDK11**,下面的参数都是基于这一版本。
### 为什么用JFR
为了在生产环境更好的定位问题。JDK提供了一个可以长期开启对应用影响很小的持续监控手段官方的目标是开启JFR监控默认配置非profile**对性能的影响在1%以内对JVM Runtime、GC、OS以及Java库进行全方位的监控。**
### JFR的核心Event
2025-03-11 11:16:07 +08:00
在JFR中一切皆为Event任意JVM行为都是一个Event例如
2025-03-11 11:04:19 +08:00
- 类加载Class Load Event
- 开启JFR记录Recording Reason Event
2025-03-11 11:16:07 +08:00
- 就算是 Event 丢失,也是一个 Data Loss Event
2025-03-11 11:04:19 +08:00
2025-03-11 11:16:07 +08:00
Event 在某些特定的时间点产生,**由名称、时间戳、Event 数据体组成。**不同的 Event 数据体不同(例如 CPU 负载Event 前后的 Java 堆大小,获取锁的线程 ID 等)
大部分的 Event都有 Event 是在哪个线程发生的、线程的调用栈、Event 持续时间,利用这些信息,我们可以回溯 Event 发生当时的情况。
2025-03-11 11:16:07 +08:00
### Event类型
Event 按照采集方式可以分为三种:
- Instant Event这种 Event 在发生时就立刻采集。例如Throw Exception Event、Thread Start Event这种在某一时刻发生的 Event
- Duration Event这种 Event 在完成的时候记录。因为需要耗费一些时间但可以设置一个时间限制超时才记录。例如GC Event、Thread Sleep Event
- Sample EventRequestable Event这种 Event 按照一定的频率采集。频率是可以配置的例如Thread Dump Event、Method Sampling Event
由于 JFR 会采集很多很多的数据,为了效率,最好配置自己感兴趣的事件采集。并且对于 Duration Event 设置时间限制,一般我们对于时间短的事件并不关心。
### Event存储
Event 会被写入`.jfr`的二进制文件中,以`little endian base 128`的形式编码,以 Class Load Event 举个例子:
```
0000FC10 : 98 80 80 00 87 02 95 ae e4 b2 92 03 a2 f7 ae 9a 94 02 02 01 8d 11 00 00
```
- 0000FC10: 文件位置
- 98 80 80 00: Event大小
- 87 02: Event ID
- 95 ae e4 b2 92 03: 时间戳
- a2 f7 ae 9a 94 02: 持续时间
- 02: 线程 ID
- 01: 堆栈 ID
- 8d 11: 加载的类
- 00 : 定义类的 ClassLoader
- 00 : 初始化类的 ClassLoader
> 实际使用中,通过可视化工具**JMC**查看`.jfr`文件
2025-03-11 13:55:26 +08:00
### 如何实现的低延迟、低性能损耗?
Event 是多线程产生的,如果 Event 记录要保证全局有序,那么肯定需要多线程向一个指定队列或者缓存输出,那么不可避免的会涉及到锁争用,这样是很低效的。而 Event 本身带时间戳,所以记录时不需要排序,将每个线程内的记录,合并成一个集合后再进行排序高效得多。
<img width='70%' src='https://pic3.zhimg.com/v2-5530b8a77d0d45ac12dd879ccf7afce8_1440w.jpg'/>
2025-03-11 13:55:26 +08:00
1. 所有的 Event 会先存储到每个线程自己的 Thread Buffer默认8KB这是一个经验值
2. Thread Buffer 满了之后刷入 Global Buffer可配置
3. Global Buffer 满了之后会选择丢弃或者刷入文件(可配置)
*Thread Buffer 中的数据要么在内存中,要么就在磁盘里。不会两个地方都存在。*
#### JFR记录数据丢失
- 断电、操作系统强制重启
- kill -9 了 Java 进程
- JVM 崩溃
2025-03-11 14:00:03 +08:00
以上三种情况,刷入文件的 Event 不会丢,但内存里的 Global Buffer、Thread Buffer 会丢。对于JVM正常退出含应用异常但JVM正常退出的情况数据不会丢。
2025-03-11 11:04:19 +08:00
2025-03-11 14:00:03 +08:00
⚠️数据在从 Thread Buffer 刷入 Global Bufeer 的时候, 去 dump JFR 的数据,可能这部分数据会被忽略而导致看不到。
2025-03-11 14:29:50 +08:00
⚠️从 Global Buffer 刷入磁盘不够快的时候,这时候要刷入磁盘的数据可能被丢弃。此时会记录下 Data Loss Event 包含了哪块时间的数据丢了,通过 JFR 日志也能看到这个信息。
### 开启JFR
有2种方式开启通过启动参数在启动的时候开启、jcmd在运行时启用/关闭。
#### 启动参数
在JDK11以后启动参数简化了。
- 启动JFR记录的参数`-XX:StartFlightRecording`
- 用于配置JFR的参数`-XX:FlightRecorderOptions`
*JDK8中的`-XX:+FlightRecorder`状态位不再需要了*
#### StartFlightRecording
2025-03-11 14:52:01 +08:00
|配置项|默认|说明|
2025-03-11 14:51:18 +08:00
|:-----|:-----|:-----|
2025-03-11 14:29:50 +08:00
|delay|0|延迟多久后启动 JFR 记录支持带单位例如delay=60s、delay=20m、delay=1h、 delay=1d|
|disk |true|是否写入磁盘,控制 global buffer 满了之后,是丢弃还是写入磁盘|
|dumponexit |false |程序退出时是否要dump出 .jfr文件|
|duration | 0 | JFR 记录持续时间支持单位配置0代表一直记录|
|filename |- | dump的输出文件例如启动目录/hotspot-pid-26732-id-1-2020_03_12_10_07_22.jfrpid是进程idid后面的1代表第1个jfr文件|
|name | - | 由于可以启动多个 JFR 记录,这个名称用于区分,否则只能看到一个记录 id不好区分|
|maxage | 0 | disk=true生效global buffer 刷入的文件保留时间支持单位配置0代表一直保存|
|maxsize | - | disk=true生效global buffer 刷入的文件最大值支持单位配置MB、GB例如250MB这个配置不能小于**maxchunksize**参数|
|path-to-gc-roots| false | 是否记录GC根节点到活动对象的路径一般不打开这个性能损耗比较大会导致FullGC。一般是在怀疑有内存泄漏、通过对象堆栈无法定位的时候动态打开。例如 ThreadLocal 没有释放这样的,可以在 dump 的时候采集 gc roots|
|settings | default.jfc| 采集 Event 的详细配置可选值default.jfc、profile.jfc|
#### FlightRecorderOptions
2025-03-11 14:50:12 +08:00
2025-03-11 14:52:01 +08:00
|配置项|默认|说明|
2025-03-11 14:51:18 +08:00
|:-----|:-----|:-----|
2025-03-11 14:50:12 +08:00
|allow_threadbuffers_to_disk | false | 在 thread buffer 线程阻塞的时候,是否将 thread buffer 内容直接写入文件。一般没必要开启这个参数,只要设置的参数让 global buffer 大小合理不至于刷盘很慢就行了|
|globalbuffersize |-|单个 global buffer 的大小,一般通过 memorysize 设置,自动计算得出,不建议自己设置|
|numglobalbuffers |-| global buffer 的个数,一般通过 memorysize 设置,自动计算得出,不建议自己设置|
|maxchunksize | 12MB | 存入磁盘的每个临时文件的大小不能小于1MB不能比**memorysize**小,更不能比**globalbuffersize**小,会导致性能下降|
|memorysize | 10MB | global buffer 占用的整体内存大小 |
|old-object-queue-size | 256 | 针对**Profiling**中的**Old Object Sample 事件**收集多少个**Old Object**。大佬的建议是256够用时间跨度大的例如 maxage 保存了一周以上的,可以翻倍|
|repository |-| 保存到磁盘的位置,等同于 -Djava.io.tmpdir 指定的目录|
|retransform | true | 是否通过 JVMTI 转换 JFR 相关 Event 类,如果设置为 false则只在 Event 类加载的时候添加相应的 Java Instrumentation。一般不用改这点内存 metaspace 还是足够的|
|samplethreads | true | 是否开启线程采集的状态位配置,只有为 true且在 Event 配置中开启了线程相关的采集,才会采集这些事件,后面会展开说|
|stackdepth | 64 | 采集事件堆栈深度,有些 Event 会采集堆栈,这个堆栈采集的深度,统一由这个配置指定。这个值不能设置过大,堆栈深度过大会影响性能。比如你用的是 default.jfc 配置的采集堆栈深度64基本上就是不影响性能的极限了。可以自定义采集某些事件增加堆栈深度。|
|threadbuffersize | 8KB | Thread Buffer 大小,增加会带来更多内存开销,减小会增加刷入 global buffer 的次数8KB 是一个经验值|
2025-03-11 16:04:48 +08:00
#### disk=true
当 global buffer 满了,写入 repository 配置的目录,这个临时目录是**对用户不可见的**,临时目录地址是-Djava.io.tmpdir指定的默认为
- linux /tmp
- windows: C:\Users\用户名\AppData\Temp
目录结构的命名格式时间_pid例如
```
--/2020_03_12_08_04_45_10916
|----2020_03_12_08_04_45.jfr
|----2020_03_12_08_05_12.jfr
|----2020_03_12_08_05_55.jfr
|----2020_03_12_08_06_08.jfr
|----2020_03_12_08_06_08.part
```
每个.jfr就是一个 Data trunk最新的文件就是`.part`每个jfr文件的大小=Data trunk的大小。
#### dumponexit=true
程序退出的时候强制dump一次将数据输出到 filename 配置的文件。用户手动dump也会存储到这个文件**输出到这个文件目录的.jfr文件才对用户可见。**
输出这个文件是不慢的就是把内存里的buffer以及临时目录中的.jfr文件合并后输出。⚠注意不能把内存里的buffer配的过大否则可能会导致内存不足引发FullGC。
2025-03-11 16:04:48 +08:00
### JFR的内存占用
- thread buffer线程数量 * thread buffer 大小默认8kb
- global buffer总大小由【memorysize】自动计算得出
相加就是JFR的总内存占用。
2025-03-11 16:33:14 +08:00
### 运行时通过jcmd开启/关闭
2025-03-11 16:32:23 +08:00
#### 开启JFR记录
eg`jcmd <pid> JFR.start name=profile_online maxage=1d maxsize=1g`JFR.start 后面的参数和*-XX:StartFlightRecording*一样
#### 停止JFR记录
eg`jcmd <pid> JFR.stop name=profile_online`
#### 查看当前正在执行的 JFR 记录
eg`jcmd <pid> JFR.check`
输出eg
```
<pid>:
Recording 1: 参数列表 (running)
```
#### 查看配置
`jcmd <pid> JFR.configure`,不传入参数,则是查看当前配置。传入参数就是修改配置,与*-XX:FlightRecorderOptions*一样。
输出eg
```
Repository path: /tmp/2020_03_18_08_41_44_21
Stack depth: 64
Global buffer count: 20
Global buffer size: 512.0 kB
Thread buffer size: 8.0 kB
Memory size: 10.0 MB
Max chunk size: 12.0 MB
Sample threads: true
```
#### 输出dump文件
`jcmd <pid> JFR.dump`
|参数 | 默认 | 描述|
|:-----|:-----|:-----|
|name | - | 指定要查看的 JFR 记录名称|
|filename | 无 | 指定输出位置|
|maxage | 0 | dump的时间范围的文件配置和上文介绍的一样|
|maxsize | 0 | dump最大文件大小配置和上文介绍的一样|
|begin | - | dump开始位置 可以这么配置09:00, 21:35:00, 2018-06-03T18:12:56.827Z, 2018-06-03T20:13:46.832, -10m, -3h, -1d|
|end |-| dump结束位置可以这么配置 09:00, 21:35:00, 2018-06-03T18:12:56.827Z, 2018-06-03T20:13:46.832, -10m, -3h, -1d|
|path-to-gc-roots| false | 一般不开启dump 的时候打开这个肯定会触发一次 fullGC对线上应用有影响|
<a href='./1_查看JFR事件的工具JMC.md' target='_blank'>查看下一节</a>