Java Virtual Machineは一日中何をしていますか？

この記事は、もともとAmpere Computing

によって公開されました

新しいGNUパフォーマンス分析ツールであるGPROFNGに関する最近のブログ投稿を見ました。このブログでは、c言語で記述されたマトリックスベクトル乗算プログラムを例として使用しています。私はJava™プログラマであり、静的にコンパイルされたCプログラミング用に設計されたツールを使用することは、Javaプログラムが実行時にコンパイルされるため、Javaアプリケーションを分析するのが難しいことがよくあります。このブログ投稿では、GPROFNGが使いやすく、Javaアプリケーションの動的な動作を掘り下げるのに非常に役立つことを示します。

最初のステップは、マトリックス乗算プログラムを作成することです。マトリックス乗算ベクターよりも難しくないため、完全なマトリックス乗算マトリックスプログラムを書きました。 3つの主な方法があります。1つのメソッドは、最も内側の乗算と加算操作を計算し、1つのメソッドは乗算と添加操作を結果の単一の要素に組み合わせ、結果の各要素を反復します。

単純なテストプログラムで計算をラップして、マトリックス積を繰り返し計算して、時間が再現可能であることを確認します。 （注1を参照）プログラムは、各マトリックスの乗算が開始される時間（Java仮想マシンが開始される時間と比較して）、および各マトリックス増殖にかかる時間を印刷します。ここでは、2つの8000×8000マトリックスを掛けるためにテストプログラムを実行しました。テストプログラムは計算を11回繰り返し、その後の動作をよりよく強調するために、繰り返しの間に920ミリ秒間睡眠をとった：

<code class="language-bash">$ numactl --cpunodebind=0 --membind=0 -- \
java -XX:+UseParallelGC -Xms31g -Xmx31g -Xlog:gc -XX:-UsePerfData \
  MxV -m 8000 -n 8000 -r 11 -s 920</code>

図1：マトリックス乗算プログラムの実行

2回目の繰り返しには、最初の繰り返しの時間の92％がかかりますが、最後の繰り返しは最初の繰り返しの時間の89％しかかかりません。これらの実行時間の変更は、Javaプログラムがウォームアップするのに時間が必要であることを確認しています。

問題は、GPROFNGを使用して最初の繰り返しと最後の繰り返しの間に何が起こるかを確認して、パフォーマンスの改善をもたらすことができますか？

この質問に答える方法の1つは、プログラムを実行し、実行中の情報を収集させることです。幸いなことに、これは簡単です。GPROFNGが「実験的な」情報と呼ぶものを収集するためにコマンドラインにプレフィックスを付けてください：

<code class="language-bash">$ numactl --cpunodebind=0 --membind=0 -- \
gprofng collect app \
    java -XX:+UseParallelGC -Xms31g -Xmx31g -Xlog:gc --XX:-UsePerfData \
        MxV -m 8000 -n 8000 -r 11 -s 920</code>

図2：gprofngの下で行列乗算プログラムを実行する 最初に注意すべきことは、パフォーマンス分析ツールと同様に、パフォーマンス分析情報を収集するとアプリケーションにコストがかかる可能性があることです。以前の未分析の実行と比較して、GPROFNGは重大なオーバーヘッドを引き起こすようには見えません。

その後、アプリケーション全体のgprofngで時間がどのように費やされるかを尋ねることができます。 （注2を参照）実行全体について、GPROFNGの最も人気のある24の方法は次のとおりです。

図3：最もホットなgprofngを表示する24の方法

上記の関数ビューは、秒の割合と合計CPU時間で表される各メソッドの排他的かつ包含CPU時間を示します。指定された関数は、GPROFNGによって生成される擬似機能であり、さまざまなインジケーターの合計値があります。この場合、アプリケーション全体の合計CPU時間は1.201秒であることがわかります。

