11.2 即时编译器 11.2.4 实战:查看及分析即时编译结果

11.2.4 实战:查看及分析即时编译结果

一般来说,Java虚拟机的即时编译过程对用户和程序都是完全透明的,虚拟机是通过解释来执行代码还是通过编译来执行代码,对于用户来说并没有什么影响(对执行结果没有影响,速度上会有显著差别),大多数情况下用户也没有必要知道。但是HotSpot虚拟机还是提供了一些参数用来输出即时编译和某些优化措施的运行状况,以满足调试和调优的需要。本节将通过实战说明如何从外部观察Java虚拟机的即时编译行为。

本节中提到的部分运行参数需要FastDebug或SlowDebug优化级别的HotSpot虚拟机才能够支持, Product级别的虚拟机无法使用这部分参数。如果读者使用的是根据第1章的教程自己编译的JDK,请注意将“–with-debug-level”参数设置为“fastdebug”或者“slowdebug”。现在Oracle和OpenJDK网站上都已经不再直接提供FastDebug的JDK下载了(从JDK 6 Update 25之后官网上就没有再提供下载),所以要完成本节全部测试内容,读者除了自己动手编译外,就只能到网上搜索非官方编译的版本了。本次实战中所有的测试都基于代码清单11-2所示的Java代码来进行。

代码清单11-2 测试代码
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
public static final int NUM = 15000;
public static int doubleValue(int i) {
// 这个空循环用于后面演示JIT代码优化过程
for(int j=0;j<100000;j++);
return i * 2;
}
public static long calcSum() {
long sum = 0;
for (int i = 1;i <= 100;i++) {
sum += doubleValue(i);
}
return sum;
}
public static void main(String[] args) {
for (int i = 0;i < NUM;i++) {
calcSum();
}
}

我们首先来运行这段代码,并且确认这段代码是否触发了即时编译。要知道某个方法是否被编译过,可以使用参数-XX:+PrintCompilation要求虚拟机在即时编译时将被编译成本地代码的方法名称打印出来,如代码清单11-3所示(其中带有“%”的输出说明是由回边计数器触发的栈上替换编译)。

代码清单11-3 被即时编译的代码
1
2
3
4
5
VM option '+PrintCompilation' 
310 1 java.lang.String::charAt (33 bytes)
329 2 org.fenixsoft.jit.Test::calcSum (26 bytes)
329 3 org.fenixsoft.jit.Test::doubleValue (4 bytes)
332 1% org.fenixsoft.jit.Test::main @ 5 (20 bytes)

从代码清单11-3输出的信息中可以确认,main()、calcSum()和doubleValue()方法已经被编译,我们还可以加上参数-XX:+PrintInlining要求虚拟机输出方法内联信息,如代码清单11-4所示。

代码清单11-4 内联信息
1
2
3
4
5
6
7
8
9
VM option '+PrintCompilation' 
VM option '+PrintInlining'
273 1 java.lang.String::charAt (33 bytes)
291 2 org.fenixsoft.jit.Test::calcSum (26 bytes)
@ 9 org.fenixsoft.jit.Test::doubleValue inline (hot)
294 3 org.fenixsoft.jit.Test::doubleValue (4 bytes)
295 1% org.fenixsoft.jit.Test::main @ 5 (20 bytes)
@ 5 org.fenixsoft.jit.Test::calcSum inline (hot)
@ 9 org.fenixsoft.jit.Test::doubleValue inline (hot)

从代码清单11-4的输出日志中可以看到,doubleValue()方法已被内联编译到calcSum()方法中,而calcSum()方法又被内联编译到main()方法里面,所以虚拟机再次执行main()方法的时候(举例而已, main()方法当然不会运行两次),calcSum()和doubleValue()方法是不会再被实际调用的,没有任何方法分派的开销,它们的代码逻辑都被直接内联到main()方法里面了。

