コマンドラインから Java* コードを解析

インテル® VTune™ プロファイラーは、Oracle* JDK* または OpenJDK* で実行された JIT コンパイル済みのコードで、オーバーヘッドの少ないユーザーモード・サンプリングとトレースおよびハードウェア・イベントベース・サンプリング解析を提供します。解釈された Java* メソッドの解析は制限されます。

ハードウェア・イベントベース・サンプリングによるデータ収集を使用して、CPU のパイプラインのハードウェア・イベントをモニターし、効率良い命令実行を制限するコードの過ちを特定します。ハードウェア・パフォーマンス・メトリックが利用でき、アプリケーションのモジュール、関数、Java* コードのソース行に対して表示することができます。また、ドライバーやシステムのミドルウェア層で呼び出された関数の呼び出しパスを調べる必要がある場合、スタックを含むハードウェア・イベントベースのサンプリング収集を利用できます。

Java* 収集を設定する

コマンドラインから Java* 解析を実行するには、次の構文を使用します。

vtune -collect <analysis_type> [-[no-]follow-child] [-mrte-mode=<mrte_mode_value>] [<-knob> <knob_name=knob_option>] [--] <target>

説明:

事前定義解析タイプで利用可能な knob を確認するには、vtune -help collect <analysis_type> コマンドを入力します。

カスタム解析タイプで利用可能な knob を確認するには、vtune -help collect-with <analysis_type> コマンドを入力します。

例 1: Java* 解析の実行

次のコマンドラインは、Linux* 上で java コマンドでホットスポット解析を実行します。

vtune -collect hotspots -- java -Xcomp -Djava.library.path=native_lib/ia32 -cp /home/Design/Java/mixed_call MixedCall 3 2

例 2: 組込み Java* コマンドの解析を実行

解析を実行する前に、java* コマンドをバッチファイル、または実行可能スクリプトに埋め込むことができます。例えば、Windows* では次のコマンドで run.bat ファイルを作成します。

java.exe -Xcomp -Djava.library.path=native_lib\ia32 -cp C:\Design\Java\mixed_call MixedCall 3 1

次のコマンドラインは、組込み java コマンドを使用して、指定するバッチファイルのホットスポット解析を実行します。

vtune -collect hotspots -- run.bat

例 3: Java* プロセスにアタッチして解析

Java* アプリケーションをしばらく実行する必要がある場合や、解析を開始するときに起動できない場合、インテル® VTune™ プロファイラーを Java* プロセスにアタッチすることができます。これを行うには、--target-process java で解析ターゲットを指定します。

動的なアタッチは、Java* 開発キット (JDK*) でのみサポートされます。

次の例では、Linux* 上で実行される Java* プロセスにホットスポット解析をアタッチします。

vtune -collect hotspots --target-process java

サマリーレポートの表示

データ収集が完了すると、インテル® VTune™ プロファイラーは自動的に summary レポートを生成します。GUI で利用可能な [サマリー] ウィンドウと同様に、コマンドライン・レポートは Java* ターゲットの全体的なパフォーマンス・データを提供します。

サマリーレポートのデータ解析の詳細は、「サマリーレポート」を参照してください。

次の例は、ホットスポット解析結果のサマリーサポートを生成します。ユーザーモード・サンプリングとトレース解析の結果では、サマリーレポートには収集とプラットフォーム情報、CPU 情報と基本メトリックごとのサマリーが含まれます。

Windows*:


    Collection and Platform Info
    ----------------------------
    Parameter                 r001hs

    ------------------------  ------------------------------------------
    Operating System          Microsoft Windows 10
    Result Size               21258782
    Collection start time     11:58:36 15/04/2019 UTC
    Collection stop time      11:58:50 15/04/2019 UTC

    CPU
    ---
    Parameter          r001hs
    -----------------  -------------------------------------------------
    Name               4th generation Intel® Core™ Processor family
    Frequency          2494227391
    Logical CPU Count  4

    Summary
    -------
    Elapsed Time:    12.939
    CPU Time:        14.813
    Average CPU Usage: 1.012

