Go to Qiita Advent Calendar 2024 Top
LoginSignup
14
5

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

NTTコムウェアAdvent Calendar 2024

Day 5
@comware_osakamoto(Osamu SAKAMOTO)inNTTコムウェア株式会社

GraalVM Native Image の Native Memory Tracking の紹介

Last updated at Posted at 2024-12-04

この記事は NTT コムウェア Advent Calendar 2024 5日目の記事です。

はじめに

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

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

今年は日本 Java ユーザグループ主催の JJUG CCC 2024 Fall にて、OpenJDK の Native Memory Tracking(NMT) 機能について調査した結果を発表させていただきました。
本記事はそれに関連して、GraalVM for JDK 23 から追加された Native Image の Native Memory Tracking(NMT) について調査した結果を紹介します。

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

なお本記事の内容は GraalVM for JDK 23 に基づいて執筆していますので、今後のアップデートで変更の可能性があることにご留意ください。

概要

GraalVM for 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

--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 その他

カテゴリの定義は NmtCategory.java から確認できます。

さらにそれぞれについて以下の４つの情報が出力されます。現在（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 のみ）を追跡し、割り当てごとにメモリ消費量を記録します。割り当てが発生した場合はその分のメモリ消費量を加算し回数をインクリメントします。割り当て解除が発生した場合はそのメモリ消費量を減算し回数をデクリメントします。

メモリ消費量を追跡する実装は 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 機能有効時です。参考までに実際にこれら２つの機能を有効化した時のメモリ消費を紹介します。

例ではアプリケーションのビルド時に --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) の様なツールでフライトレコードを参照する場合はサポート対象外のイベントを表示する設定が必要です。

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

フライトレコードから特定のイベントのみを参照する場合は 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 機能は初期実装であり、今後も機能追加が計画されています。開発者が執筆した情報をみると、今後の具体的な機能追加計画が紹介されています。また GitHub のイシューをみるとすでにいくつかの機能がアップストリームにマージされています。以下にいくつか紹介します。

まとめ

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 イベントの情報を取得できます。

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

参考文献

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

14
5
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
14
5

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?