除了查看哪些方法被编译之外,我们还可以更进一步看到即时编译器生成的机器码内容。不过如果得到的是即时编译器输出一串0和1,对于我们人类来说是没法阅读的,机器码至少要反汇编成基本的汇编语言才可能被人类阅读。虚拟机提供了一组通用的反汇编接口^1,可以接入各种平台下的反汇编适配器,如使用32位x86平台应选用hsdis-i386适配器,64位则需要选用hsdis-amd64[^2],其余平台的适配器还有如hsdis-sparc、hsdis-sparcv9和hsdis-aarch64等,读者可以下载或自己编译出与自己机器相符合的反汇编适配器,之后将其放置在JAVA_HOME/lib/amd64/server下[^3],只要与jvm.dll或libjvm.so的路径相同即可被虚拟机调用。为虚拟机安装了反汇编适配器之后,我们就可以使用-XX: +PrintAssembly参数要求虚拟机打印编译方法的汇编代码了,关于HSDIS插件更多的操作介绍,可以参考第4章的相关内容。

如果没有HSDIS插件支持,也可以使用-XX:+PrintOptoAssembly(用于服务端模式的虚拟机) 或-XX:+PrintLIR(用于客户端模式的虚拟机)来输出比较接近最终结果的中间代码表示,代码清单11-2所示代码被编译后部分反汇编(使用-XX:+PrintOptoAssembly)的输出结果如代码清单11-5所示。对于阅读来说,使用-XX:+PrintOptoAssembly参数输出的伪汇编结果包含了更多的信息(主要是注释),有利于人们阅读、理解虚拟机即时编译器的优化结果。

代码清单11-5 本地机器码反汇编信息(部分)
1
2
3
4
5
6
7
8
9
10
11
…… …… 
000 B1: # N1 <- BLOCK HEAD IS JUNK Freq: 1
000 pushq rbp
subq rsp, #16 # Create frame
nop # nop for patch_verified_entry
006 movl RAX, RDX # spill
008 sall RAX, #1
00a addq rsp, 16 # Destroy frame
popq rbp
testl rax, [rip + #offset_to_poll_page] # Safepoint: poll for GC
…… ……

前面提到的使用-XX:+PrintAssembly参数输出反汇编信息需要FastDebug或SlowDebug优化级别的HotSpot虚拟机才能直接支持,如果使用Product版的虚拟机,则需要加入参数-XX: +UnlockDiagnosticVMOptions打开虚拟机诊断模式。

如果除了本地代码的生成结果外,还想再进一步跟踪本地代码生成的具体过程,那可以使用参数- XX:+PrintCFGToFile(用于客户端编译器)或-XX:PrintIdealGraphFile(用于服务端编译器)要求Java虚拟机将编译过程中各个阶段的数据(譬如对客户端编译器来说包括字节码、HIR生成、LIR生成、寄存器分配过程、本地代码生成等数据)输出到文件中。然后使用Java HotSpot Client Compiler Visualizer[^4](用于分析客户端编译器)或Ideal Graph Visualizer[^5](用于分析服务端编译器)打开这些数据文件进行分析。接下来将以使用服务端编译器为例,讲解如何分析即时编译的代码生成过程。这里先把重点放在编译整体过程阶段及Ideal Graph Visualizer功能介绍上,在稍后在介绍Graal编译器的实战小节里,我们会使用Ideal Graph Visualizer来详细分析虚拟机进行代码优化和生成时的执行细节,届时我们将重点关注编译器是如何实现这些优化的。

服务端编译器的中间代码表示是一种名为理想图(Ideal Graph)的程序依赖图(Program Dependence Graph,PDG),在运行Java程序的FastDebug或SlowDebug优化级别的虚拟机上的参数中加入“-XX:PrintIdealGraphLevel=2-XX:PrintIdeal-GraphFile=ideal.xml”,即时编译后将会产生一个名为ideal.xml的文件,它包含了服务端编译器编译代码的全过程信息,可以使用Ideal Graph Visualizer对这些信息进行分析。

image-20211126114437962

图11-6 编译过的方法列表

Ideal Graph Visualizer加载ideal.xml文件后,在Outline面板上将显示程序运行过程中编译过的方法列表,如图11-6所示。这里列出的方法是代码清单11-2中所示的测试代码,其中doubleValue()方法出现了两次,这是由于该方法的编译结果存在标准编译和栈上替换编译两个版本。在代码清单11-2中,专门为doubleValue()方法增加了一个空循环,这个循环对方法的运算结果不会产生影响,但如果没有任何优化,执行该循环就会耗费处理器时间。直到今天还有不少程序设计的入门教程会把空循环当作程序延时的手段来介绍,下面我们就来看看在Java语言中这样的做法是否真的能起到延时的作用。

展开方法根节点,可以看到下面罗列了方法优化过程的各个阶段(根据优化措施的不同,每个方法所经过的阶段也会有所差别)的理想图,我们先打开“After Parsing”这个阶段。前面提到,即时编译器编译一个Java方法时,首先要把字节码解析成某种中间表示形式,然后才可以继续做分析和优化, 最终生成代码。“After Parsing”就是服务端编译器刚完成解析,还没有做任何优化时的理想图表示。打开这个图后,读者会看到其中有很多有颜色的方块,如图11-7所示。每一个方块代表了一个程序的基本块(Basic Block)。基本块是指程序按照控制流分割出来的最小代码块,它的特点是只有唯一的一个入口和唯一的一个出口,只要基本块中第一条指令被执行了,那么基本块内所有指令都会按照顺序全部执行一次。

image-20211126114606819

图11-7 基本块图示(1)

代码清单11-2所示的doubleValue()方法虽然只有简单的两行字,但是按基本块划分后,形成的图形结构却要比想象中复杂得多,这是因为一方面要满足Java语言所定义的安全需要(如类型安全、空指针检查)和Java虚拟机的运作需要(如Safepoint轮询),另一方面有些程序代码中一行语句就可能形成几个基本块(例如循环语句)。对于例子中的doubleValue()方法,如果忽略语言安全检查的基本块, 可以简单理解为按顺序执行了以下几件事情:

可以简单理解为按顺序执行了以下几件事情:
1)程序入口,建立栈帧。
2)设置j=0,进行安全点(Safepoint)轮询,跳转到4的条件检查。
3)执行j++。
4)条件检查,如果j<100000,跳转到3。
5)设置i=i*2,进行安全点轮询,函数返回。