Linux*:


    Collection and Platform Info
    ----------------------------
    Parameter                 r002hs
    -------------------------------------------------------------------
    Application Command Line  /tmp/java_mixed_call/src/run.sh

    Operating System          3.16.0-30-generic NAME="Ubuntu"
    VERSION="14.04.2 LTS, Trusty Tahr"
    ID=ubuntu
    ID_LIKE=debian
    PRETTY_NAME="Ubuntu 14.04.2 LTS"
    VERSION_ID="14.04"
    HOME_URL="http://www.ubuntu.com/"
    SUPPORT_URL="http://help.ubuntu.com/"
    BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
    Computer Name             10.125.21.55

    Result Size               11560723

    Collection start time     13:55:00 05/02/2019 UTC

    Collection stop time      13:55:10 05/02/2019 UTC


    CPU
    ---
    Parameter          r001hs
    -----------------  -------------------------------------------------
    Name               3rd generation Intel® Core™ Processor family
    Frequency          3492067692
    Logical CPU Count  8

    Summary
    -------
    Elapsed Time:    10.183
    CPU Time:        19.200
    Average CPU Usage: 1.885

この例は、ホットスポット解析 (ハードウェア・イベントベース・サンプリング・モード) 結果のサマリーレポートを生成します。ハードウェア・イベントベース・サンプリング解析の結果では、サマリーレポートには収集とプラットフォーム情報、CPU 情報、基本メトリックごとのサマリー、およびイベントのサマリーが含まれます。


    Collection and Platform Info
    ----------------------------
    Parameter                 r002hs

    ------------------------  ------------------------------------------
    Operating System          3.16.0-30-generic NAME="Ubuntu"
    VERSION="14.04.2 LTS, Trusty Tahr"
    ID=ubuntu
    ID_LIKE=debian
    PRETTY_NAME="Ubuntu 14.04.2 LTS"
    VERSION_ID="14.04"
    HOME_URL="http://www.ubuntu.com/"
    SUPPORT_URL="http://help.ubuntu.com/"
    BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
    Result Size               171662827
    Collection start time     10:44:34 15/04/2019 UTC
    Collection stop time      10:44:50 15/04/2019 UTC

    CPU
    ---
    Parameter          r002hs
    -----------------  -------------------------------------------------
    Name               4th generation Intel® Core™ Processor family
    Frequency          2494227445
    Logical CPU Count  4

    Summary
    -------
    Elapsed Time:    15.463
    CPU Time:        6.392
    Average CPU Usage: 0.379
    CPI Rate:        1.318

    Event summary
    -------------
    Hardware Event Type         Hardware Event Count:Self  Hardware Event Sample Count:Self  Events Per Sample
    --------------------------  -------------------------  --------------------------------  -----------------
    INST_RETIRED.ANY                          13014608235                              8276  1900000
    CPU_CLK_UNHALTED.THREAD                   17158609921                              8207  1900000
    CPU_CLK_UNHALTED.REF_TSC                  15942400300                              5163  1900000
    BR_INST_RETIRED.NEAR_TAKEN                 1228364727                              4648  200003
    CALL_COUNT                                  213650621                             75413  1
    ITERATION_COUNT                             370567815                             84737  1
    LOOP_ENTRY_COUNT                            162943310                             70069  1

最もホットなメソッドを特定する

hotspots コマンドライン・レポートを開始点として、最も多くのプロセッサー時間を要する (ホットスポット解析)、利用可能な CPU を活用していない、または待機時間が長い (スレッド化解析) などの問題があるプログラム単位 (関数、モジュール、オブジェクトなど) を特定します。

このレポートではデフォルトで、最もパフォーマンス上重要なユニットから、最もホットなプログラム単位が降順で表示されます。コマンドライン・レポートは、デフォルトの GUI 解析ビューポイントで表示される内容と同じデータが示されます。

  • hotspots レポートで利用可能なグループのリストを表示するには、vtune -report hotspots -r <result_dir> group-by=? と入力します。
  • レポートに含める上位の項目数を設定するには、limit アクションオプションを使用して、vtune -report <report_type> -limit <value> -r <result_dir> と入力します。

この例は、指定したホットスポット解析結果の hotspots レポートを生成し、モジュール別にデータをグループ化します。結果が指定されていないため、インテル® VTune™ プロファイラーは最新の解析結果を使用します。

vtune -report hotspots

