はじめに

ちょっと前のどこかのイベント（おそらくJJUG）でJitWatchというのが紹介されていて、ちょっと気になってました。このブログではJITWatchを動かして見ようかと思います。
紹介動画とかみつつ、自分の理解をまとめています。正確な情報は公式のGitHub、紹介動画、スライド、Wiki等をご覧ください。
間違え等があればご指摘いただけると嬉しいです。

JitWatchとは

HotSpot JIT compilerのLogの解析と可視化を行なうためのツールです。
AdoptOpenJDKのプロジェクトで、Hotspotのログファイルを読み込んで、解析を実行することが可能なようです。具体的には、以下のような機能を提供します。

クラスツリーとどのメソッドがJIT コンパイルされたか、いつコンパイルされたか、そしてコンパイルに関する情報のView機能
ソースコード、バイトコード、アセンブリをそれぞれ対応付けして確認する
JIT コンパイルをプロットしていつコンパイルが行われたかを可視化する機能
native methodsのサイズ、バイトコードのサイズ、コンパイルタイムのサイズなどのランキング機能

動かしてみる

環境

$ java --version
openjdk 11.0.10 2021-01-19
OpenJDK Runtime Environment 18.9 (build 11.0.10+9)
OpenJDK 64-Bit Server VM 18.9 (build 11.0.10+9, mixed mode)


$ mvn --version
Apache Maven 3.6.3
Maven home: /usr/share/maven
Java version: 11.0.10, vendor: Oracle Corporation, runtime: /home/someone/.sdkman/candidates/java/11.0.10-open
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "5.4.0-72-generic", arch: "amd64", family: "unix"

まずは起動してみる

インストールとJITWatchの起動は、GitHubからプロジェクトをクローンしてきて、Exec Maven Pluginの実行コマンド叩くだけでGUIが立ち上がります。
ただし、注意点としてJITWatchのGUIはJavaFXを利用するためもし含まれていないJDKを利用している場合はここの手順を参考にセットアップして利用するか、JDKを別のものに買えてください。
それでは、起動してみます。

$  git clone https://github.com/prometheus-operator/kube-prometheus.git

$ cd jitwatch

$ mvn clean compile test exec:java

実行すると以下のような画面が表示されます。

f:id:yuya_hirooka:20210430151602p:plain

さくっと起動ができました。

Sandboxを動かしてみる

JITWatchの左上にsandbox文字が見れるのでおもむろに押してみます。
すると以下のようなエディターが立ち上がり、サンプルコードを実行できるようになっているみたいです。

f:id:yuya_hirooka:20210430153356p:plain

Configure Sandboxの設定からクラスパス等を設定するといろいろできそうですが、一旦はこのままRunコマンドを実行してみます。
すると以下のようなウィンドウが起動され実行結果が出力されます。

f:id:yuya_hirooka:20210430155416p:plain

これはTriViewと呼ばれるもので、実際のソースコードと対応するバイドコード、そしてアセンブリのコードが出力されるようになっているみたいです。
AssemblyのタブではAssembly not found. Was -XX:+PrintAssembly option used?という出力がされていますが、これはJITWatchがアセンブリコードを表示するためにいろいろ設定をしてやる必要があるからのようです。これらの設定等は後ほど補足しますが、ここではスルーします。

JITWatchを起動した際に、1番最初に表示された画面を確認してみると、少し表示が変わっているのがわかります。

f:id:yuya_hirooka:20210430174743p:plain

ここでは、Compile Treeが表示されており、パッケージとそこに属するクラスを選択することができ、それぞれにメソッド対する解析結果を見ることができます。

画面上部にはTimeline、Histo、Toplist、Cacheなどのボタンが用意されていますが、このボタンを押すとそれぞれの解析結果を見れるようです。先程表示されていた、TriViewも上部にあります。主要なものの説明を以下にまとめます。

