深度探索JFR - JFR详细介绍与生产问题定位落地 - 3.

2020-07-10  本文已影响0人  干货满满张哈希

本文基于 OpenJDK 11

3. 虚拟机相关 Event

3.3. JIT即时编译相关

JIT 即时编译可能会遇到编译后的代码缓存占满,或者因为空间有限或者代码设计问题,导致某些关键方法需要重编译导致性能问题,以及因为代码块过大导致编译失败从而性能有问题,这些问题我们可以通过 JFR 中相关的 Event 进行查询。
JFR 对于 Java 开发可以完全替换 JVM 编译日志

额外讲解:JIT 相关的知识

首先,这里简单介绍下 JIT 相关的知识(这里我推荐看 O'Rerilly 上面的 Java Performance 第二版的第四章:Working with the JIT Compiler):

首先什么是 JIT: 当 Java 被编译为字节码形式的 class 文件之后,他可以在任意的 JVM 运行。这里说的编译,主要是指前端编译器。但是 class 文件里面的字节码并不能直接运行,而是要通过后端编译器在程序运行期间,将字节码转变成机器码,这样电脑才能执行你的代码。

Java Code Cache 是啥: 如果 Java 每次都需要即时编译成机器码,再执行,效率太慢了。那么是不是对于某些热点代码,编译后的机器码,缓存起来,这样下次就不用重新即时编译了,多快乐。Java Code Cache 就是用来干这个的。但是编译后的机器码太大了,Java Code Cache 的空间是有限的,也不能将所有的代码都编译成机器码缓存起来。所以就需要一些优化与清理策略。

C1,C2 编译器与分层编译(Tiered Compilation)以及编译级别(Compilation Level): C1,C2 按照老概念来看,分别是客户端编译器和服务端编译器,随着 -server 的 Java 参数的消失,代表着 Java 程序本质上不再区分客户端服务端,所以目前所有的 Java 进程都是 C1,C2混合使用。

C1 编译器对代码做一些简单的优化并加入一些采样代码, C2 针对 C1 加入的代码的采样结果,做更多的分析(语法解析,逃逸分析,高级优化器等等),优化成为更好的代码。C1是一个简单快速的编译器,主要关注点在于局部优化,而放弃许多耗时较长的全局优化手段。C2 则是关注于耗时较长的全局优化手段。同时由于 Java Code Cache 是有限的,有些代码可能优化后被淘汰,需要重新编译,没必要对于每种代码都进行 C1 C2 的优化,那些执行次数少的代码,直接编译执行即可。

C1,C2是怎么配合的呢?从 Java 7 开始引入了分层编译的概念,目前已经是默认的即时编译方式。Java 代码一共有如下几层编译级别:

一般情况下,热点代码都是经过 0 -> 3 -> 4 这个路径被优化的。但是也有例外情况:

Java Code Cache 分块(Segmented Code Cache): 从 Java 9 开始引入的 Code Cache 分块,主要解决之前把所有种类代码放一起,导致扫描的时候效率低下。例如之前说的有些代码经过 C1 优化,之后 C2 优化,这些代码最好分开存储。(C1 优化过得代码,C2 优化完之后,C1的要被清理掉)。

目前 Java Code Cache 分为 3 块:

默认情况下,非方法代码堆包括 3MB 的来自于虚拟机的固定空间占用,以及随着编译线程个数上涨而上涨的空间占用。剩下的空间,带采样的代码堆与不带采样的代码堆评分,可以通过如下参数修改:

Code Cache Sweeper(代码缓存清理器): 随着 Java Code Cache 的分块处理,目前 Code Cache Sweeper 只用扫描 带采样的代码堆 和 非方法代码堆,并且可以分开并发扫描,看那些代码缓存可以回收。

Method Inline(方法内联): 通俗来讲,就是JVM在运行时优化编译好的代码,将经常调用的方法从调用替换为方法体代码,减少调用。通常发生在 C1 编译器优化。举一个简单的例子:在编写Java的POJO object时候,经常会用到getter和setter,这是从学校里学java开始,我们就一直使用的设计模式,为了保证POJO类对象的域安全。但是我们是否考虑过,如果每次都用这个而外的方法修改,那么是否都会多一次方法栈寻址调用?这样对性能肯定是有影响的。幸好我们有Java Inline Method这个机制,参考下面的代码:

public class JitInlining {
    public static void main(String args[]) {
        Position position = new Position(25);
        for (int i = 0; i < 1000000; ++i) {
            int x = position.getX();
            position.setX(x + 1);
        }
        System.out.println(position.getX());
    }
}
class Position {
    private int x;
    public Position(int x) {
        this.x = x;
    }
    public int getX() {
        return x;
    }
    public void setX(int x) {
        this.x = x;
    }
}

加上jvm参数来看一下inline效果:-XX:+UnlockDiagnosticVMOptions -XX:+PrintInlining

@ 19   com.test.Position::getX (5 bytes)   accessor
@ 27   com.test.Position::setX (6 bytes)   accessor

这个accessor代表jit识别这些方法是某个field的accessor(即getter或者setter),accessor是会被inline的。

OSR(On Stack Replacement): 一种在运行时替换正在运行的函数/方法的栈帧的技术。JIT 优化,一般在某一段代码被执行很多次之后,例如:

for (int i = 0; i < 10000; i ++) {
    this.data++;
}

this.data++;如果被编译器优化之后,这个循环还没执行完,则需要 OSR 机制,动态替换正在栈帧中待执行的代码。这样还没完成的循环,就可以用优化后的代码执行。

通常来看,应该把 所有的栈上替换执行代码都叫做 OSR,但是 Java 中只针对于编译器优化的代码替换原有代码称为 OSR,对于去优化的替换(就是用原有代码替换优化过的代码),称为Bailout

为什么会有这种Bailout的情况呢?代码优化可以分为(这里参考大神的知乎回答):

JIT即时编译相关的 Event 列表

事件名称 简介 default.jfc中的配置 profile.jfc中的配置
CompilerConfiguration 即时编译器配置采集 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次
CompilerStatistics 即时编译器统计数据采集 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次 是否启用: 是;周期: 1000ms一次
Compilation JIT编译事件收集,编译时间大于某一时间限制则被收集 是否启用: 是;时间阈值: 1s 是否启用: 是;时间阈值: 100ms
CompilierPhase 编译阶段,较为底层的事件,一般 Java 开发不关心这个时间 是否启用: 是;时间阈值: 60s 是否启用: 是;时间阈值: 10s
CompilationFailure 编译失败事件,default没有开启,可以考虑开启,但是里面的信息都比较底层,所以一般只看 Compilation 事件定位问题 是否启用: 是否启用:
CompilerInlining 编译内联事件,这个事件线上不要开启,很影响性能,测试阶段可以开启看看内联失败的原因 是否启用: 是否启用:
CodeCacheConfiguration 代码缓存配置采集 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次
CodeCacheStatistics 代码缓存统计数据采集 是否启用: 是;周期: 每一个 chunk 采集一次 是否启用: 是;周期: 每一个 chunk 采集一次
CodeCacheFull 代码缓存空间已满事件 是否启用: 是否启用:
CodeSweeperConfiguration 代码缓存清理配置采集 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次 是否启用: 是;周期: 每写入一个新的 chunk 的开头采集一次
CodeSweeperStatistics 代码缓存清理统计数据采集,这个我们一般不看的 是否启用: 是;周期: 每一个 chunk 采集一次 是否启用: 是;周期: 每一个 chunk 采集一次
SweepCodeCache 代码缓存清理事件采集 是否启用: 是;时间阈值: 100ms 是否启用: 是;时间阈值: 100ms

CompilerConfiguration 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Thread Count 线程个数 2
Tiered Compilation 是否启用了分层编译(Tiered Compilation) true

CompilerStatistics 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Bailouts 放弃编译好的机器码使用原有字节码执行的总次数(去优化,对应上面提到的 OSR 中的 Bailout 情况),这个如果经常发生,则需要看一下发生的事件对应的其他 Compiler 相关的事件是否能定位到对应的方法 2
Compiled Methods 编译的方法总数 41329
Invalidated Compilations 无效的编译 0
Compilation Resulting Code Size 程序启动以来编译后的代码大小 85502368 B
Compilation Resulting Size 程序启动以来编译占用的总大小 128496488 B
OSR Bytes Compiled On Stack Replacement(栈上替换,这里是向上优化) 编译的代码字节大小,这个一般为采集不到,我们也不从这里看大小,一般为0,不用关注 0 B
OSR Compilations 程序启动以来 On Stack Replacement(栈上替换,这里是向上优化) 编译总次数 609
Peak Time 程序启动以来最长编译时间 961 ms
Standard Bytes Compiled 标准编译代码大小,这个一般为采集不到,我们也不从这里看大小,一般为0,不用关注 0 B
Standard Compilations 程序启动以来标准编译次数 40108
Total time JIT 编译总占用时间 206547 ms

Compilation 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
持续时间 事件持续时间 55607927 ticks
结束时间 事件结束时间 2869587482704980480 epochticks
Event Thread 编译线程,可能是 C1 CompilerThreadN 或者是 C2 CompilerThreadN,分别对应 C1,C2线程 C1 CompilerThread0
Compiled Code Size 编译后的代码大小 11048 B
Compilation Identifier 本次编译对应的全局唯一id,通过这个 id 确认哪些事件对应的是同一次编译。 5224
Compilation Level 编译级别 1,2,3,4 (0不会出现的,因为就是没编译) 1
Inlined Code Size 内联代码大小 1328 B
On Stack Replacement 是否为栈上替换 false
Java Method 对应的 Java 方法 String java.io.WinNTFileSystem.resolve(File)
Java Method Succeeded 是否编译成功,如果没有成功,看看是否代码块太大导致的 true

CompilierPhase 事件我们并不关心,也不会打开,跳过。CompilationInlining 我们也是一般不看并且不会打开,这里也跳过。

CompilerFailure 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Event Thread 编译线程,可能是 C1 CompilerThreadN 或者是 C2 CompilerThreadN,分别对应 C1,C2线程 C1 CompilerThread0
Compilation Identifier 本次编译对应的全局唯一id,通过这个 id 确认哪些事件对应的是同一次编译。 6012
Failure Message 失败信息 Jvmti state change invalidated dependencies(JVM正在关闭会报这个)

CodeCacheConfiguration 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Expansion size 每次扩展大小 65536 B
Initial Size 初始大小 2555904 B
Minimum Block Length 内存分配最小块大小 4 B
Non-nmethod Size 对应上面说的 非方法代码堆大小 5825164 B
Non-profiled Size 对应上面说的 不带采集代码堆大小 122916538 B
Profiled Size 对应上面说的 带采集代码堆大小 122916538 B
Reserved Size 总大小 251658240 B
Reserved Top 代码缓存内存堆地址 140692249706496
Start Address 代码缓存内存堆基地址 140691998048256

CodeCacheFull 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Event Thread 编译线程,可能是 C1 CompilerThreadN 或者是 C2 CompilerThreadN,分别对应 C1,C2线程 C1 CompilerThread0
Adaptors 非方法堆里面元素数量 578
Code Heap 事件指的是哪个代码堆,看 CacheCache目前处于什么阶段,如果是运行阶段,则可能是:CodeHeap 'non-profiled nmethods',CodeHeap 'profiled nmethods',CodeHeap 'non-nmethods',如果程序刚启动,JVM原生的占用non-nmethod就满了),可能就是 Unused,如果还没拆分出来,则是笼统的 CodeCache Unused
Commited Top 代码缓存内存堆目前请求提交地址 140692249706496
Entries 元素个数 91512
Full Count 目前为止,CodeCacheFull次数 1
Methods 编译方法数量 854
Reserved Top 代码缓存内存堆地址 140692249706496
Start Address 代码缓存内存堆开始地址 140692249706496
Unallocated 未分配内存大小 2637824 B