アプリケーションメソッド（MXVクラスのもの）はすべてCPU時間のほとんどを占めていますが、JVMランタイムコンパイラ（コンパイル::コンパイル）、およびの一部ではない他の機能を含む他の方法がいくつかあります。マトリックス乗算プログラム。プログラム全体のこの表示は、割り当て（MXV.Allocate）と初期化（MXV.Initialize）コードをキャプチャします。これは、テストプログラムの一部であるため、あまり興味があり、起動中にのみ使用され、乗算されます。マトリックスではほとんど重要ではありません。

GPROFNGを使用して、興味のあるアプリケーションの部分をたどることができます。 GPROFNGの優れた機能は、実験を収集した後、収集されたデータにフィルターを適用できることです。たとえば、特定の時間間隔で何が起こるか、または特定のメソッドがコールスタックにあるときに何が起こるかを見てください。デモンストレーションの目的とフィルタリングを簡単にするために、Sthread.Sleep（MS）への戦略的な呼び出しを追加して、プログラムフェーズに基づいてフィルターを簡単に記述しやすくします（1秒間隔で分割）。このため、各マトリックスの乗算には約0.1秒しかかからない場合でも、上記の図1のプログラム出力が各繰り返しの間に約1秒である理由です。

gprofngはスクリプト可能であるため、GPROFNG実験から1秒を抽出するスクリプトを書きました。最初の秒は、Java Virtual Machine Startupのすべてです。

図4：最初の秒をフィルタリングするための最もホットな方法。この瞬間に、マトリックスの乗算は手動で遅延しているため、JVMスタートアップを表示できるようになりました。 コンパイラは、アプリケーションの方法がまだ実行されていない場合でも、実行時（例：コンパイル:: compile_java_method、CPU時間の16％）から始まっていることがわかります。 （マトリックス乗算コールは、私が挿入したスリープコールによって遅れました。）

最初の秒は1秒で、その間にさまざまなJVMメソッドで割り当ておよび初期化方法が実行されますが、マトリックス乗算コードはまだ開始されていません。

図5：2番目の2秒で最もホットな方法。マトリックスの割り当てと初期化は、JVMスタートアップと競合します

JVM起動と配列の割り当てと初期化が完了したので、図6に示すように、3番目の秒でマトリックス乗算コードの最初の繰り返しがあります。ただし、マトリックスの乗算コードは、マトリックス乗算コードが高温であることがわかっているため、メソッドをコンパイルしているJava Runtime Compiler（たとえば、CompileBroker :: Invoke_compiler_on_method、図6の8％）と競合していることに注意してください。

それでも、マトリックス乗算コード（たとえば、MXV.mainメソッドに「「含める」時間、91％を含む）は、ほとんどのCPU時間を取得します。包含時間は、マトリックスの乗算（例：MXV.Multiply）に0.100 cpu秒かかることを示しています。これは、図2のアプリケーションで報告された実際の時間と一致しています。 （実際の時間を収集して報告するのにいくつかの時間がかかります。これは、gprofngカウントをmxv.multiplyにcpu時間以外にあります。）

図6：ランタイムコンパイラがマトリックス乗算方法と競合していることを示しています。 この特定の例では、マトリックスの乗算は、多数のアイドルサイクルを備えたマルチプロセッサシステムで実行され、ランタイムコンパイラが個別のスレッドとして実行されるため、マトリックスの乗算は実際にはCPU時間で競合しません。重い負荷を備えた共有マシンなどのより制限的なケースでは、ランタイムコンパイラが費やす時間の8％が問題になる可能性があります。一方、ランタイムコンパイラに費やされる時間は、より効率的なメソッドの実装をもたらすため、多くのマトリックスの乗算を計算すると、それは私が喜んで行う投資になります。 5番目に、マトリックス乗算コードにはJava仮想マシンがあります。

図7：すべてのメソッドが5秒間に実行され、マトリックス乗算方法のみがアクティブであることを示します

