通过 JFR 与日志深入探索 JVM - 2. JFR 基本原理以及快慢因素

最新推荐文章于 2024-04-09 00:43:50 发布

hashcon

最新推荐文章于 2024-04-09 00:43:50 发布

阅读量5.5w

点赞数 1

分类专栏：通过JFR与日志深入探索JVM 文章标签： java JVM JFR JFR事件

本文链接：https://blog.csdn.net/zhxdick/article/details/111562928

版权

通过JFR与日志深入探索JVM 专栏收录该内容

6 篇文章 11 订阅

订阅专栏

全系列目录：通过 JFR 与日志深入探索 JVM - 总览篇

我个人有个习惯，对于要用的一个新的框架，新的中间件等等，我一般不太信任它的官网“吹”的优点以及性能测试，我一般会一边使用一边自己测试，并且猜想其内部实现并结合源码搞清楚它的实现原理以及一些“坑”（这些“坑”并不是说这些框架或者中间件有什么毛病，而是因为官网浮夸的“吹”以及有些事情说一半留一半导致用户有误解），在这之后我才敢放心使用。

所以呢，我想先将 JFR 实现的基本原理提前说明白，这样可以让大家先有个整体印象，搞明白为何这么配置就对线上 JVM 影响小，从而放心使用。

JFR 的生命周期

JFR 记录开始：每个 JVM 进程可以同时启用多个 JFR 记录采集，可以在 JVM 启动的时候利用 JVM 启动参数启用 JFR 记录，也可以通过jcmd动态开启 JFR 记录采集，也可以在程序内通过代码开启采集。

JFR 记录结束：可以启动时指定在采集多久后结束，也可以通过jcmd动态关闭 JFR 记录采集，也可以在程序内通过代码结束采集。在结束时，可以指定让 JFR 记录 dump 到一个文件中。JFR 记录也会随着 JVM 的结束而结束。

JFR 记录分析：可以随时通过jcmd动态将 JFR 记录 dump 到一个文件中，或者通过代码程序中执行 dump，进行后续分析。注意 dump 并不会结束一个 JFR 记录，并且 dump 最多只能 dump 出上次 dump 到现在的所有记录。

JFR 记录实时分析：可以通过 JFR Stream 实现对于 JFR 记录的实时消费与处理。

JFR 的核心 - Event 的构成

在 JFR中，一切皆为事件（Event）：

任意 JVM 行为都是一个 Event，例如类加载也是一个 Event，对应 Class Load Event
开启 JFR 记录的原因也是一个 Event，对应的就是 Recording Reason Event
就算是有 Event 丢失，他也是一个 Event，对应 Data Loss Event

这些 Event 在某些特定的时间点或者特定的场景下产生，每个事件都有事件类型，开始时间，结束时间，发生事件的线程，事件发生的线程堆栈还有 Event 数据体组成。Event 数据体不同的 Event 数据不同，例如 CPU 负载，Event 发生之前还有之后的 Java 堆大小，获取锁的线程 ID 等等。需要注意的是，并不是所有事件都要采集结束时间，发生事件的线程或者事件发生的线程堆栈，例如那种定时采样事件，就不需要记录这些。

Event 的分类

首先，按照采集规则，可以分为三类：

瞬时事件（Instant Event）：顾名思义，这种 Event 在发生时就立刻采集。例如：抛异常的事件 Throw Exception Event 还有线程一旦启动就会有 Thread Start Event，类似于这种在某一时刻发生的 Event。
持续事件（Duration Event）：这种 Event 需要耗费一些时间，在完成的时候如果超过一定时间限制才会记录。这个时间限制是可以设置的。例如有 GC 发生的时候的 GC Event，以及线程休眠的 Thread Sleep Event。
采样事件（Sample Event 或者是 Requestable Event）：按照一定的频率采集，这个频率是可以配置的。例如定时采集所有线程堆栈的 Thread Dump Event，定时检查 Runnable 线程在执行那些方法的 Method Sampling Event

按照事件类型，又可以分为：

Java 应用监控
a. TLAB 分配相关事件与统计事件
b. 文件 IO 相关
c. 网络 IO 相关
d. Java 异常与错误相关事件与统计事件
e. Java 锁同步相关
f. Java 线程相关事件与统计事件
g. 类加载统计
JVM 监控
a. 类加载相关事件
b. JIT 编译相关事件与代码高速缓存相关事件与统计事件
c. GC 相关事件
d. 安全点相关事件
e. 偏向锁相关事件
f. JVM 操作事件监控采集
g. JVM 信息与运行信息相关事件
h. 模块化操作相关事件
操作系统监控

Event 的序列化存储结构

这里先用一个事件作为例子，简单介绍下存储，具体存储结构的详细介绍，请参考后面的章节。

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
PayLoad（每种 Event 的 field 不同）：
- 8d 11: 加载的类
- 00 : 定义类的 ClassLoader
- 00 : 初始化类的 ClassLoader

