Javaのヒープ使用量を簡単に参照する方法

Javaのプログラムの実行時のヒープメモリの使用量を簡単に参照する方法を紹介します。
Java起動時にオプションを付与することで、GCログを出力することができます。
Java9より**Unified JVM Logging**としてシステムログに関する仕様が統合されており、Java8とJava9移行ではGCログを出力するオプションが変わっています。
ここでは、Java8とJava11で実際に試してみたオプションを紹介します。

# 1. 環境

+ OS：CentOS Linux release 8.5.2111
+ java8：1.8.0_312
+ java11：11.0.13

```:OS
[root@centos85 ~]# cat /etc/redhat-release
CentOS Linux release 8.5.2111
[root@centos85 ~]#
```

```:java8
[root@centos85 ~]# /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-2.el8_5.x86_64/jre/bin/java -version
openjdk version "1.8.0_312"
OpenJDK Runtime Environment (build 1.8.0_312-b07)
OpenJDK 64-Bit Server VM (build 25.312-b07, mixed mode)
[root@centos85 ~]#
```

```:java11
[root@centos85 ~]# /usr/lib/jvm/java-11-openjdk-11.0.13.0.8-4.el8_5.x86_64/bin/java -version
openjdk version "11.0.13" 2021-10-19 LTS
OpenJDK Runtime Environment 18.9 (build 11.0.13+8-LTS)
OpenJDK 64-Bit Server VM 18.9 (build 11.0.13+8-LTS, mixed mode, sharing)
[root@centos85 ~]#
```
試した環境ではJava8とJava11と両方にストールしています。
java8で実行するときは
`/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-2.el8_5.x86_64/jre/bin/java`
を
Java11で実行するときは
`/usr/lib/jvm/java-11-openjdk-11.0.13.0.8-4.el8_5.x86_64/bin/java`
のコマンドを使用しました。

# 2. サンプルプログラム

以下のサンプルプログラム（「java.lang.OutOfMemoryError: Java heap space」が発生する）を実行して、GCログを出力しました。

```java:Main.java
package test;

import java.io.BufferedReader;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.Paths;
import java.util.ArrayList;
import java.util.List;

public class Main {

    public static void main(String[] args) {

        Path path = Paths.get("/apl/files", "data.tsv");

        List<Data> list = new ArrayList<>();

        for (int i = 0; i < 1000000; i++) {
            try (BufferedReader br = Files.newBufferedReader(path, StandardCharsets.UTF_8)) {

                String record;

                while ((record = br.readLine()) != null) {
                    String[] cols = record.split("\t");

                    Data data = new Data();
                    data.setId(Integer.parseInt(cols[0]));
                    data.setData1(cols[1]);
                    data.setData2(cols[2]);

                    list.add(data);

                }
            } catch (IOException e) {
                e.printStackTrace();
            }
            System.out.println((i + 1) + "回目の取り込み完了");
        }
        System.out.println(list.size() + "件の取り込みが完了しました。");
    }
}
```

```Data.java
package test;

public class Data {

    private int id;
    private String data1;
    private String data2;

    public int getId() {
        return id;
    }

    public void setId(int id) {
        this.id = id;
    }

    public String getData1() {
        return data1;
    }

    public void setData1(String data1) {
        this.data1 = data1;
    }

    public String getData2() {
        return data2;
    }

    public void setData2(String data2) {
        this.data2 = data2;
    }
}
```

# 3. Java8でのGCログ出力

Java8でGCログを出力する場合、以下のオプションを付与します。

+ -verbose:gc
+ -Xloggc:<ログの出力先>
+ -XX:+PrintGCDetails
+ -XX:+PrintGCDateStamps

以下のコマンドでjarファイルに固めたサンプルプログラムを実行します。
ここでは「-Xms128m -Xmx128m」とヒープサイズを128mに指定しています。

`/usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-2.el8_5.x86_64/jre/bin/java -Xms128m -Xmx128m -verbose:gc -Xloggc:/apl/log/java8_gc_$(date "+%Y%m%d_%H%M%S").log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -jar /apl/bin/testheap.jar`

```console:実行結果
[root@centos85 ~]# /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.312.b07-2.el8_5.x86_64/jre/bin/java -Xms128m -Xmx128m -verbose:gc -Xloggc:/apl/log/java8_gc_$(date "+%Y%m%d_%H%M%S").log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -jar /apl/bin/testheap.jar
1回目の取り込み完了
2回目の取り込み完了
3回目の取り込み完了
4回目の取り込み完了
5回目の取り込み完了
6回目の取り込み完了
7回目の取り込み完了
8回目の取り込み完了
9回目の取り込み完了
10回目の取り込み完了

～省略～

4299回目の取り込み完了
4300回目の取り込み完了
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at java.lang.String.substring(String.java:1969)
        at java.lang.String.split(String.java:2368)
        at java.lang.String.split(String.java:2422)
        at test.Main.main(Main.java:26)
[root@centos85 ~]#
```

