20

Java リスト反復コードでいくつかのマイクロ ベンチマークを実行しています。-XX:+PrintCompilation および -verbose:gc フラグを使用して、タイミングの実行中にバックグラウンドで何も起こらないようにしました。ただし、出力に理解できないものがあります。

コードは次のとおりです。ベンチマークを実行しています。

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


出力からのこれらの 4 行がわかりません。

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)


  • これらのメソッドが両方とも 2 回コンパイルされるのはなぜですか?
  • この出力をどのように読むのですか...さまざまな数字は何を意味していますか?
4

2 に答える 2

19

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」はタイムスタンプです。

2列目

2 列目は、compilation_id と method_attributes です。HotSpot コンパイルがトリガーされると、すべてのコンパイル ユニットがコンパイル ID を取得します。2 列目の数字はコンパイル ID です。JIT コンパイルと OSR コンパイルには、コンパイル ID の 2 つの異なるシーケンスがあります。したがって、1% と 1 は異なるコンパイル単位です。最初の 2 行の % は、これが OSR コンパイルであることを示しています。コードが大規模なループをループしており、VM がこのコードがホットであると判断したため、OSR コンパイルがトリガーされました。そのため、OSR コンパイルがトリガーされました。これにより、VM はオン スタック置換を実行し、準備ができたら最適化されたコードに移行できます。

3列目

3 列目performance.api.PerformantIteration::iterateWithConstantSizeはメソッド名です。

4列目

4 番目の列は、OSR コンパイルが行われる場合と行われない場合で再び異なります。まずは共通部分から見ていきましょう。4 番目の列の終わり (59 バイト) は、コンパイル単位のサイズをバイトコードで示します (コンパイルされたコードのサイズではありません)。OSR コンパイルの @ 19 の部分は、osr_bci を参照します。上記のリンクから引用します -

Java メソッドの「場所」はそのバイトコード インデックス (BCI) によって定義され、OSR コンパイルをトリガーした場所は「osr_bci」と呼ばれます。OSR でコンパイルされた nmethod は、その osr_bci からのみ入力できます。osr_bci が異なる限り、同じメソッドの複数の OSR コンパイル バージョンが同時に存在する可能性があります。

最後に、メソッドが 2 回コンパイルされたのはなぜですか?

1 つ目は OSR コンパイルで、ウォームアップ コード (例) が原因でループの実行中に発生したと考えられ、2 つ目のコンパイルは JIT コンパイルであり、おそらくコンパイルされたコードをさらに最適化します。

于 2012-10-26T13:45:50.177 に答える
0

OSR が最初に発生したとき、Invocation Counter tigger メソッド コンパイルが変更されたと思います (PS: 申し訳ありませんが、私の英語はプールです)。

于 2014-08-28T03:44:30.180 に答える