CodeCacheStatistics 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Adaptors 非方法堆里面元素数量 578
Code Heap 事件指的是哪个代码堆,看 CacheCache目前处于什么阶段,如果是运行阶段,则可能是:CodeHeap 'non-profiled nmethods',CodeHeap 'profiled nmethods',CodeHeap 'non-nmethods',如果程序刚启动,JVM原生的占用non-nmethod就满了),可能就是 Unused,如果还没拆分出来,则是笼统的 CodeCache Unused
Entries 元素个数 91512
Full Count 目前为止,CodeCacheFull次数 1
Methods 编译方法数量 854
Reserved Top 代码缓存内存堆地址 140692249706496
Start Address 代码缓存内存堆开始地址 140692249706496
Unallocated 未分配内存大小 2637824 B

CodeSweeperConfiguration 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
Code Cache Flushing Enabled 是否启用了Code Cache Flushing,默认也都是启用的 true
Code Sweeper Enabled 是否启用了CodeSweeper,默认都是启用的 true

CodeSweeperStatistics 我们不关心

SweepCodeCache 事件结构

字段 描述 举例
开始时间 事件开始时间 1594215268138540326 epochns
持续时间 事件持续时间 55607927 ticks
结束时间 事件结束时间 2869587482704980480 epochticks
Event Thread 清理线程 Sweeper thread
Methods Flushed 现在为止刷新的方法数量 5
Sweep Identifier 全局唯一清理ID 737
Methods Swept 现在为止清理的方法数量 26700
Methods Zombified 现在为止僵尸化的方法数量 2
上一篇下一篇

猜你喜欢

热点阅读