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
[root@centos85 ~]# cat /etc/redhat-release
CentOS Linux release 8.5.2111
[root@centos85 ~]#
[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 ~]#
[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ログを出力しました。
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() + "件の取り込みが完了しました。");
}
}
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
[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 ~]#
ログが出力されていることを確認します。
[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
[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 ~]#
ログが出力されていることを確認します。
[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」のページからダウンロード可能です。
ダウンロードしたGCViewerのjarファイル(ここでは「gcviewer-1.36.jar」をWindows10で実行)をダブルクリックして起動し、出力したログファイルを読み込むと以下の通り表示されます。
上下2段で表示していますが、上側がJava8で実行したGCログの表示、下側がJava11で実行したGCログの表示です。
参考
- Java / JavaSE / 11 ツール・リファレンス
- Unified JVM Logging で出力したログを GCViewer に食わせる : ASP.NET 練習帳
- 知って使えるJVMのログ出力と情報収集や解析ツール (1/2)|CodeZine(コードジン)
- Java 11でのGCログの出力フォーマットについて - ColdFusion Associate
- [Javaの起動オプションにGCログ設定とヒープダンプを設定する]("https://sakusaku-techs.com/java/gc/" Javaの起動オプションにGCログ設定とヒープダンプを設定する)
以上