了解-XX：+ PrintCompilation的输出 [英] Understanding the output of -XX:+PrintCompilation
问题描述
我在Java列表迭代代码上运行一些微基准测试。我使用了-XX：+ PrintCompilation和-verbose：gc标志来确保在运行定时时后台没有发生任何事情。但是，我在输出中看到了一些我无法理解的内容。
I am running some micro benchmarks on Java list iteration code. I have used -XX:+PrintCompilation, and -verbose:gc flags to ensure that nothing is happening in the background when the timing is being run. However, I see something in the output which I cannot understand.
这是代码，我正在运行基准测试：
import java.util.ArrayList;
import java.util.List;
public class PerformantIteration {
private static int theSum = 0;
public static void main(String[] args) {
System.out.println("Starting microbenchmark on iterating over collections with a call to size() in each iteration");
List<Integer> nums = new ArrayList<Integer>();
for(int i=0; i<50000; i++) {
nums.add(i);
}
System.out.println("Warming up ...");
//warmup... make sure all JIT comliling is done before the actual benchmarking starts
for(int i=0; i<10; i++) {
iterateWithConstantSize(nums);
iterateWithDynamicSize(nums);
}
//actual
System.out.println("Starting the actual test");
long constantSizeBenchmark = iterateWithConstantSize(nums);
long dynamicSizeBenchmark = iterateWithDynamicSize(nums);
System.out.println("Test completed... printing results");
System.out.println("constantSizeBenchmark : " + constantSizeBenchmark);
System.out.println("dynamicSizeBenchmark : " + dynamicSizeBenchmark);
System.out.println("dynamicSizeBenchmark/constantSizeBenchmark : " + ((double)dynamicSizeBenchmark/(double)constantSizeBenchmark));
}
private static long iterateWithDynamicSize(List<Integer> nums) {
int sum=0;
long start = System.nanoTime();
for(int i=0; i<nums.size(); i++) {
// appear to do something useful
sum += nums.get(i);
}
long end = System.nanoTime();
setSum(sum);
return end-start;
}
private static long iterateWithConstantSize(List<Integer> nums) {
int count = nums.size();
int sum=0;
long start = System.nanoTime();
for(int i=0; i<count; i++) {
// appear to do something useful
sum += nums.get(i);
}
long end = System.nanoTime();
setSum(sum);
return end-start;
}
// invocations to this method simply exist to fool the VM into thinking that we are doing something useful in the loop
private static void setSum(int sum) {
theSum = sum;
}
}
这是输出。
152 1 java.lang.String::charAt (33 bytes)
160 2 java.lang.String::indexOf (151 bytes)
165 3Starting microbenchmark on iterating over collections with a call to size() in each iteration java.lang.String::hashCode (60 bytes)
171 4 sun.nio.cs.UTF_8$Encoder::encodeArrayLoop (490 bytes)
183 5
java.lang.String::lastIndexOf (156 bytes)
197 6 java.io.UnixFileSystem::normalize (75 bytes)
200 7 java.lang.Object::<init> (1 bytes)
205 8 java.lang.Number::<init> (5 bytes)
206 9 java.lang.Integer::<init> (10 bytes)
211 10 java.util.ArrayList::add (29 bytes)
211 11 java.util.ArrayList::ensureCapacity (58 bytes)
217 12 java.lang.Integer::valueOf (35 bytes)
221 1% performance.api.PerformantIteration::main @ 21 (173 bytes)
Warming up ...
252 13 java.util.ArrayList::get (11 bytes)
252 14 java.util.ArrayList::rangeCheck (22 bytes)
253 15 java.util.ArrayList::elementData (7 bytes)
260 2% performance.api.PerformantIteration::iterateWithConstantSize @ 19 (59 bytes)
268 3% performance.api.PerformantIteration::iterateWithDynamicSize @ 12 (57 bytes)
272 16 performance.api.PerformantIteration::iterateWithConstantSize (59 bytes)
278 17 performance.api.PerformantIteration::iterateWithDynamicSize (57 bytes)
Starting the actual test
Test completed... printing results
constantSizeBenchmark : 301688
dynamicSizeBenchmark : 782602
dynamicSizeBenchmark/constantSizeBenchmark : 2.5940773249184588
我不理解输出中的这四行。
260 2% performance.api.PerformantIteration::iterateWithConstantSize @ 19 (59 bytes)
268 3% performance.api.PerformantIteration::iterateWithDynamicSize @ 12 (57 bytes)
272 16 performance.api.PerformantIteration::iterateWithConstantSize (59 bytes)
278 17 performance.api.PerformantIteration::iterateWithDynamicSize (57 bytes)
- 为什么这两种方法都被编译两次？
- 如何读取此输出...各种数字是什么意思？
推荐答案
我将尝试回答我自己的问题这个 Thomas Jungblut 发布的低noreferrer>链接。
I am going to attempt answering my own question with the help of this link posted by Thomas Jungblut.
260 2% performance.api.PerformantIteration::iterateWithConstantSize @ 19 (59 bytes)
268 3% performance.api.PerformantIteration::iterateWithDynamicSize @ 12 (57 bytes)
272 16 performance.api.PerformantIteration::iterateWithConstantSize (59 bytes)
278 17 performance.api.PerformantIteration::iterateWithDynamicSize (57 bytes)
第一栏
第一栏'260'是时间戳。
The first column '260' is the timestamp.
第二栏
第二列是compilation_id和method_attributes。触发HotSpot编译时，每个编译单元都会获得编译ID。第二列中的数字是编译ID。 JIT编译和OSR编译有两个不同的编译ID序列。所以1％和1是不同的编译单元。前两行中的％表示这是OSR编译的事实。由于代码在大循环上循环，并且VM确定此代码很热，因此触发了OSR编译。因此，触发了OSR编译，这将使VM能够进行堆栈替换并在准备就绪后转移到优化代码。
The second column is the compilation_id and method_attributes. When a HotSpot compilation is triggered, every compilation unit gets a compilation id. The number in the second column is the compilation id. JIT compilation, and OSR compilation have two different sequences for the compilation id. So 1% and 1 are different compilation units. The % in the first two rows, refer to the fact that this is an OSR compilation. An OSR compilation was triggered because the code was looping over a large loop, and the VM determined that this code is hot. So an OSR compilation was triggered, which would enable the VM to do an On Stack Replacement and move over to the optimized code, once it is ready.
第三专栏
第三列 performance.api.PerformantIteration :: iterateWithConstantSize 是方法名称。
第四栏
当OSR编译发生时和它不是。我们先来看看常见的部分。第四列的末尾（59字节），指的是字节码中编译单元的大小（不是编译代码的大小）。 OSR编译中的@ 19部分是指osr_bci。我将引用上面提到的链接 -
The fourth column is again different when OSR compilation happens and when it does not. Let's look at the common parts first. The end of the fourth column (59 bytes), refers to the size of the compilation unit in bytecode (not the size of the compiled code). The @ 19 part in OSR compilation refers to the osr_bci. I am going to quote from the link mentioned above -
Java方法中的地点由其字节码索引（BCI）定义和
触发OSR编译的地方称为osr_bci。
OSR编译的nmethod只能从其osr_bci输入;只要他们的osr_bci不同，
可以是相同方法的多个OSR编译版本，只要他们的osr_bci不同。
A "place" in a Java method is defined by its bytecode index (BCI), and the place that triggered an OSR compilation is called the "osr_bci". An OSR-compiled nmethod can only be entered from its osr_bci; there can be multiple OSR-compiled versions of the same method at the same time, as long as their osr_bci differ.
最后，为什么方法编译了两次？
第一个是OSR编译，可能是在循环时发生的由于预热代码（在示例中）正在运行，第二次编译是JIT编译，可能是为了进一步优化编译代码？
The first one is an OSR compilation, which presumably happened while the loop was running due to the warmup code (in the example), and the second compilation is a JIT compilation, presumably to further optimize the compiled code ?
这篇关于了解-XX：+ PrintCompilation的输出的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！