Windows*:


    Function               CPU Time  CPU Time:Effective Time  CPU Time:Effective Time:Idle  CPU Time:Effective Time:Poor  CPU Time:Effective Time:Ok  CPU Time:Effective Time:Ideal  CPU Time:Effective Time:Over  CPU Time:Spin Time  CPU Time:Overhead Time  Module          Function (Full)        Source File   Start Address
    ---------------------  --------  -----------------------  ----------------------------  ----------------------------  --------------------------  -----------------------------  ----------------------------
    consume_time            10.371s                  10.371s                            0s                       10.341s                      0.020s                         0.010s                            0s                  0s                      0s  mixed_call.dll  consume_time           mixed_call.c  0x180001000
    NtWaitForSingleObject    1.609s                       0s                            0s                            0s                          0s                             0s                            0s              1.609s                      0s  ntdll.dll       NtWaitForSingleObject  [Unknown]     0x1800906f0
    WriteFile                0.245s                   0.245s                        0.009s                        0.190s                      0.030s                         0.016s                            0s                  0s                      0s  KERNELBASE.dll  WriteFile              [Unknown]     0x180001c50
    func@0x707d5440          0.114s                   0.010s                            0s                        0.010s                          0s                             0s                            0s              0.104s                      0s  jvm.dll         func@0x707d5440        [Unknown]     0x707d5440
    func@0x705be5c0          0.072s                   0.025s                            0s                        0.025s                          0s                             0s                            0s              0.047s                      0s  jvm.dll         func@0x705be5c0        [Unknown]     0x705be5c0
    ...

Linux*:


    Function            CPU Time  CPU Time:Effective Time  CPU Time:Effective Time:Idle  CPU Time:Effective Time:Poor  CPU Time:Effective Time:Ok  CPU Time:Effective Time:Ideal  CPU Time:Effective Time:Over  CPU Time:Spin Time  CPU Time:Overhead Time  Module            Function (Full)     Source File  Start Address
    ------------------  --------  -----------------------  ----------------------------  ----------------------------  --------------------------  -----------------------------  ----------------------------
    [libmixed_call.so]   17.180s                  17.180s                            0s                       17.180s                          0s                             0s                            0s                  0s                      0s  libmixed_call.so  [libmixed_call.so]  [Unknown]    0

    [libjvm.so]           1.698s                   1.698s                        0.020s                        1.678s                          0s                             0s                            0s                  0s                      0s  libjvm.so         [libjvm.so]         [Unknown]    0

    [libpthread.so.0]     0.136s                   0.136s                            0s                        0.136s                          0s                             0s                            0s                  0s                      0s  libpthread.so.0   [libpthread.so.0]   [Unknown]    0

    [libtpsstool.so]      0.052s                   0.052s                            0s                        0.052s                          0s                             0s                            0s                  0s                      0s  libtpsstool.so    [libtpsstool.so]    [Unknown]    0
    ...

次の例では、指定するホットスポット解析結果 (ハードウェア・イベントベース・サンプリング・モード) の hotspots・レポートに含める項目数を 3 つに設定し、アプリケーション・モジュールごとにレポートのデータをグループ化します。

vtune -report hotspots -limit 3 -r r002hs -group-by module

Windows*:


    Module          CPU Time  CPU Time:Effective Time  CPU Time:Effective Time:Idle  CPU Time:Effective Time:Poor  CPU Time:Effective Time:Ok  CPU Time:Effective Time:Ideal  CPU Time:Effective Time:Over  CPU Time:Spin Time  CPU Time:Overhead Time  Instructions Retired  CPI Rate  Wait Rate  CPU Frequency Ratio  Context Switch Time  Context Switch Time:Wait Time  Context Switch Time:Inactive Time  Context Switch Count  Context Switch Count:Preemption  Context Switch Count:Synchronization  Module Path
    --------------  --------  -----------------------  ----------------------------  ----------------------------  --------------------------  -----------------------------  ----------------------------  -------
    mixed_call.dll   15.294s                  15.294s                        0.419s                       14.871s                      0.004s                             0s                            0s                  0s                      0s        21,148,958,284     1.907      0.000                1.149               1.401s                             0s                             1.401s                26,769                           26,769                                     0  C:\work\module Java\module Java\java_mixed_call\vc9\bin32\mixed_call.dll
    jvm.dll           0.582s                   0.582s                        0.033s                        0.547s                      0.002s                             0s                            0s                  0s                      0s           792,807,896     1.513      0.437                0.899               0.047s                         0.005s                             0.042s                   462                              451                                    11  C:\Program Files (x86)\Java\jre8\bin\client\jvm.dll
    ntoskrnl.exe      0.404s                   0.404s                        0.034s                        0.370s                      0.001s                             0s                            0s                  0s                      0s           660,557,183     1.096      0.000                0.780                                                                                                                                                                                      C:\WINDOWS\system32\ntoskrnl.exe
    ...