可以看出，JFR 的事件，是一个非常紧凑的存储方式，为了节省空间，对于同一类型的数字，根据大小变长存储。同时，没有存储字段名称。最后，对于一些公共的字段，例如上面这个事件定义类的 ClassLoader这样的字段，保留的是指向元空间的指针。的这样保证了节省空间，对于 JFR 这种存储流程来说，节约空间对于提升性能是很重要的，下一小节就会说明为何这样。

这里仅仅是举个例子，实际使用中，我们肯定不会去这么看每个 Event 的，而是通过可视化工具 JMC 去看，这个我们后面会讲到。这些 Event 也可以被应用消费解析，解析的工具类也是 Java 内置的，后面也会讲到。

Event 是如何产生的？存储流程是？

首先，Event 肯定是多线程产生的，这点显而易见。如果 Event 记录要保证全局有序，那么肯定需要多线程向一个指定队列或者缓存输出，那么不可避免的会涉及到锁争用，这样是很低效的。 Event本身带时间戳，那么可不可以在最后读取的时候进行排序？在一个线程内，生成的 Event 肯定是有序的；那么多线程产生的 Event，就可以看成一个又一个的有序集合。最后，针对这些有序集合的每个元素进行整体排序，算法上快很多。所以我们没有必要在 Event 产生的时候就进行整体排序。

在 JFR 中，所有的 Event，会先存储到每个线程自己的线程 JFR 缓冲（Thread Buffer）中；在这个 Buffer 满了之后，会将 Buffer 的内容刷入全局 JFR 缓冲（Global Buffer ）中；Global Buffer 是一个环形 Buffer，保存着所有线程发送来的 Thread Buffer 中的内容。当这个环形 Buffer 存储到达上限之后，根据配置，会选择丢弃或者刷入文件。

可以看出，不同的 Buffer 之间的数据不会有任何重叠。并且某一块数据，要么就是在内存中，要么就是在磁盘上，不会两个地方都存在，那么这样会带来数据丢失的问题：

首先，在断电的时候或者操作系统强制重启的时候，还未写入磁盘的 Event 会丢失。
如果只是强制 kill -9 掉了 Java 进程，那么刷入文件写入高速缓冲的 Event 不会丢失，但是 Global Buffer 中还有 Thread Buffer 中的数据会丢失。同样的，如果JVM崩溃了，这些内存Buffer中的数据也会丢失。正常退出，或者应用异常但是JVM正常退出的，数据不会丢失。
采集的数据在可见之前可能会有很小的延迟。例如数据在从 Thread Buffer 刷入 Global Bufeer 的时候，你如果去 dump JFR 的数据，可能这部分数据会被忽略而导致看不到。
最后一点，任何情况下导致在从 Global Buffer 刷入磁盘不够快的时候，这时候要刷入磁盘的数据可能被丢弃。当发生这种情况是，就会记录下数据丢失事件，这个事件包括是那块时间的数据丢掉了。通过 JFR 的日志也能看到这个信息。

这里涉及到的概念说明：

线程 JFR 缓冲（Thread Buffer）：每个线程写入 JFR 事件的缓冲池
全局 JFR 缓冲（Global Buffer ）：当某个线程的 Thread Buffer 满了，会刷入 Global Buffer。
JFR 数据块（Data Chunk）：Global Buffer 满了默认会刷入本地临时文件，本地临时文件并不是一个文件，而是按照一定大小分割的多个文件。每一个临时文件就是一个 Data Chunk，或者 Chunk

JFR 快的原因

由于 Event 产生是每个线程独立产生的，生成事件就像打印日志一样，这些事件是尽可能地节省了空间的，可以让各种缓冲不那么快变满。同时，通过从线程 JFR 缓冲 -> 全局 JFR 缓冲的流程大大减少了并发争用。并且，写入临时文件也是在全局 JFR 缓冲满了之后才刷入文件，减少了文件 IO。

造成 JFR 慢的原因以及如何避免

通过上面的分析，我们可以知道，只要 Event 的产生没有瓶颈，那么 JFR 记录是很快的。但是，如果配置不当，Event 的产生很可能产生瓶颈，原因是：

JFR 某些 Event 采集可能会造成全局进入安全点（Safepoint）从而造成 STW（Stop-The-World）。例如 Thread dump event 采集所有线程堆栈，打印线程堆栈是需要全局进入安全点的，对于这种事件采集过于频繁肯定会对性能造成影响。还有如果开启了 JFR 追踪 GC 根节点，也会造成频繁进入安全点。
JFR 某些 Event 可以开启堆栈采集，但是追踪堆栈是一个比较耗费性能的操作。

对于可能进入安全点的 Event，或者是开启了堆栈采集的 Event，一定要控制好采集的频率或者事件的时间阈值限制，减少采集次数，如果过快，或者在业务高峰时采集的事件过多，肯定会影响性能。