GraalVM Native Image の Native Memory Tracking の紹介

この記事は [NTT コムウェア Advent Calendar 2024](https://qiita.com/advent-calendar/2024/nttcomware) 5日目の記事です。

## はじめに

こんにちは、NTT コムウェア株式会社の坂本統です。

私は普段 Java システムの技術サポートを仕事にしています。
特に Java 実行・開発環境ソフトウェア（JRE/JDK）である [OpenJDK](https://openjdk.org/) を専門として Java 仮想マシン（JVM）のトラブルシューティングを得意としています。

今年は日本 Java ユーザグループ主催の [JJUG CCC 2024 Fall](https://ccc2024fall.java-users.jp/) にて、OpenJDK の Native Memory Tracking(NMT) 機能について調査した結果を発表させていただきました。
本記事はそれに関連して、[GraalVM for JDK 23](https://www.graalvm.org/release-notes/JDK_23/) から追加された **Native Image の Native Memory Tracking(NMT)** について調査した結果を紹介します。 

本記事を理解するためにはいくつか前提知識が必要ですので、併せて私の Qiita 記事もご参照下さい。

* [GraalVM Native Image トラブルシューティングことはじめ](https://qiita.com/comware_osakamoto/items/88633f9a6a02df102141)
* [Native Memory Tracking を使用した Java プロセスのメモリ消費内訳の紹介](https://qiita.com/comware_osakamoto/items/8937ff9cbba987462956)

なお本記事の内容は [GraalVM for JDK 23](https://www.graalvm.org/release-notes/JDK_23/) に基づいて執筆していますので、今後のアップデートで変更の可能性があることにご留意ください。

## 概要

[GraalVM for JDK 23](https://www.graalvm.org/release-notes/JDK_23/) にて、Native Image の NMT 機能が初期実装されました。まだ開発中のため OpenJDK の NMT と比べて不足している機能や異なる仕様がありますが、アプリケーションのメモリ消費傾向を解析するための嬉しい機能追加です。

まず OpenJDK の NMT について説明すると、この機能は Java プロセスのメモリ消費量を細分化された単位で記録します。Java ヒープや Metaspace などのアプリケーションによって管理されたメモリ領域だけでなく、JVM(HotSpot VM) 自身がその動作のために必要なメモリ領域（ネイティブメモリ）も測定できます。本記事では 分かりやすさのため Java ヒープ領域を**オンヒープ**、ネイティブメモリを**オフヒープ**と呼称します。

一方 Native Image の NMT は（現時点で）オフヒープの使用量のみを記録できます。Native Image は OpenJDK の HotSpot と異なり、JVM に Substrate VM を使用します。Substrate VM は Java で実装されるため、SubstrateVM が使用するメモリもオンヒープに割り当てられます。ただし、それでもいくつかの Substrate VM の機能はオフヒープでメモリを割り当てます。Native Image の NMT はこのオフヒープのメモリ消費を追跡することを目的にしています。

本記事では Native Image の NMT の使用方法と記録した NMT 情報の見方について説明した後、実際に NMT 機能を使用した結果を紹介いたします。

## 使用方法

Native Image の NMT 機能を利用するには、他のデバッグ機能と同様に `--enable-monitoring` オプションに `nmt` を指定してビルド時から NMT 機能を有効化（イメージへの追加）する必要があります。

```:ビルド例
$ native-image --enable-monitoring=nmt MyApp
```

:::note info
`--enable-monitoring` にはヒープダンプ出力機能（`heapdump`）や JDF Flight Recorder(JFR) 機能の有効化（`jfr`）も指定できます。NMT を試す場合はこれらを含むすべてのデバッグ機能を有効化する `all` を指定すると便利です。
:::

`--enable-monitoring=nmt` を指定してビルドされた Native Image は NMT 機能を使用できる様になります。ただし現時点（GraalVM for JDK 23）の Native Image の NMT は OpenJDK のそれと違い、`jcmd` を使用してアプリケーション実行中の特定のタイミングの NMT 情報を取得したり、ベースラインを設定できません。現時点で使用可能な方法は Native Image 実行オプションに `-XX:+PrintNMTStatistics` オプションを指定して、アプリケーション終了時に NMT 記録を出力することだけです。また出力形式や項目も異なります。

次に実行例と NMT 記録の出力例を示します。

```:実行例
$ ./myapp -XX:+PrintNMTStatistics
^C # アプリケーションの停止
Native memory tracking
  Peak total used memory: 1288 bytes
  Total alive allocations at peak usage: 3
  Total used memory: 400 bytes
  Total alive allocations: 3
  Compiler peak used memory: 0 bytes
  Compiler alive allocations at peak: 0
  Compiler currently used memory: 0 bytes
  Compiler currently alive allocations: 0
  Code peak used memory: 0 bytes
  Code alive allocations at peak: 0
  Code currently used memory: 0 bytes
  Code currently alive allocations: 0
  GC peak used memory: 0 bytes
  GC alive allocations at peak: 0
  GC currently used memory: 0 bytes
  GC currently alive allocations: 0
  Heap Dump peak used memory: 0 bytes
  Heap Dump alive allocations at peak: 0
  Heap Dump currently used memory: 0 bytes
  Heap Dump currently alive allocations: 0
  JFR peak used memory: 0 bytes
  JFR alive allocations at peak: 0
  JFR currently used memory: 0 bytes
  JFR currently alive allocations: 0
  JNI peak used memory: 80 bytes
  JNI alive allocations at peak: 1
  JNI currently used memory: 80 bytes
  JNI currently alive allocations: 1
  jvmstat peak used memory: 0 bytes
  jvmstat alive allocations at peak: 0
  jvmstat currently used memory: 0 bytes
  jvmstat currently alive allocations: 0
  Native Memory Tracking peak used memory: 64 bytes
  Native Memory Tracking alive allocations at peak: 4
  Native Memory Tracking currently used memory: 48 bytes
  Native Memory Tracking currently alive allocations: 3
  PGO peak used memory: 0 bytes
  PGO alive allocations at peak: 0
  PGO currently used memory: 0 bytes
  PGO currently alive allocations: 0
  Threading peak used memory: 288 bytes
  Threading alive allocations at peak: 3
  Threading currently used memory: 272 bytes
  Threading currently alive allocations: 2
  Unsafe peak used memory: 0 bytes
  Unsafe alive allocations at peak: 0
  Unsafe currently used memory: 0 bytes
  Unsafe currently alive allocations: 0
  Internal peak used memory: 1024 bytes
  Internal alive allocations at peak: 1
  Internal currently used memory: 0 bytes
  Internal currently alive allocations: 0
```

なお Native Image の NMT は CPU とメモリのオーバーヘッドが最小限に抑えられているためアプリケーション性能への影響も少なくなっています。

## NMT 記録情報の見方

前述の実行例を見ると OpenJDK の NMT 出力結果とは異なることが分かります。ここでは NMT 記録情報の見方について説明します。

Native Image の NMT は全体の記録を表す `Total` とそれから分類されたカテゴリごとのメモリ使用量と割り当て回数を出力します。現時点のカテゴリは以下の通りです。

|カテゴリ |説明
|---|---|
|Compiler |JIT コンパイル
|Code |JIT コンパイルされたコード
|GC |ガベージコレクタ
|HeapDump |ヒープダンプ出力
|JFR |JDK Flight Recorder
|JNI |Java Native Interface
|JvmStat |JVM stat およびパフォーマンスデータ
|NMT |Native Memory Tracking
|PGO |Profile-guided optimization
|Threading |スレッディング
|Unsafe |Unsafe によるメモリ割り当て
|Internal |その他

:::note info
カテゴリの定義は [NmtCategory.java](https://github.com/oracle/graal/blob/jdk-23.0.1/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/nmt/NmtCategory.java#L30) から確認できます。
:::

さらにそれぞれについて以下の４つの情報が出力されます。現在（`currently`）のメモリ消費量（`used memory`）とメモリ割り当て回数（`alive allocation`）が記録されます。さらに記録期間全体を通したピーク（`pead/at peak`）のメモリ消費量と割り当て回数も記録されます。

|情報 |説明
|---|---|
|peak used memory |メモリ消費量のピーク（byte）
|alive allocation at peak |割り当て回数のピーク
|currently used memory |現在のメモリ消費量(byte) 
|currently alive allocations |現在の割り当て回数

Native Image の NMT はカテゴリごとのメモリ割り当て（現在は `malloc` のみ）を追跡し、割り当てごとにメモリ消費量を記録します。割り当てが発生した場合はその分のメモリ消費量を加算し回数をインクリメントします。割り当て解除が発生した場合はそのメモリ消費量を減算し回数をデクリメントします。

:::note info
メモリ消費量を追跡する実装は [NmtMallocMemoryInfo.java](https://github.com/oracle/graal/blob/jdk-23.0.1/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/nmt/NmtMallocMemoryInfo.java) から確認できます。
:::

以下の NMT カテゴリのメモリ消費を例に見てみましょう。現在、つまりアプリケーション終了時の時点では割り当てが`3`回発生し、その割り当て量の合計は `48 bytes` です。また記録期間全体を通したピークは、割り当て`4`回発生で、割り当て量は `64 bytes` です。


```:NMT カテゴリのメモリ消費
  Native Memory Tracking peak used memory: 64 bytes
  Native Memory Tracking alive allocations at peak: 4
  Native Memory Tracking currently used memory: 48 bytes
  Native Memory Tracking currently alive allocations: 3
```

### （参考）ヒープダンプ出力および JFR 有効時のログ

前述の実行例の `Peak total used memory` を見ると `1288 bytes` であり、オフヒープの使用量は最大でもたった `1KB` 程度です。これはオンヒープと比べて極少ですからオフヒープのメモリ消費はほとんど気にする必要ない様に思えてしまいます。もちろんその様なことはなく、ケースバイケースでオフヒープも大きくメモリを消費することがあります。特にメモリ消費量が大きくなるケースはヒープダンプ出力時と JFR 機能有効時です。参考までに実際にこれら２つの機能を有効化した時のメモリ消費を紹介します。

:::note warn
例ではアプリケーションのビルド時に `--enable-monitoring=all` を指定し、ヒープダンプ出力機能と JFR 機能を含めたデバッグ機能を全て有効化しています。
:::

#### ヒープダンプ出力時のメモリ消費

まずはヒープダンプを出力した場合の NMT 測定結果を見てみましょう。この例では意図的に OutOfMemoryError を発生させるアプリケーション `outofmemoryerror` を実行してヒープダンプを出力させた時の NMT 記録を確認します。Native Image 実行オプションには、最大 Java ヒープサイズを制限するための `-Xmx100m -Xms100m` と、OutOfMemoryError 発生時にヒープダンプを出力するための `-XX:+HeapDumpOnOutOfMemoryError` 、NMT 出力のための `-XX:+PrintNMTStatistics` を指定します。

```:実行例
$ ./outofmemoryerror -Xmx100m -Xms100m -XX:+HeapDumpOnOutOfMemoryError -XX:+PrintNMTStatistics
Dumping heap to svm-heapdump-3828956-OOME.hprof ...
Heap dump file created [104278134 bytes in 0.139 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Array allocation too large.
...省略
Native memory tracking
  Peak total used memory: 518768 bytes
  Total alive allocations at peak usage: 7
  Total used memory: 248 bytes
  Total alive allocations: 2
...省略
  Heap Dump peak used memory: 518440 bytes
  Heap Dump alive allocations at peak: 5
  Heap Dump currently used memory: 0 bytes
  Heap Dump currently alive allocations: 0
...省略
```

ヒープダンプの出力は単発的な実行であるため、`Heap Dump` カテゴリの現在（`currently`）の消費量は `0 bytes` ですが、そのピーク（`peak`）は `506KB` 程度でありダンプ時にバーストしています。`Peak total used memory` と比較すると 99.9% はバーストしたメモリ消費量になります。Java ヒープサイズやアプリケーション特性によりさらに大きなメモリ消費となる可能性ありますのでヒープダンプ出力機能を有効化する場合はバーストすることに少し注意して下さい。

#### JFR 機能有効時のメモリ消費

続いて JFR 機能を有効化した NMT 測定結果を見てみましょう。この例ではスレッドスリープするだけのアプリケーション `sleep` に対し JFR を実行させた時の NMT 記録を確認します。Native Image 実行オプションには、 JFR 機能を起動時から有効化する `-XX:StartFlightRecording="filename=flight_record.jfr"` と NMT 出力のための `-XX:+PrintNMTStatistics` を指定します。なおこのアプリケーションは起動後まもなく手動で停止させています。

```
./sleep -XX:StartFlightRecording=filename=flight_recorder.jfr -XX:+PrintNMTStatistics
[warn][jfr,setting] @Deprecated JFR events, and leak profiling are not yet supported.
[warn][jfr,setting] @Deprecated JFR events, and leak profiling are not yet supported.
^C # アプリケーションの停止
Native memory tracking
  Peak total used memory: 10735813 bytes
  Total alive allocations at peak usage: 366
  Total used memory: 35944 bytes
  Total alive allocations: 11
...省略
  JFR peak used memory: 10727149 bytes
  JFR alive allocations at peak: 359
  JFR currently used memory: 32960 bytes
  JFR currently alive allocations: 4
...省略
```

JFR 機能は起動時から実行されているため、`JFR` カテゴリのメモリを常に消費します。現在（`currently`）の消費量は `32KB` 程度で、さらにピーク（`peak`）は `10476KB` 程度でありヒープダンプよりも大きいことが分かります。アプリケーション特性によって JFR の記録が増えることでさらに大きなメモリ消費となる可能性がありますので JFR 機能を有効化する場合もメモリ消費量が大きく増えることに少し注意して下さい。

## JFR イベントの追加

現在の Native Image の NMT はアプリケーション終了時の出力しかできず、アプリケーション実行中のオフヒープのメモリ消費を測定できません。ただし JFR 機能を使用すればアプリケーション実行中にサンプリングされた NMT 記録を参照できます。

GraalVM for JDK 21 では Native Image の NMT の実装に伴い、以下の NMT 関連の JFR イベントが追加されました。

|イベント |説明
|---|---|
|jdk.NativeMemoryUsage |カテゴリごとのメモリ使用量
|jdk.NativeMemoryUsageTotal |Total のメモリ使用量
|jdk.NativeMemoryUsagePeak |カテゴリごとのメモリ使用量のピーク（Native Image 固有イベント）
|jdk.NativeMemoryUsageTotalPeak |Total のメモリ使用量のピーク（Native Image 固有イベント）

このうち `jdk.NativeMemoryUsagePeak` および `jdk.NativeMemoryUsageTotalPeak` は **Native Image 固有実装のイベント**です。OpenJDK の JFR ではこれらのイベントは存在しないことに注意して下さい。特に VisualVM や JDK Mission Controler(JMC) の様なツールでフライトレコードを参照する場合はサポート対象外のイベントを表示する[設定](https://developers.redhat.com/articles/2024/05/21/native-memory-tracking-graalvm-native-image#getting_started_with_nmt_in_native_image)が必要です。

それぞれの JFR イベントは次の様な情報が記録されています。OpenJDK の NMT と同様にメモリ消費量を `reserved` および `committed` 単位で参照できます。ただし現時点では `malloc` しか追跡しないので同値です。なお割り当て回数（`alive allocations`）は取得できません。

:::note info
フライトレコードから特定のイベントのみを参照する場合は `jfr` ツール（GraalVM 同梱）を使用すると手軽です。

```
$ jfr print --events ${JFR_EVENT_NAME} ${FLIGHT_RECORD.jfr}
```

:::

### jdk.NativeMemoryUsage

```
jdk.NativeMemoryUsage {
  startTime = 17:01:41.718 (2024-11-27)
  type = "JFR"
  reserved = 10.2 MB
  committed = 10.2 MB
}
```
### jdk.NativeMemoryUsage

```
jdk.NativeMemoryUsageTotal {
  startTime = 17:01:36.397 (2024-11-27)
  reserved = 10.1 MB
  committed = 10.1 MB
}
```

### jdk.NativeMemoryUsagePeak 

```
jdk.NativeMemoryUsagePeak {
  startTime = 17:01:36.397 (2024-11-27)
  type = "Native Memory Tracking"
  peakReserved = 1.2 kB
  peakCommitted = 1.2 kB
  countAtPeak = 74
  eventThread = "main" (javaThreadId = 1)
}
```

### jdk.NativeMemoryUsageTotalPeak

```
jdk.NativeMemoryUsageTotalPeak {
  startTime = 17:01:41.718 (2024-11-27)
  peakReserved = 10.2 MB
  peakCommitted = 10.2 MB
  countAtPeak = 116
  eventThread = "JFR Shutdown Hook" (javaThreadId = 49)
}
```

## （参考）今後の機能追加

Native Image の NMT 機能は初期実装であり、今後も機能追加が計画されています。[開発者が執筆した情報](https://developers.redhat.com/articles/2024/05/21/native-memory-tracking-graalvm-native-image)をみると、今後の具体的な機能追加計画が紹介されています。また GitHub のイシューをみるとすでにいくつかの機能がアップストリームにマージされています。以下にいくつか紹介します。

* 仮想メモリ（mmap など）の追跡
  * [Java ヒープとイメージヒープの追加](https://github.com/oracle/graal/pull/9549)
* アプリケーション実行中の NMT 記録の取得
  * [SIGUSR1 シグナル受信によるヒープダンプと NMT 記録のダンプ](https://github.com/oracle/graal/pull/8876)
  * [jcmd によるデバッグログのダンプ（NMT/JFR/ヒープダンプなど）](https://github.com/oracle/graal/pull/9232)


## まとめ

GraalVM for JDK 23 から Native Image のデバッグ機能として NMT 機能が初期実装されました。Native Image のビルド時に `--enable-monitoring=nmt` を指定し、かつ Native Image 実行時に `-XX:+PrintNMTStatistics` を指定することでアプリケーション終了時に NMT 記録を出力できます。現時点の Native Image の NMT はオフヒープのメモリ消費量と割り当て回数を記録できますが、オンヒープは未実装です。

また Native Image の JFR に NMT 関連の JFR イベントが４つ追加されました。Native Image のビルド時に NMT 機能と JFR 機能を有効化することで、NMT 測定結果と同様の JFR イベントの情報を取得できます。

現時点では開発中の機能ですが、開発状況は活発で今後の機能改善に有用なデバッグ機能となることが期待できます。

## 参考文献

* [GitHub - oracle/graal(jdk-23.0.1)](https://github.com/oracle/graal/tree/jdk-23.0.1)
* [GraalVM Docs - Native Memory Tracking (NMT) with Native Image(GraalVM for JDK 23)](https://www.graalvm.org/latest/reference-manual/native-image/debugging-and-diagnostics/NMT/)
* [Red Hat Developer - Native memory tracking in GraalVM Native Image](https://developers.redhat.com/articles/2024/05/21/native-memory-tracking-graalvm-native-image)


記載されている会社名、製品名、サービス名は、各社の商標または登録商標です。