Config: クラスパスなどの設定。
Timeline: コンパイルのタイムライン
Histo: コンパイル時間、メソッドサイズ、インラインメソッドサイズなどのヒストグラム
Cache: 時間軸に対するコードキャッシュのフリースペース
Threads: コンパイラのスレッドアクティビティ
TriView: ソースコード、バイドコード、アセンブリのView
Sugest: 予想が難しい分岐とホットメソットのインラインのサジェスト

ログを読み込んで解析を行なう

アプリの実行ログから解析を行ないます。
Spring BootのWebアプリを作成して、解析をしてみようと思います。

プロジェクトを作成して、hotspotのログを取得する

プロジェクトはSpring Initializrを使って、以下の設定で作成します。

f:id:yuya_hirooka:20210430192206p:plain

作成したプロジェクトをダウンロードして解凍し以下のコントローラーひとつだけ作成しておきます。

@RestController
public class HelloController {

    Logger logger = LoggerFactory.getLogger(HelloController.class);

    @GetMapping("/hello")
    public String hello() {
        for (int i = 0; i < 1000; i++) logger.info(String.format("exec adjustNum %s times", adjustNum(i)));
        return "hello";
    }

    private int adjustNum(int a) {
        return a + 1;
    }
}

以下のコマンドでビルドします。

$ mvn clean package

$ ls target/
classes  demo-0.0.1-SNAPSHOT.jar  demo-0.0.1-SNAPSHOT.jar.original  generated-sources  generated-test-sources  maven-archiver  maven-status  surefire-reports  test-classes

jarができたので実行をします。

この際にJITWatchが必要とするログを出力するため以下のオプションを追加します。

-XX:+UnlockDiagnosticVMOptions
- JDKの解析系のオプションをアンロックする
-XX:+LogCompilation
- メソッドのコンパイルログを出力する
-XX:+TraceClassLoading
- クラスロードされたクラスの追跡を有効にする

今回の場合は以下のように実行します。

$ java  -XX:+UnlockDiagnosticVMOptions -XX:+LogCompilation -XX:+TraceClassLoading -jar target/demo-0.0.1-SNAPSHOT.jar

すると、hotsopt_pid[アプリケーションのpid].logという名前のログファイルが出力されます。

$ ls
HELP.md  demo.iml  hotspot_pid41577.log  mvnw  mvnw.cmd  pom.xml  src  target

今回の場合はhotspot_pid41577.logというのがそれですね。

JITWatchの設定を行なう

作成したログファイルをJITWatchに読み込ませますが、その前に以下のような設定をJITWatch側で行なう必要があります。

src.zip(Javaプラットフォームのソース・コードを含むアーカイブ)を指定
アプリケーションのsrcディレクトリ
アプリケーションのclassファイルのロケーション

これらはJITWatchのConfig(最初に起動する画面上部の右から五番目あたり)から行なうことができます。
Config画面は以下のようになっています。

f:id:yuya_hirooka:20210430214748p:plain

画面上部の段にはsrc.zipとアプリケーションのsrcデレクトリ、下の段にはクラスファイルのロケーションを指定します。

src.zipに関してはAdd JDK srcボタンを押すと（おそらくJITWatchを起動している）JDKのzipが自動的に設定され、その他の2つはAdd Folderで設定します。

この状態で、Open log から先程のログ読み込み、startボタンを押します。すると以下のようにadjustNum()関数がC1コンパイルされたことが確認できます。

f:id:yuya_hirooka:20210430233641p:plain

アセンブリコードの生成（補足）

今回は試しませんが、JITWatchのTriViewでは生成されたアセンブリのコードも見ることができます。
そのためにはhsdisをビルドして、JDKの適当なディレクトリ(8以前と以降で配置するディレクトリが違います)に配置し、プログラム実行時に-XX:+PrintAssemblyオプションを指定してやる必要があります。
詳細はここを確認してください。

感想

今回、Spring Bootのアプリの解析をやってみましあんまり意味は無かったかもしれません、ちなみにjarを適切に指定してやるとSpringのクラスの解析も行えそうでした。

へのへのもへじ

JITWatchを動かしてみる