Linux*:


    Module            CPU Time  CPU Time:Effective Time  CPU Time:Effective Time:Idle  CPU Time:Effective Time:Poor  CPU Time:Effective Time:Ok  CPU Time:Effective Time:Ideal  CPU Time:Effective Time:Over  CPU Time:Spin Time  CPU Time:Overhead Time  Instructions Retired  CPI Rate  Wait Rate  CPU Frequency Ratio  Context Switch Time  Context Switch Time:Wait Time  Context Switch Time:Inactive Time  Context Switch Count  Context Switch Count:Preemption  Context Switch Count:Synchronization  Module Path
    ----------------  --------  -----------------------  ----------------------------  ----------------------------  --------------------------  -----------------------------  ----------------------------  ------
    libmixed_call.so   15.294s                  15.294s                        0.419s                       14.871s                      0.004s                             0s                            0s                  0s                      0s        21,148,958,284     1.907      0.000                1.149               1.401s                             0s                             1.401s                26,769                           26,769                                     0  /tmp/java_mixed_call/src/libmixed_call.so
    libjvm.so           0.582s                   0.582s                        0.033s                        0.547s                      0.002s                             0s                            0s                  0s                      0s           792,807,896     1.513      0.437                0.899               0.047s                         0.005s                             0.042s                   462                              451                                       11  /tmp/java_mixed_call/src/libmjvm.so
    ...
    ...

スタック解析

Java* アプリケーションのパフォーマンスを最大限に引き出すには、Java* プロジェクトのパフォーマンスが求められるモジュールを C やアセンブリーなどのネイティブ言語で作成してコンパイルします。これは、アプリケーションがベクトル化を利用し、強力な CPU リソースを最大限活用するのに役立ちます。このプログラミング手法を用いることで、ベクトル・コンピューティング (SIMD ユニットと命令セットにより実装) のような強力な CPU リソースを使用することができます。この場合、計算を多用する関数がホットスポットとしてプロファイル結果に表示されます。それらの関数は、大部分の処理を行うため、これは期待された結果と言えます。しかし、ホットスポット関数だけでなく、それらの関数が JNI インターフェイスを介して呼び出される Java* コードの位置を特定したいこともあります。言語が混在するアルゴリズム実装においてそのようなクロスランタイム呼び出しをトレースすることは課題の 1 つです。

callstacks レポートを使用して、各ホットスポット関数の完全なスタックデータを表示し、それぞれのスタックが関数の CPU 時間や待機時間に与える影響を特定できます。

callstacks レポートで利用可能なグループのリストを表示するには、vtune -report callstacks -r <result_dir> group-by=? と入力します。

次のコマンドラインは、指定する基本ホットスポット解析結果の callstacks レポートを生成します。

Windows*:


    Function      Function Stack             CPU Time  Module                Function (Full)                 Source File     Start Address
    ------------  -------------------------  --------  --------------------  ------------------------------  --------------  -------------
    consume_time                              10.371s  mixed_call.dll        consume_time                    mixed_call.c    0x180001000
    MixedCall::CallNativeFunc   10.371s  [Compiled Java code]  MixedCall::CallNativeFunc(int)  MixedCall.java  0x186debc0
    MixedCall::foo4                  0s  [Compiled Java code]  MixedCall::foo4(int)            MixedCall.java  0x186c1ae3
    MixedCall::foo3                  0s  [Compiled Java code]  MixedCall::foo3(int)            MixedCall.java  0x186bb583
    MixedCall::foo2                  0s  [Compiled Java code]  MixedCall::foo2(int)            MixedCall.java  0x186bb583
    MixedCall::foo1                  0s  [Compiled Java code]  MixedCall::foo1(int)            MixedCall.java  0x186bb583
    MixedCall::run                   0s  [Compiled Java code]  MixedCall::run()                MixedCall.java  0x186bb19d
    call_stub                        0s  [Dynamic code]        call_stub                       [Unknown]       0x18010827
    ...

Linux*:


    Function            Function Stack             CPU Time  Module                Function (Full)                 Source File     Start Address
    ------------------  -------------------------  --------  --------------------  ------------------------------  --------------  --------------
    [libmixed_call.so]                              17.180s  libmixed_call.so      [libmixed_call.so]              [Unknown]       0
    [libmixed_call.so]           8.600s  libmixed_call.so      [libmixed_call.so]              [Unknown]       0
    MixedCall::CallNativeFunc        0s  [Compiled Java code]  MixedCall::CallNativeFunc(int)  MixedCall.java  0x7fb63937eec0
    MixedCall::foo4                  0s  [Compiled Java code]  MixedCall::foo4(int)            MixedCall.java  0x7fb6393831e3
    MixedCall::foo3                  0s  [Compiled Java code]  MixedCall::foo3(int)            MixedCall.java  0x7fb63938046c
    MixedCall::foo2                  0s  [Compiled Java code]  MixedCall::foo2(int)            MixedCall.java  0x7fb63938046c
    MixedCall::foo1                  0s  [Compiled Java code]  MixedCall::foo1(int)            MixedCall.java  0x7fb63938046c
    MixedCall::run                   0s  [Compiled Java code]  MixedCall::run()                MixedCall.java  0x7fb63938009b
    ...

