インテル® VTune™ プロファイラーは、Oracle* JDK* または OpenJDK* で実行された JIT コンパイル済みのコードで、オーバーヘッドの少ないユーザーモード・サンプリングとトレースおよびハードウェア・イベントベース・サンプリング解析を提供します。解釈された Java* メソッドの解析は制限されます。
ハードウェア・イベントベース・サンプリングによるデータ収集を使用して、CPU のパイプラインのハードウェア・イベントをモニターし、効率良い命令実行を制限するコードの過ちを特定します。ハードウェア・パフォーマンス・メトリックが利用でき、アプリケーションのモジュール、関数、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™ プロファイラーは最新の解析結果を使用します。
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* アプリケーションの解析をサポートします。
システム全体のプロファイルはマネージドコードではサポートされません。
パフォーマンス上の理由により、JVM* はほとんど呼ばれなかったメソッドをコンパイルする代わりに、インタープリターで解釈します。インテル® VTune™ プロファイラーは解釈された Java* メソッドを認識しないため、復元されたコールスタックではそのような呼び出しを [!インタープリター] としてマークします。
そのような関数を名前付きでスタックに表示する場合、-Xcomp オプションを使用して JVM* でコンパイルします (結果は、[コンパイル済み Java* コード] メソッドとして表示されます)。しかし、実行中に多くの小さな関数やほとんど使用されない関数が呼び出された場合、タイミング特性は顕著に変わります。
ホットスポットのソースコードを開く際に、インテル® VTune™ プロファイラーはイベントや時間統計を誤ったコードに割り当てることがあります。これは JDK* Java* VM 固有の現象です。ループの場合、パフォーマンス・メトリックが上にずれます。多くの場合、情報はホットなメソッドのソースコードの最初の行に表示されます。
イベントと時間のソースコードへのマッピングはおおよそのものです。
ユーザーモード・サンプリング・ベースのホットスポット解析タイプでは、インテル® VTune™ プロファイラーはコールスタックの一部だけを表示することがあります。Windows* 上で完全なスタックを表示するには、追加の -Xcomp JDK* Java* VM コマンドライン・オプションを使用し、JIT コンパイルを有効にしてスタック・ウォーキングの精度を高めます。Linux* では、Java* VM の動作を変更する追加の JDK* Java* VM コマンドライン・オプションを使用します。
より精度の高いスタック・ウォーキングの JIT コンパイルを有効にする、追加の -Xcomp JDK* Java* VM コマンドライン・オプションを使用します。
Linux* x86 では、サーバー Java* VM の代わりにクライアント JDK* Java* VM を使用します。つまり、JDK* Java* VM コマンドライン・オプションの -client を明示的に指定するか、-server を指定しません。
Linux* x64 では、インタープリターで解釈したメソッドとコンパイルバージョンのオンザフライ置換をオフにする -XX:-UseLoopCounter コマンドライン・オプションを指定します。
ホットスポットとマイクロアーキテクチャー解析タイプでは、Java* アプリケーションのプロファイルがサポートされます。一部の組込み Java* 同期プリミティブ (OS の同期オブジェクトを呼び出さない) は、インテル® VTune™ プロファイラーで認識できないため、スレッド化解析が制限されます。その結果、一部のタイミングメトリックがずれる可能性があります。
Java* ソースコードのコレクション制御用のユーザー API を提供する専用ライブラリーはありません。ただし、JNI 呼び出しで __itt 呼び出しをラップしてネイティブ API を適用することはできます。