Java 標準プロファイラの VisualVM をつかってプロセスの分析をする

アプリケーションを運用していると、SQLや Java の処理の遅延により、性能問題が発生することがあります。運用開始時には性能問題はなかったシステムでも、長く運用していくと、日々のデータの蓄積により、性能が徐々に悪化したり、突如として極端な劣化が見られ、ユーザーからのクレームにつながることもあります。

この記事では、性能問題におけるボトルネックを調査する時に役立つ、Java のプロファイルツールについて解説します。

VisualVM とは

VisualVM は、Java アプリケーションのメモリやCPUなどの使用状況や、スレッドの状態などを収集して、GUI で視覚的に表示・分析してくれる便利なツールです。

公式サイト では、VisualVM について、次のように解説されています。

VisualVMは、jvmstat、JMX、Serviceability Agent（SA）、Attach APIなどのさまざまなテクノロジーを使用して、多くのベンダーのJava1.4以降で実行されているアプリケーションを監視およびトラブルシューティングします。

このように、VisualVM には、Java アプリケーションのパフォーマンスや問題の分析に役立つツールが１つにまとまっています。

VisualVM のインストール

それでは、実際に VisualVM をインストールして Java アプリのプロファイルをしてみましょう。

VisualVM は、Oracle JDK を使用している場合は、インストール時に VisualVM も付属しているため、改めてインストールする必要はありません。

Open JDK の場合は、JDK に VisualVM は付属していないため、以下の URL からダウンロードします。

https://visualvm.github.io/download.html

ポテパンダの一言メモ

VisualVM のインストーラーには zip 版と dmg 版の２種類があります。zip 版をダウンロードした場合は、任意のディレクトリに解答したファイルを展開しておきます。

起動方法

Oracle JDK を使用している場合は、以下のパスの実行ファイルを起動します。

<JDKのイントール先>/bin/jvisualvm

Open JDK の場合は、以下のパスの実行ファイルを起動します。（Windows の場合は visualvm.exe）

<VisualVMの展開先>/bin/visualvm

JDK の場所を指定する場合は –jdkhome を付けます

<VisualVMの展開先>/bin/visualvm --jdkhome path/to/jdkhome

起動すると次のような画面が表示されます。

左側のツリーの「Local」の下には、現在ローカルPC上で動いている Java のプロセスが表示されます。VisualVM も表示されていますが、それは、VisualVM も Java で作られているアプリであるためです。

同ツリーから VisualVM をクリックして、プロセスの詳細を表示させてみます。

VisualVM では、Java プロセスの情報を「概要」「監視」「スレッド」「サンプラ」の 4つのタブに分けて表示します。

検証用プログラムの作成

それでは、サンプルプログラムを作って、VisualVM でプロセスの情報を表示させてみましょう。

String と StringBuffer の文字列結合を比較

Java では、大量の文字列を結合する場合は、StringBuffer クラスを使用して、文字列結合を行なった方が効率がよいと言われています。

実際に String と StringBuffer でそれぞれ大量の文字列を連結するサンプルコードを作成して、VisualVM でリソース消費量を監視し、その原因を探ってみましょう。

String の文字列結合

まず、String で文字列を連結する非効率と言われるコードで試してみます。

public class Main {
  public static void main(String[] args) throws Exception {
    // VisualVM でサンプリングを開始するための待ち時間
    Thread.sleep(10000);

    String buf = "";
    for (int i = 0; i < 100000; i++) {
      buf += "test_message" + i + "\n";
    }

    Thread.sleep(2000);
  }
}

上のコードをデバッグ実行します。すると、左側のツリーにプロセスが表示されるため、ダブルクリックし、[Sampler] タブ → [CPU] をクリックの順に操作し、CPU のサンプリングを開始します。

（アプリケーションの実行が終了すると、左側のツリーからプロセスが消えるため、最終行ステップの Thread.sleep(2000) をブレークポイントで止めるなどしてプロセスが停止しないようにしてください）

サンプルプログラムの実行が完了すると、次のような結果が得られました。

java.lang.StringBuilder.<init>() となっている行はコンストラクタの呼び出しです。コンストラクタの呼び出し時間の合計が 3,407ms と長いことから、StringBuilder のコンストラクタが１度だけでなく、ループの中で何度も呼び出されていることが分かります。

また、java.lang.StringBuilder.toString() の処理にも時間がかかっており、StringBuilder の内容を何度も String 型に変換する非効率な処理になっていることも分かります。

このような結果から、String 型の文字列連携は、内部では以下のようなコードに変換されているようです。

次のコードを見ても分かるとおり、StringBuilder のインスタンスをループの中で何度も生成する非常に非効率なコードになっています。

String buf = "";

for (int i = 0; i < 100000; i++) {
  buf = new StringBuilder(buf).append("test_message" + i + "\n").toString();
}

[Memory] をクリックして、メモリの使用量も確認してみましょう。

StringBuilder のインスタンスを何度も生成したことにより、メモリの使用率も高くなっています。

StringBuffer の文字列結合

次に StringBuffer で文字列結合するコードを試してみましょう。

以下のコードを作成し、先ほどと同じように、デバッグ実行を開始後、[Sampler] タブ → [CPU] をクリックの順に操作し、CPU のサンプリングを開始します。

public class Main {
  public static void main(String[] args) throws Exception {
    // VisualVM でサンプリングを開始するための待ち時間
    Thread.sleep(10000);

    StringBuffer sb = new StringBuffer();

    for (int i = 0; i < 100000; i++) {
      sb.append("test_message" + i + "\n");
    }

    Thread.sleep(2000);
  }
}

サンプルプログラムの実行が完了すると、次のような結果が得られました。

結果はなんと、StringBuffer の処理が早すぎて、CPU のサンプリングの対象になりませんでした。

メモリの使用率も見てみましょう。

StringBuffer のインスタンを１つしか生成していないため、先ほどの String の文字列結合に比べて、はるかにメモリ使用量が少なくなっているのが分かります。

まとめ

VisualVM を使って、Java のプロセスを監視・分析する方法を解説してきました。

アプリケーションの性能問題が発生した時に役立つ VisualVM の使い方を是非覚えておきましょう。

【関連記事】
▶スレッドダンプを取得して Javaプロセスのトラブル調査に役立てよう