Mxv.onecell、Mxv.MultiplyAdd、およびMxv.Multiplyの間の60％/30％/10％の割り当てに注意してください。 MXV.MultiplyAddメソッドは、乗算と加算のみを計算するだけです。ただし、マトリックス乗算の最も内側の方法です。 Mxv.OneCellには、MXV.MultiplyAddを呼び出すループがあります。ループオーバーヘッドと呼び出し（評価条件と制御転送）がMXV.MultiplyAddでの直接的な算術演算よりも比較的機能していることがわかります。 （MXV.ONECELLの排他的時間は0.060 cpu秒ですが、Mxv.MultiplyAddはこの違いを反映して0.030 cpu秒です。）Mxv.Multiplyの外側ループ実行周波数は、ランタイムコンパイラがまだまとめていないほど高くありません。 、しかし、この方法は0.010 cpu秒を使用しています。 マトリックスの乗算は、JVMランタイムコンパイラが再び開始し、Mxv.Multiplyが非常に熱くなっていることを発見した9秒まで続きます。

最後の繰り返しでは、マトリックス乗算コードがJava仮想マシンを最大限に活用しています。

図9：マトリックス乗算プログラムの最後の繰り返し。

結論

パフォーマンス分析のためにGPROFNGを使用して、Javaアプリケーションのランタイムに簡単に到達できることを示しました。 GPROFNGのフィルタリング関数を使用して、時間のスライスごとに実験を確認すると、興味のあるプログラム段階を確認することができました。たとえば、アプリケーションの割り当てと初期化フェーズを除くと、ランタイムコンパイラがマジックを実行しているときにプログラムの繰り返しを1つ表示するだけで、ホットコードが徐々にコンパイルされるにつれて改善されるパフォーマンスを強調することができます。

さらに読み取り

GPROFNGについて知りたい読者の場合、GPROFNGに関する入門ビデオを含むブログ投稿を紹介します。

謝辞

Ruud van der Pas、Kurt Goebel、Vladimir Mezentsevのアドバイスと技術サポートをありがとう、そしてこのブログ投稿を書くように励ましてくれたElena Zannoni、David Banman、Craig Hardy、Dave Nearyに感謝します。

注

1. プログラムコマンドラインコンポーネントの動機は次のとおりです。

numactl - cpunodebind = 0 - membind = 0-。 Java仮想マシンが使用するメモリをNUMAノードのコアとメモリに制限します。 JVMを1つのノードに制限すると、実行中のプログラム間の違いを減らすことができます。
java。 AARCH64のJDK-17.0.4.1のOpenJDKバージョンを使用しています。
-xx：parparallelgc。利用可能なコレクターで最小限のバックグラウンドワークを実行するため、並列ガベージコレクターを有効にします。
-XMS31G -XMX31G。十分なJavaオブジェクトのヒープスペースを提供し、ガベージコレクションを必要としません。
-xlog：gc。 GCアクティビティを記録して、実際に収集する必要がないことを確認します。 （ "信頼しますが、確認してください。"）
-xx：-useperfdata。 Java仮想マシンのオーバーヘッドを減らします。

gprofngオプションの説明は
2. です

-limit 24。最初の24のメソッドのみが表示されます（ここでは排他的なCPU時間でソートされます）。 24の方法を示す方法で、ほとんど使用していない方法が良いアイデアを与えてくれることがわかります。その後、16の方法が些細なCPU時間に寄与する方法に減ることができる場所の一部で制限16を使用します。いくつかの例では、GPROFNG自体がディスプレイを制限します。これは、時間を蓄積する方法がそれほど多くないためです。
-ViewMode Expert。 JVM自体を含むJavaメソッドだけでなく、すべての累積CPU時間を表示するメソッド。このフラグを使用すると、ランタイムコンパイラメソッドなどを確認できます。

以上がJava Virtual Machineは一日中何をしていますか？の詳細内容です。詳細については、PHP 中国語 Web サイトの他の関連記事を参照してください。