了解-XX的输出：+ PrintCompilation

我正在Java列表迭代代码上运行一些微型基准测试。我使用了-XX：+ PrintCompilation和-verbose：gc标志来确保在计时运行时后台没有任何事情发生。但是，我在输出中看到了一些我无法理解的东西。了解-XX的输出：+ PrintCompilation

下面的代码，我上运行的风向标：

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)

为什么这两种方法都被编译两次？
我如何读取这个输出......各种数字意味着什么？

来源

2012-10-26 Parag

感谢@Thomas Jungblut不知道我怎么错过了-XX：+ PrintCompilation从标题 – Parag

np，这里是关于汇编的一个很好的资源：https://gist.github.com/1165804#file_notes.md –

我打算尝试用Thomas Jungblut发布的link帮助回答我自己的问题。

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' 是时间戳。

第二列

第二列是compilation_id和method_attributes。当一个HotSpot编译被触发时，每个编译单元都会得到一个编译ID。第二列中的数字是编译ID。 JIT编译和OSR编译对于编译ID有两个不同的序列。所以1％和1是不同的编译单元。前两行中的％表示这是OSR编译的事实。 OSR编译被触发是因为代码正在循环大循环，并且VM确定此代码很热。因此，一个OSR编译被触发，这将使VM能够进行堆栈替换，并在准备就绪后转移到优化的代码。

第三塔

第三列performance.api.PerformantIteration::iterateWithConstantSize是方法名。

第四栏

第四列是再不同的，当OSR编译发生，当它没有。我们先看看通用部分。第四列（59字节）的末尾是指字节码中编译单元的大小（不是编译代码的大小）。 OSR编译中的@ 19部分引用了osr_bci。我会从上述链接引用 - 在Java方法

A“地方”是由触发OSR编译被称为“osr_bci”的字节码指数（BCI），并的地方定义。 OSR编译的nmethod只能从其osr_bci输入;那么可以是同一个时间的相同方法的多个OSR编译版本，只要它们的osr_bci不同即可。

最后，为什么该方法编译两次？

第一个是一个OSR汇编，而循环是由于（在该示例中）延伸到预热代码这大概发生，并且所述第二编译是一个JIT编译，大概是为了进一步优化编译代码？

来源

2012-10-26 13:45:50 Parag

如果你在热身期间得到OSR代码“你做错了”。还列出了JVM的参数，它可能只是C1（客户机/哑编译器）和C2（更智能，速度慢的编译器）。重新编译也可以是去优化的结果。最简单的（？）方法是列出生成的代码，如果您看到C1存根，那么您知道它是C1代码。 – bestsss

@bestsss这是为什么？我认为OSR编译正在发生，因为示例的热身代码调用了一个大循环。 – Parag

我的观点是如果你试图预热任何东西，你应该避免OSR，用更小的方法分割它。 – bestsss

-1

我觉得第一次OSR发生了，那么它改变调用计数器跳跳虎方法compilar （PS：对不起，我的英语是池）

来源

2014-08-28 03:44:30 wgz

了解-XX的输出：+ PrintCompilation

回答

相关问题