ハードウェア・メトリックを解析

インテル® VTune™ プロファイラーは、プラットフォームの CPU マイクロアーキテクチャー向けに Java* アプリケーションを最適化する高度なプロファイル・オプションを提供します。Java* や JVM* テクノロジーは、ハードウェア・アーキテクチャー固有のコーディングから開発者を解放するように意図されていますが、Java* コードを現在のインテル® アーキテクチャー向けに最適化すれば、将来の世代の CPU でも、おそらくこの利点は維持されます。

インテル® VTune™ プロファイラーは、ハードウェア・イベントベース・サンプリング収集中のハードウェア・イベント数をカウントして、Java* アプリケーションが利用可能なハードウェア・リソースをどのように利用しているか理解するのを支援します。hw-events レポートタイプを使用して、アプリケーション関数ごとのハードウェア・イベント数を降順 (デフォルト) で表示します。

Thw-events レポートで利用可能なグループのリストを表示するには、vtune -report hw-events -r <result_dir> group-by=? と入力します。

この例は、指定したホットスポット解析結果 (ハードウェア・イベントベース・サンプリング・モード) で、hw-events レポートを生成します。

Windows*:


    Function               Hardware Event Count:INST_RETIRED.ANY  Hardware Event Count:CPU_CLK_UNHALTED.THREAD  Hardware Event Count:CPU_CLK_UNHALTED.REF_TSC  Hardware Event Count:BR_INST_RETIRED.NEAR_TAKEN  Hardware Event Count:ITERATION_COUNT  Hardware Event Count:LOOP_ENTRY_COUNT  Hardware Event Count:CALL_COUNT  Context Switch Time  Context Switch Time:Wait Time  Context Switch Time:Inactive Time  Context Switch Count  Context Switch Count:Preemption  Context Switch Count:Synchronization  Module          Function (Full)        Source File   Start Address
    ---------------------  -------------------------------------  --------------------------------------------  ---------------------------------------------  -----------------------------------------------
    consume_time                                   8,649,248,560                                28,577,118,234                                 25,656,728,125                                      126,927,912                           126,914,825                                      0                                0               0.217s                             0s                             0.217s                 4,147                            4,147                                     0  mixed_call.dll  consume_time           mixed_call.c  0x180001000
    NtWaitForSingleObject                          1,683,967,360                                 3,955,057,542                                    716,832,500                                          200,003                                     0                                      0                           66,678             223.825s                        62.467s                           161.358s                 9,030                            5,158                                 3,873  ntdll.dll       NtWaitForSingleObject  [Unknown]     0x1800906f0
    WriteFile                                      1,207,593,104                                 1,022,685,972                                  1,713,743,550                                                0                                     0                                      0                           61,803               0.340s                         0.003s                             0.337s                   962                              954                                     8  KernelBase.dll  WriteFile              [Unknown]     0x180001c50

Linux*:


    Function            Hardware Event Count:INST_RETIRED.ANY  Hardware Event Count:CPU_CLK_UNHALTED.THREAD  Hardware Event Count:CPU_CLK_UNHALTED.REF_TSC Context Switch Time  Context Switch Time:Wait Time  Context Switch Time:Inactive Time  Context Switch Count  Context Switch Count:Preemption  Context Switch Count:Synchronization  Module              Function (Full)     Source File  Start Address
    ------------------  -------------------------------------  --------------------------------------------  --------------------------------------------- -------------------  -----------------------------
    [libmixed_call.so]                         21,148,958,284                                40,338,264,445                                 35,096,009,324              1.401s                             0s                             1.401s                26,769                           26,769                                     0  [libmixed_call.so]  [libmixed_call.so]  [Unknown]    0
    [libjvm.so]                                   792,807,896                                 1,199,773,286                                  1,335,034,092              0.047s                         0.005s                             0.042s                   462                              451                                    11  [libjvm.so]         [libjvm.so]         [Unknown]    0
    ...

制限事項

インテル® VTune™ プロファイラーは、制限付きで Java* アプリケーションの解析をサポートします。

関連情報