以上几个步骤反映到Ideal Graph Visualizer生成的图形上,就是图11-8所示的内容。这样我们若想看空循环是否被优化掉,或者何时被优化掉,只要观察代表循环的基本块是否被消除掉,以及何时被优化掉就可以了。

image-20211126114717078

图11-8 基本块图示(2)

要观察这一点,可以在Outline面板上右击“Difference to current graph”,让软件自动分析指定阶段与当前打开的理想图之间的差异,如果基本块被消除了,将会以红色显示。对“After Parsing”和“PhaseIdealLoop 1”阶段的理想图进行差异分析,会发现在“PhaseIdealLoop 1”阶段循环操作就被消除了,如图11-9所示,这也就说明空循环在最终的本地代码里实际上是不会被执行的。

image-20211126114751677

图11-9 基本块图示(3)

从“After Parsing”阶段开始,一直到最后的“Final Code”阶段都可以看到doubleValue()方法的理想图从繁到简的变迁过程,这也反映了Java虚拟机即时编译器尽力优化代码的过程。到了最后的“Final Code”阶段,不仅空循环的开销被消除了,许多语言安全保障措施和GC安全点的轮询操作也被一起消除了,因为编译器判断到即使不做这些保障措施,程序也能得到相同的结果,不会有可观察到的副作用产生,虚拟机的运行安全也不会受到威胁。

[^2]: HSDIS的源码可以从HotSpot虚拟机源码仓库中获取(路径为:src\utils\hsdis),具体可以参见第1 章。此源码需要执行编译,对于HSDIS的编译,读者可以参考AdoptOpenJDK的官方GitHub: https://github.com/AdoptOpenJDK/jitwatch/wiki/Building-hsdis/。如果不想自己编译,在GitHub上搜 索“hsdis-i386.so/dll”“hsdis-amd64.so/dll”这样的关键词也可以找到不少编译好的Linux或Windows的 HSDIS插件。
[^3]: 如果使用JDK 8或之前版本,应放在JRE_HOME/bin/server目录下。
[^4]: 官方站点:http://ssw.jku.at/Research/Projects/JVM/CCVis.html。
[^5]: 官方站点:http://ssw.jku.at/General/Staff/TW/igv.html。