VisualVMを使ってみる

Java ツール JVM GraalVM

はじめに

Javaのプロセスをプロファイルするツールはいろいろあると思うのですが、個人的にVisuralVMが気になったので、調べてまとめます。 具体的には以下のようなことを目指します。

  • VivualVMの概要を知る
    • どのようなことができるかを知る
  • 実際に使ってみる
    • ヒープの使用率からGCのアクティビティを見てみる

VisualVMとは

VisualVMはJavaベースのアプリケーションに関する情報を可視化された形で表示するためのツールです。ローカルやリモートで動作するJavaアプリに接続して情報を得ることが可能です。また、取得したデータをローカルに保存してあとで表示したり、共有したりすることが可能です。

どのような情報をみることがきるか

VisualVMでは以下のような情報をみることができます。

  • Javaプロセスの設定や環境
  • CPU使用率
  • GCアクティビティとヒープ
  • ロードされているクラス
  • スレッドの情報

使ってみる

それでは、使ってみようと思います。

環境

動作環境は以下のとおりです。

$ uname -srvmpio
Linux 5.4.0-45-generic #49-Ubuntu SMP Wed Aug 26 13:38:52 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

$ lsb_release -a
LSB Version:    core-11.1.0ubuntu2-noarch:security-11.1.0ubuntu2-noarch
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.1 LTS
Release:    20.04
Codename:   focal

$ java --version
openjdk 14.0.1 2020-04-14
OpenJDK Runtime Environment (build 14.0.1+7)
OpenJDK 64-Bit Server VM (build 14.0.1+7, mixed mode, sharing)

また、VisualVMのバージョンは2.0.4を使います。

インストール

VisualVMを利用する方法は以下の３つがあります。

今回はスタンドアローンのものを利用しようと思います。
VisualVMのサイト からバイナリをダウンロードします。 aptでも入れることはできるようですが、今回は公式のやり方に従ってやろうと思います。

ダウンロードしたzipをunzipしてbin配下をみるとvisualvmとvisualvm.exeが置かれていました。

$ unzip visualvm_204.zip 
$ cd visualvm_204/bin
$ ls
visualvm  visualvm.exe

LinuxでVisualVMを起動する場合はvisualvmのバイナリを実行すると良さそうです。

$ ./vsualvm

利用規約に同意すると以下のようなホーム画面が現れます。

f:id:yuya_hirooka:20200905132038p:plain

これでインストールと起動までできました。

Javaのプロセスに接続して基本的な情報を確認する

早速アプリに接続しようと思いますが、まずは接続するJavaのコードを記述します。

Main.java

public class Main {
    public static void main(String[] args) throws Exception {
        for (int i = 0; i< 1000; i++ ){
            Thread.sleep(1000);
            System.out.println(String.format("loop Number: %d", i) );
        }
    }
}

コードがすぐに終了してしまうと接続する前に停止してしまって困るので、スリープを1000回実行するようにしてます。
このコードを実行して、VisualVMから確認します。

$ java Main.java
loop Number: 0
loop Number: 1
loop Number: 2
loop Number: 3
.
.
.

再度VisualVMの画面を開きサイドバーのApplicationタブを見て見ます。

f:id:yuya_hirooka:20200905134633p:plain

Localの項目に先程まではVisualVMのみ表示されていましたが、今は複数の選択肢が確認できると思います。ここでは動作中のJavaプロセスの一覧をみることができますVisualVM自身のJavaのプロセスであるため初期段階ではVisualVMのみ表示されていましたが、いまはIntelliJと自身が作成したJavaプログラムのプロセスが表示されているのが確認できます。
自分のプログラムのプロセスを選択するとOverviewタブが選択された状態で表示されます。

f:id:yuya_hirooka:20200905135933p:plain

このOverviewではアプリケーションの基本的な情報が表示され、動いているJavaのバージョンや、フラグ等を確認することができます。

モニタータブで諸々の情報を確認する

モニタータブでは以下のような情報を確認することができます。

  • CPU使用率
  • ヒープに関する情報
  • ロードされているクラスの情報
  • スレッドに関する情報

f:id:yuya_hirooka:20200905141620p:plain

GCのアクティビティを見てみる

先程のプログラムを少し変更して、インスタンスをひたすら作成するようにしてみます。 まずは、インスタンス化されるクラスを作ります。

Customer.java

public class Customer {
    public Customer(String name) {
        this.name = name;
    }

    private String name;

    public String getName() {
        return name;
    }

    @Override
    public String toString() {
        return String.format("customer name is %s", name);
    }
}

次にメインクラスを書き換え上記のクラスのインスタンスをひたすら生成するようにします。

public class Main {
    public static void main(String[] args) throws Exception {
        List<Customer> customerList = new ArrayList<>();
        long i = 0L;
        while (true){
            Thread.sleep(1);
            Customer henoheno = new Customer("henoheno");
            customerList.add(henoheno);
            i++;
            if (i >1000000){
                customerList.clear();
                i = 0;
            }
        }

    }
}

この際、GCの発生を早めるために-Xmx50mフラグを指定しておきます。
プログラムを実行して、しばらく待ってからプロセスのヒープの使用率を確認してみます。 以下のような表示が得られました。

f:id:yuya_hirooka:20200905161732p:plain

まず、設定通りマックスヒープサイズが、やく50MB程度になっていることが確認できます。
また、実際の使用率（図中の青の領域）を見てみると上昇と下降を繰り返していることが確認できます。 これは、下降のタイミングでGCが発生していると思われます。

おまけ：プラグインを入れて世代で分けられたヒープを可視化する

VisualVMには世代ごととのヒープを可視化するためのプラグインが用意されています。
最後にそのプラグインをインストールしてつかって、見たいと思います。
VisualVMの画面の上部のtoolsメニューからPluginsを選択すると以下のような画面が表示されます。

f:id:yuya_hirooka:20200905162053p:plain

Available PluginsのタブからVisualGCのプラグインを選択肢、Installをクリックします。
利用規約に同意すると、インストールが始まり完了後に再度アプリのプロセスに接続すると、下図のようにVisualGCのタブが増えており、そこから可視化された、世代別のヒープを確認することができます。

f:id:yuya_hirooka:20200905162627p:plain

参考