コマンドラインから 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 レポートタイプを使用して、アプリケーション関数ごとのハードウェア・イベント数を降順 (デフォルト) で表示します。

hw-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* アプリケーションの解析をサポートします。

関連情報