2024年4月23日
Quarkus 原生应用程序发生 OutOfMemoryError 时获取堆转储
从 JDK 21 的 GraalVM 开始，原生可执行文件可以使用 -XX:+HeapDumpOnOutOfMemoryError 选项在抛出 java.lang.OutOfMemoryError 时生成堆转储。在本篇博客文章中，我们将探讨如何使用此标志，检查 GraalVM 原生镜像的堆转储是什么样的，以及它与 HotSpot 生成的堆转储有何不同。
注意：GraalVM 原生镜像可执行文件的堆同时包含只读和读写段。只读部分称为“镜像堆”，其中包含在镜像构建期间预先初始化的数据，以帮助加快启动速度。读写部分是在运行时进行分配的地方。因此，在运行时生成的堆转储将包含“镜像堆”和读写堆的内容。
要让此标志生效，我们需要制造一个 Quarkus 应用程序耗尽内存的情况。一种简单的方法是配置应用程序使用一个不进行任何内存回收的垃圾收集器，即 Epsilon GC。一旦 Quarkus 应用程序以 Epsilon GC 运行，施加一些负载，在短时间内它就会耗尽内存并生成堆转储。
让我们以一个简单的响应 HTTP 端点请求的 Quarkus 应用程序作为起点来实现这一点。可以使用浏览器或命令行通过 code.quarkus.io 下载示例应用程序。
$ wget "https://code.quarkus.io/d?S=io.quarkus.platform%3A3.8&cn=code.quarkus.io" -O code.zip
$ unzip code.zip
$ cd code-with-quarkus接下来，使用 GraalVM for JDK 21 构建一个 Quarkus 原生可执行文件，并配置它使用 Epsilon GC。
$ ./mvnw package -DskipTests -Dnative -Dquarkus.native.additional-build-args=--gc=epsilon注意：对于 Quarkus 原生应用程序，GC 选择需要在构建时完成。
在生成 Quarkus 原生可执行文件的过程中，您将能够观察到 GC 确实被配置为 EpsilonGC。
[INFO] --- quarkus-maven-plugin:3.9.3:build (default) @ getting-started-reactive ---
...
[1/8] Initializing...
Java version: 21.0.2+13, vendor version: GraalVM CE 21.0.2+13.1
Graal compiler: optimization level: 2, target machine: compatibility
C compiler: gcc (redhat, x86_64, 13.2.1)
Garbage collector: Epsilon GC (max heap size: 80% of RAM)构建完成后，使用 -XX:+HeapDumpOnOutOfMemoryError -XX:+ExitOnOutOfMemoryError 启动 Quarkus。后者会在发生 OutOfMemoryError 时强制应用程序关闭，而不是让进程处于不确定的状态。
$ getting-started-reactive-1.0.0-SNAPSHOT-runner -XX:+HeapDumpOnOutOfMemoryError -XX:+ExitOnOutOfMemoryError -Xmx64m
__ ____ __ _____ ___ __ ____ ______
--/ __ \/ / / / _ | / _ \/ //_/ / / / __/
-/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2024-04-12 09:58:00,855 INFO [io.quarkus] (main) getting-started-reactive 1.0.0-SNAPSHOT native (powered by Quarkus 3.9.3) started in 0.030s. Listening on: http://0.0.0.0:8080
2024-04-12 09:58:00,855 INFO [io.quarkus] (main) Profile prod activated.
2024-04-12 09:58:00,855 INFO [io.quarkus] (main) Installed features: [cdi, rest, smallrye-context-propagation, vertx]接下来，对 Quarkus 应用程序暴露的 HTTP 端点施加一些负载，例如使用 bash 循环中的 curl。
$ while true; do curl https://:8080/hello; done切换到 Quarkus 控制台，您将看到 OutOfMemoryError 以及一些指示正在生成堆转储的消息。
2024-04-12 09:58:00,855 INFO [io.quarkus] (main) getting-started-reactive 1.0.0-SNAPSHOT native (powered by Quarkus 3.9.3) started in 0.030s. Listening on: http://0.0.0.0:8080
2024-04-12 09:58:00,855 INFO [io.quarkus] (main) Profile prod activated.
2024-04-12 09:58:00,855 INFO [io.quarkus] (main) Installed features: [cdi, rest, smallrye-context-propagation, vertx]
Dumping heap to svm-heapdump-2213-OOME.hprof ...
Heap dump file created [98454651 bytes in 0.733 secs]
Terminating due to java.lang.OutOfMemoryError: Garbage-collected heap size exceeded.市面上有多种图形化工具可以检查堆转储，例如 VisualVM、Eclipse Memory Analyzer (MAT) 等，但也有一些新的工具可以在命令行运行，以快速了解堆转储的概况，例如 Java Object Layout (JOL)。
$ java -Xmx256m -DprintFirst=6 -jar jol-cli.jar heapdump-stats svm-heapdump-2213-OOME.hprof
Heap Dump: svm-heapdump-2213-OOME.hprof
Read progress: DONE
Hotspot Layout Simulation (JDK 21, Current VM: 12-byte object headers, 4-byte references, 8-byte aligned objects, 8-byte aligned array bases)
=== Class Histogram
Table is sorted by "INSTANCES".
Printing first 6 lines. Use -DprintFirst=# to override.
INSTANCES SIZE SUM SIZE CLASS
------------------------------------------------------------------------------------------------
132,330 24 3,175,920 java.lang.String
50,277 40 2,011,080 io.vertx.core.http.impl.headers.HeadersMultiMap$MapEntry
44,852 40 1,794,080 com.oracle.svm.core.monitor.JavaMonitor
38,755 32 1,240,160 java.util.HashMap$Node
33,776 24 810,624 byte[5]
31,728 48 1,522,944 java.util.HashMap
... ... ... ...
899,336 9,438,056 48,193,360 <other>
------------------------------------------------------------------------------------------------
1,231,054 9,438,264 58,748,168 <total>
=== Class Histogram
Table is sorted by "SIZE".
Printing first 6 lines. Use -DprintFirst=# to override.
INSTANCES SIZE SUM SIZE CLASS
------------------------------------------------------------------------------------------------
1 3,480,544 3,480,544 byte[3480528]
1 3,236,728 3,236,728 byte[3236705]
1 642,648 642,648 byte[642626]
1 289,824 289,824 byte[289808]
1 173,664 173,664 byte[173645]
1 157,728 157,728 byte[157710]
... ... ... ...
1,231,048 1,457,128 50,767,032 <other>
------------------------------------------------------------------------------------------------
1,231,054 9,438,264 58,748,168 <total>
=== Class Histogram
Table is sorted by "SUM SIZE".
Printing first 6 lines. Use -DprintFirst=# to override.
INSTANCES SIZE SUM SIZE CLASS
------------------------------------------------------------------------------------------------
1 3,480,544 3,480,544 byte[3480528]
1 3,236,728 3,236,728 byte[3236705]
132,330 24 3,175,920 java.lang.String
50,277 40 2,011,080 io.vertx.core.http.impl.headers.HeadersMultiMap$MapEntry
10,054 184 1,849,936 io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext
44,852 40 1,794,080 com.oracle.svm.core.monitor.JavaMonitor
... ... ... ...
993,539 2,720,704 43,199,880 <other>
------------------------------------------------------------------------------------------------
1,231,054 9,438,264 58,748,168 <total>通过堆转储中存在的 com.oracle.svm.core.monitor.JavaMonitor 实例，可以清晰地观察到驱动 GraalVM 原生镜像的可执行文件 VM SubstrateVM。如果我们重复完全相同的练习，但改用 Quarkus JVM 模式，堆转储会是什么样子？让我们来看看。
为 JVM 模式重新构建 Quarkus 应用，并使用 Epsilon GC 运行它。
$ mvnw package -DskipTests
$ java -XX:+HeapDumpOnOutOfMemoryError -XX:+ExitOnOutOfMemoryError -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC -Xmx64m -jar quarkus-run.jar
__ ____ __ _____ ___ __ ____ ______
--/ __ \/ / / / _ | / _ \/ //_/ / / / __/
-/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2024-04-12 10:02:37,945 INFO [io.quarkus] (main) getting-started-reactive 1.0.0-SNAPSHOT on JVM (powered by Quarkus 3.9.3) started in 1.692s. Listening on: http://0.0.0.0:8080
2024-04-12 10:02:37,961 INFO [io.quarkus] (main) Profile prod activated.
2024-04-12 10:02:37,962 INFO [io.quarkus] (main) Installed features: [cdi, rest, smallrye-context-propagation, vertx]施加相同的负载后，您也会在 JVM 模式下观察到堆转储的生成。
2024-04-12 10:02:37,945 INFO [io.quarkus] (main) getting-started-reactive 1.0.0-SNAPSHOT on JVM (powered by Quarkus 3.9.3) started in 1.692s. Listening on: http://0.0.0.0:8080
2024-04-12 10:02:37,961 INFO [io.quarkus] (main) Profile prod activated.
2024-04-12 10:02:37,962 INFO [io.quarkus] (main) Installed features: [cdi, rest, smallrye-context-propagation, vertx]
java.lang.OutOfMemoryError: Java heap space
Dumping heap to java_pid2841.hprof ...
Heap dump file created [97383542 bytes in 1.232 secs]
Terminating due to java.lang.OutOfMemoryError: Java heap space而这便是使用 JOL 时的堆转储样子。
java -Xmx256m -DprintFirst=6 -jar jol-cli.jar heapdump-stats java_pid2841.hprof
Heap Dump: java_pid2841.hprof
Read progress: DONE
Hotspot Layout Simulation (JDK 21, Current VM: 12-byte object headers, 4-byte references, 8-byte aligned objects, 8-byte aligned array bases)
=== Class Histogram
Table is sorted by "INSTANCES".
Printing first 6 lines. Use -DprintFirst=# to override.
INSTANCES SIZE SUM SIZE CLASS
------------------------------------------------------------------------------------------------
91,335 24 2,192,040 java.lang.String
35,946 40 1,437,840 io.vertx.core.http.impl.headers.HeadersMultiMap$MapEntry
34,942 32 1,118,144 java.util.HashMap$Node
22,998 24 551,952 byte[5]
22,789 48 1,093,872 java.util.HashMap
22,381 32 716,192 java.util.concurrent.ConcurrentHashMap$Node
... ... ... ...
716,986 19,427,976 59,367,272 <other>
------------------------------------------------------------------------------------------------
947,377 19,428,176 66,477,312 <total>
=== Class Histogram
Table is sorted by "SIZE".
Printing first 6 lines. Use -DprintFirst=# to override.
INSTANCES SIZE SUM SIZE CLASS
------------------------------------------------------------------------------------------------
1 972,120 972,120 int[243026]
1 416,136 416,136 int[104030]
1 282,056 282,056 int[70510]
1 237,608 237,608 byte[237587]
1 131,920 131,920 int[32976]
1 129,672 129,672 int[32414]
... ... ... ...
947,371 17,258,664 64,307,800 <other>
------------------------------------------------------------------------------------------------
947,377 19,428,176 66,477,312 <total>
=== Class Histogram
Table is sorted by "SUM SIZE".
Printing first 6 lines. Use -DprintFirst=# to override.
INSTANCES SIZE SUM SIZE CLASS
------------------------------------------------------------------------------------------------
91,335 24 2,192,040 java.lang.String
7,189 232 1,667,848 io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext
35,946 40 1,437,840 io.vertx.core.http.impl.headers.HeadersMultiMap$MapEntry
15,528 80 1,242,240 java.util.HashMap$Node[16]
14,380 80 1,150,400 io.vertx.core.http.impl.headers.HeadersMultiMap$MapEntry[16]
34,942 32 1,118,144 java.util.HashMap$Node
... ... ... ...
748,057 19,427,688 57,668,800 <other>
------------------------------------------------------------------------------------------------
947,377 19,428,176 66,477,312 <total>如预期所示，此堆转储中不存在 SubstrateVM 类，堆转储中只剩下 Quarkus、Vert.x 和 OpenJDK 类型。
