スキップしてメイン コンテンツに移動

Javaパフォーマンスチューニング3

Topics:

パフォーマンスチューニングの続編。Java Performance 2nd Editionより。

・パフォーマンス測定時の注意
パフォーマンス測定時にはランダムサンプルとフラグサンプル(任意の箇所にフラグを指定して測定)がある。
(ところでその分類によると、任意の間隔、例えば100ms周期、という指定はランダムにあたるのだろうか、フラグにあたるのだろうか)

どちらにせよサンプリングエラーは発生してしまうが、特にフラグサンプルの場合、適切なフラグを付けないと、本当に改善すべき点が見えず、実際とは異なる結果が測定されてしまう蓋然性が高まる。

・改善対象の選定
JDKやJVMそのものを書き換えないと改善できないところに注力してしまうことがないように注意する必要がある。

・測定結果の可視化
オープンソースの async-profiler project を使用すればどのメソッドがCPU時間をどれほど使っているかがボトムアップでわかる

・Sampling Profiler と Instrumented Profiler
Instrumented profilers(日本語訳はなんだろう)は読み込まれるバイトコードの変更することで様々な計測ができるようになるもの 。
Sampling Profilerでまずはざっくりとみて、そこからInstrumented Profilerでドリルダウンしていくと良いらしい
その他、Native profilerではgcの可視化なども見れるのでgcの時間が長かったらgcタイミングをチューニングする


・メソッドやスレッドの時系列確認ツール
どのメソッドやスレッドでブロックが発生してしまっているかを見る。
jvisualvm を使用すると良い(Instrumented Profilersに該当するらしい)
そのほか、Oracle Developer Studio profiling toolで使えるthread timeline chartだとブロッキングが可視化できる

・JFRによる記録とJMCによる確認
OpenJdk11, OracleJDdk8から同梱されているツールであるJava Flight Recorder(JFR)。
JVM上で発生したイベントを確認することで事後の分析を実現する。

ここで記録したJFRの記録はJava Mission Control(JMC)で確認するのが通例とのこと。
ただし、JMCはリリースサイクルがJDKとは別であることなどもあり同梱されてない。
そのため、別途ダウンロードが必要。例えば、Jdk11ではバージョン7を使う。

MacでJMCを使用する場合には、https://jdk.java.net/jmc/ からダウンロードする
.appファイルが入っていたので、とりあえず jmc-7+14_osx-x64_bin/JDK\ Mission\ Control.app を /usr/local/lib/に移動し、
/usr/local/binで次のコマンドでパスを通した

ln -s ../lib/jmc-7+14_osx-x64_bin/JDK\ Mission\ Control.app/Contents/MacOS/jmc jmc

JMCを呼び出した時のJava(JVM)で呼ばれている他のプロセスもJMCのGUIで見れるので、
jcmdで次のようにstartしてあげれば、Finishさせて結果を見ることはできた

% jcmd process_id JFR.start [options_list]

JFRではメモリやコードなど様々なviewが用意されている
JFRで集められる情報はjcmdやjconsoleのそれよりも詳細なものが多いと書かれている。
jconsoleでは現在動いているアプリのCPUやメモリ、スレッドの使用量の推移が簡単に見れたので、
お手軽に見るにはjconsole、しっかり見るならJFRという使い分けがいいかもしれない。

デフォルトではJFRは無効化されているため、有効化するためには

-XX:+FlightRecorder

をフラグとして追加する。

なお、JMCのGUI からも変更可能。

・jvisualvmによる可視化
jvisualvmでパフォーマンス状況を可視化できるというわけでローカルのOpenJDK11環境で試してみることに。
単純にjvisualvmすると次のようになる。

Unable to locate an executable at "/Library/Java/JavaVirtualMachines/adoptopenjdk-11.0.2.jdk/Contents/Home/bin/jvisualvm" (-1)

最新状況を確認するとGraalVMと同梱されているようなので、GraalVMのものを使用した
https://visualvm.github.io/

/Library/Java/GraalVirtualMachines/graalvm-ce-java11-19.3.0.2/Contents/Home/bin/jvisualvm

対象プロセスIDを選んで(jpsで探してから)CPUボタンを押して計測することで処理のE2Eの実行時間などがとれる。
Profilerだと全量取るので影響が大きい基本はSamplerで良さそう。

一部見方がわからない部分もあったが、手元のメソッドAとBで呼ばれてからの時間と、DB系にかかっている時間、計算等にかかっている時間などがわかってなかなか興味深かった。