ログが出力されていることを確認します。
```console:確認
[root@centos85 ~]# ls -l /apl/log
合計 16
-rw-r--r--. 1 root root 12666 12月 17 17:31 java8_gc_20231217_173052.log
[root@centos85 ~]#
```

# 4. Java11でのGCログ出力

Java11でGCログを出力する場合、以下のオプションを付与します。

+ -Xlog:gc*:file=<ログの出力先>:tags,time,uptime,level

以下のコマンドでjarファイルに固めたサンプルプログラムを実行します。
ここでは「-Xms128m -Xmx128m」とヒープサイズを128mに指定しています。

`/usr/lib/jvm/java-11-openjdk-11.0.13.0.8-4.el8_5.x86_64/bin/java -Xms128m -Xmx128m -Xlog:gc*:file=/apl/log/java11_gc_$(date "+%Y%m%d_%H%M%S").log:tags,time,uptime,level -jar /apl/bin/testheap.jar`

```console:実行結果
[root@centos85 ~]# /usr/lib/jvm/java-11-openjdk-11.0.13.0.8-4.el8_5.x86_64/bin/java -Xms128m -Xmx128m -Xlog:gc*:file=/apl/log/java11_gc_$(date "+%Y%m%d_%H%M%S").log:tags,time,uptime,level -jar /apl/bin/testheap.jar
1回目の取り込み完了
2回目の取り込み完了
3回目の取り込み完了
4回目の取り込み完了
5回目の取り込み完了
6回目の取り込み完了
7回目の取り込み完了
8回目の取り込み完了
9回目の取り込み完了
10回目の取り込み完了

～省略～

4289回目の取り込み完了
4290回目の取り込み完了
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at java.base/java.util.Arrays.copyOfRange(Arrays.java:4030)
        at java.base/java.lang.StringUTF16.newString(StringUTF16.java:1025)
        at java.base/java.lang.String.substring(String.java:1880)
        at java.base/java.lang.String.split(String.java:2289)
        at java.base/java.lang.String.split(String.java:2364)
        at test.Main.main(Main.java:26)
[root@centos85 ~]#
```

ログが出力されていることを確認します。
```console:確認
[root@centos85 ~]# ls -l /apl/log
合計 84
-rw-r--r--. 1 root root 66798 12月 17 17:47 java11_gc_20231217_174721.log
-rw-r--r--. 1 root root 12666 12月 17 17:31 java8_gc_20231217_173052.log
[root@centos85 ~]#
```

# 5. GCViewerでログの確認

出力したGCログは*GCViewer*を使用すると、グラフィカルにログを参照することが可能です。

2023/12/17現在、GCViewerは「[Changelog · chewiebug/GCViewer Wiki · GitHub](https://github.com/chewiebug/GCViewer/wiki/Changelog "Changelog · chewiebug/GCViewer Wiki · GitHub")」のページからダウンロード可能です。

ダウンロードしたGCViewerのjarファイル（ここでは「gcviewer-1.36.jar」をWindows10で実行）をダブルクリックして起動し、出力したログファイルを読み込むと以下の通り表示されます。

![gc1.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/292434/453f8fca-d89e-dfae-a7dc-25286b89c123.png)

上下2段で表示していますが、上側がJava8で実行したGCログの表示、下側がJava11で実行したGCログの表示です。

# 参考
+ [Java / JavaSE / 11 ツール・リファレンス](https://docs.oracle.com/javase/jp/11/tools/java.html#GUID-3B1CE181-CD30-4178-9602-230B800D4FAE "Java / JavaSE / 11 ツール・リファレンス")
+ [Unified JVM Logging で出力したログを GCViewer に食わせる : ASP.NET 練習帳](http://blog.livedoor.jp/aspplus/archives/51943721.html "Unified JVM Logging で出力したログを GCViewer に食わせる : ASP.NET 練習帳")
+ [知って使えるJVMのログ出力と情報収集や解析ツール (1/2)|CodeZine（コードジン）](https://codezine.jp/article/detail/16074 "知って使えるJVMのログ出力と情報収集や解析ツール (1/2)|CodeZine（コードジン）")
+ [Java 11でのGCログの出力フォーマットについて - ColdFusion Associate](https://cfassociates.samuraiz.co.jp/index.cfm/faq/etc/java11-xlog-format/ "Java 11でのGCログの出力フォーマットについて - ColdFusion Associate")
+ [Javaの起動オプションにGCログ設定とヒープダンプを設定する]("https://sakusaku-techs.com/java/gc/" Javaの起動オプションにGCログ設定とヒープダンプを設定する)

---
以上