A Broken AOT Cache Still Serves 200

· 13 min read
Contents

Exit 1. Eight restarts. The health check gets no HTTP answer at all:

[truncated-on] flags=-XX:AOTCache=/aotcache/app.aot -XX:AOTMode=on -Xlog:aot
[truncated-on] state=status=restarting exit=1 restarts=8 health_http=000
[truncated-on] log: [0.002s][error  ][aot] An error has occurred while processing the AOT cache. Run with -Xlog:aot for details. [0.002s][error  ][aot] Loading static archive failed.

I broke that cache on purpose: truncated the trained file and started the Micronaut app on it. Then I started the same container on the same truncated file and dropped one flag, -XX:AOTMode=on:

[truncated-auto] flags=-XX:AOTCache=/aotcache/app.aot -Xlog:aot
[truncated-auto] state=status=running exit=0 restarts=0 health_http=200
[truncated-auto] log: [0.003s][error  ][aot] An error has occurred while processing the AOT cache. Run with -Xlog:aot for details. [0.003s][error  ][aot] Loading static archive failed.

Same two error lines. Running, zero restarts, health 200. Spring Boot and Quarkus did exactly the same thing against their own truncated caches.

That second block is the whole reason this post exists. The benchmark gained a scenario, jvm-aotcache-256mb: the JDK's AOT cache (Project Leyden, JEPs 483/514/515) at 256 MB, on all 18 synth branches. A tier like that can quietly measure plain java -jar and print "Leyden" on the chart. There are no numbers here. The measured results come with the full rerun.

The default for an unusable AOT cache is "continue"#

JEP 483 says so twice. In the walkthrough: "If the cache file is unusable or does not exist then HotSpot issues a warning message and continues." In the consistency rules: "If any of these constraints are violated then HotSpot, by default, issues a warning and ignores the cache."

The JEP says "warning". The log says [error], twice, and then the app serves traffic. In production that is the right call; the JEP's own example is a cloud provider adding a JVMTI class-file load hook for monitoring. In a benchmark it means a stale, truncated or mismatched cache produces a perfectly healthy run of the wrong thing. The row gets a label, a throughput, an RSS curve, and none of it involves the cache.

So the measured run passes AOTMode=on, which JEP 483 defines as "reports an error and exits if any of the above constraints are violated, or if the cache does not exist." From scripts/bench/lib.sh, identical on all 18 branches:

# AOTMode=on: a cache the JVM cannot use is a startup error, never a silent fallback (JEP 483).
export AOT_FLAGS="-XX:AOTCache=/aotcache/app.aot -XX:AOTMode=on -Xlog:aot"

A JVM that exits 1 crash-loops, wait_healthy gives up after 120 one-second tries, and the scenario aborts. A healthy run leaves a receipt in config.txt: aot_opened=[0.004s][info][aot] Opened AOT cache /aotcache/app.aot.

AOTMode=on catches a cache the JVM cannot use. A valid cache that learned nothing gets through. Reading the training path again showed that hole in the first version. warm_up ends in || log "WARN: warm-up did not complete cleanly (see warmup.txt)", and aot_train only checked that the cache file was non-empty. Had k6 failed, the JVM would still have written a cache on SIGTERM, trained on startup alone, and the measured run would have opened and mapped it without a word.

The fix landed on all 18 branches, one commit each (e3068b0f on Micronaut imperative-jdbc-synth). Training now has to prove itself twice: at least one successful warm-up request (http_reqs greater than http_req_failed), then the JDK's own AOTCache creation is complete line in the training log. "More than zero requests" would not have done it. To test the check, I pointed every warm-up request at the wrong host while the app stayed healthy. k6 still counted each attempt, and training stopped with FAIL: AOT training: warm-up did not train (http_reqs=5724 failed=5724).

The same pass caught an ordering problem. benchmark-all.sh runs under set -euo pipefail and used to sort jvm-aotcache-256mb in front of every other scenario, so one Leyden failure would have cost the whole branch its run. The same commits append it last and log a failure there as FAIL: $scenario (exit $?); suite continues.

--add-opens: the flag this repo already ships#

The third control case started an intact cache with one extra JVM flag:

[addopens-on] flags=-XX:AOTCache=/aotcache/app.aot -XX:AOTMode=on -Xlog:aot --add-opens=java.base/java.lang=ALL-UNNAMED
[addopens-on] state=status=restarting exit=1 restarts=8 health_http=000
[addopens-on] log: [0.027s][error][aot] An error has occurred while processing the AOT cache. Run with -Xlog:aot for details. [0.027s][error][aot] Mismatched values for property jdk.module.addopens: java.base/java.lang=ALL-UNNAMED specified during runtime but not during dump time

That flag is no contrived example. It is the exact string in every Micronaut jvm-vthreads-* script, four or five per branch, because the loom-carrier event loops reach into VirtualThread by reflection. JEP 483 lists --add-exports, --add-opens, --add-reads and four more as options that "must not be used". Without AOTMode=on, a vthreads-plus-cache scenario would have logged the mismatch and run on without the cache.

That is why jvm-aotcache-256mb is a copy of each branch's jvm-synth-256mb.sh: platform threads, no module flags, the same JAVA_TOOL_OPTIONS byte for byte. The Micronaut one:

#!/usr/bin/env bash
LABEL="jvm-aotcache-256mb"
# JDK AOT cache (Leyden), UPGRADE-PLAN row 1.42: jvm-synth-256mb plus a trained AOT cache.
# JAVA_TOOL_OPTIONS, memory limit and services are copied unchanged. Spring Boot and Quarkus also
# change jar layout here (extracted / aot-jar, so the JDK loaders see every class); Micronaut keeps
# its uber-jar. config.txt records it as aot_packaging.
COMPOSE_FILE="docker-compose-java.yml:docker-compose-synth.yml:docker-compose-aotcache.yml"
MEM_LIMIT="256m"
SERVICES="postgres mock app"
export JAVA_TOOL_OPTIONS="-Dmicronaut.executors.blocking.number-of-threads=50 -Dmicronaut.executors.blocking.type=FIXED -Xms64m -Xmx64m -Xss256k -XX:+UseSerialGC -XX:ReservedCodeCacheSize=32m -Dmicronaut.server.netty.worker.threads=4 -Dmicronaut.netty.event-loops.default.num-threads=4"
export AOT_TRAIN=1
source "$(dirname "$0")/scenario.sh"

AOT_TRAIN=1 makes the harness train first, identically for all three frameworks: same image, same options plus -XX:AOTCacheOutput, the existing warm-up, SIGTERM, fresh database.

Built-in class loaders: one JDK feature, three packagings#

JEP 483's non-goals carry the second rule: "Only classes loaded from the class path, the module path, and the JDK itself, by the JDK's built-in class loaders, can be cached." The three frameworks ship their JVM apps three different ways. So the new scenario gets its own aotcache stage in Dockerfile.java, the only per-framework text in the change:

  • Micronaut: the shaded uber-jar already runs on the JDK's app class loader. Copy it, done.
  • Spring Boot: the fat jar's classes go through Boot's LaunchedClassLoader. The Boot docs prescribe the extracted layout. The repo's Dockerfile.java line is java -Djarmode=tools -jar /app/app.jar extract --destination /app/extracted, and the scenario runs /app/extracted/app.jar.
  • Quarkus: fast-jar runs on Quarkus's RunnerClassLoader. The Quarkus guide prescribes aot-jar, which "Delegates all class loading to the JDK's class loaders". A separate builder stage repackages with -Dquarkus.package.jar.type=aot-jar plus the scenario's own build args.

The baseline image is unchanged, layer for layer, on all 18 branches.

How much each layout gets out of the cache, counted with -Xlog:class+load from start to healthy on each framework's imperative-jdbc-synth branch. "From cache" means the log said source: shared objects file:

PackagingApp classes (dev.tsvinc) from cacheAll classes from cache
Micronaut uber-jar197 / 19710,522 / 10,707 (98.3 %)
Spring Boot extracted109 / 10912,911 / 13,224 (97.6 %)
Spring Boot fat jar75 / 10510,300 / 12,413 (83.0 %)
Quarkus aot-jar109 / 10910,443 / 10,552 (99.0 %)
Quarkus fast-jar89 / 898,284 / 9,166 (90.4 %)

Keep the denominators straight. For Spring Boot the gap shows up in the app's own classes. For Quarkus the app's classes come out at 100 % either way; the 9-point gap is all in the framework and library classes behind them. The class totals move with the layout too. Repeat runs of the Quarkus layouts agree within a few dozen classes, so Quarkus's 89 against 109 is not noise. Spring Boot's 105 against 109 has no repeat run. I have not traced why either differs.

Custom-loader classes still came from the cache#

Look at the fat-jar and fast-jar rows again. The Spring Boot Dockerfile.java comment I wrote says the cache "cannot hold" those classes. The Quarkus one says "cannot AOT-link", which turns out to be the accurate version. The Spring Boot docs say a cache without the extracted form "has no effect". Yet 75 Spring Boot app classes and all 89 Quarkus app classes came from the archive.

The jdk25u sources explain the split. systemDictionaryShared.cpp archives classes from user-defined loaders as "unregistered" classes, with the comment // Do not exclude: unregistered classes are passed from preimage to final image. The AOT linker refuses them, in aotClassLinker.cpp:

if (!SystemDictionaryShared::is_builtin(ik)) {
  // not loaded by a class loader which we know about
  return false;
}

So a custom-loader class can come out of the archive already parsed. It never gets the load-and-link-ahead-of-time treatment that JEP 483 is about. Two consequences:

  • The class count overstates the fat jar. shared objects file says where the bytes came from, not whether the class arrived linked. The prescribed layouts win on all classes and on linking, and the scenario follows them.
  • Spring Boot and Quarkus run a different jar layout in this scenario than in jvm-synth-256mb. Their delta against the baseline will be cache plus layout, and the report has to say so. config.txt now records it as aot_packaging=. A no-cache run of the same layouts would separate the two; that control is proposed and waiting on a decision. Micronaut is the one framework where the delta is the cache alone.

One image for training and run#

The Quarkus metaspace post listed four walls between a trained cache and a JVM that maps it. Wall 3 was a cache trained in eclipse-temurin:25-jdk and run on 25-jre, rejected with "lib/modules size has changed". The fix I wrote down was "runtime must use the JDK image", and the plan for this tier inherited it.

That rule was wrong. Every aotcache stage is FROM eclipse-temurin:25.0.4.1_1-jre, the same digest as the baseline image, and training and the measured run both start from it. The cache mapped under AOTMode=on on 18 of 18 branches. JRE-trained, JRE-run, no complaint.

The rule that survives is narrower: one image for training and run. JEP 483 asks for "the same JDK release", and a JDK image and a JRE image of one release ship different lib/modules files.

The create step forks a second JVM with your JAVA_TOOL_OPTIONS#

Training uses JEP 514's one-step -XX:AOTCacheOutput: the JVM records during the run and, on exit, launches a child JVM to assemble the cache. JEP 514 is blunt about the cost: the child "uses its own Java heap with the same size as the heap used for the training run", so "the memory needed to complete the one-step workflow is double the heap size".

What does the child inherit? jdk25u's metaspaceShared.cpp answers in a comment above the loop that builds the child's arguments: // Pass all arguments. These include those from JAVA_TOOL_OPTIONS and _JAVA_OPTIONS. It filters out the parent's three AOT flags, puts back the output and configuration paths, appends -XX:AOTMode=create, and CDS.java hands the whole list to the child as its JAVA_TOOL_OPTIONS. The Micronaut training log shows the handoff:

app-1  | Launching child process /opt/java/openjdk/bin/java to assemble AOT cache /aotcache/app.aot using configuration /aotcache/app.aot.config
app-1  | Picked up JAVA_TOOL_OPTIONS: -Djava.class.path=/app/app.jar -Dmicronaut.executors.blocking.number-of-threads=50 -Dmicronaut.executors.blocking.type=FIXED -Xms64m -Xmx64m -Xss256k -XX:+UseSerialGC -XX:ReservedCodeCacheSize=32m -Dmicronaut.server.netty.worker.threads=4 -Dmicronaut.netty.event-loops.default.num-threads=4 -Xlog:aot -XX:AOTCacheOutput=/aotcache/app.aot -XX:AOTConfiguration=/aotcache/app.aot.config -XX:AOTMode=create
[...]
app-1  | [0.489s][info   ][aot] Heap range = [0x00000000fc000000 - 0x0000000100000000]
[...]
app-1  | AOTCache creation is complete: /aotcache/app.aot 85909504 bytes

That heap range spans 0x4000000 bytes: 64 MiB, the -Xmx64m the parent was given. Since -Xms64m -Xmx64m travel with the options, the training container can run under a 1 GB limit (two JVMs, two heaps) without changing the heap geometry the cache records.

Equal training time is not equal training#

The training workload is the harness's existing warm-up: k6, 5 constant VUs, 30 seconds. That is a closed loop. Each VU sends its next request when the last one returns, so a slow framework sends fewer. From each branch's aot-train/warmup.txt:

VariantMicronautQuarkusSpring Boot
imperative-jdbc-synth558155685654
reactive-r2dbc-synth553956415490
imperative-synth432416389
reactive-synth450454438
imperative-synth-more-io195172184
reactive-synth-more-io214200221

These are counts from the training logs. The request mix is the same for all three frameworks; the volume favours whoever is fastest cold. On the heavy variants a few hundred requests across a mixed workload is tens of calls per handler. jdk25u's compiler_globals.hpp sets Tier3InvocationThreshold to 200. Class loading needs one call per path, so the JEP 483 part of the cache is covered; the profiling side gets thin material there.

Training also runs against an empty database. Under WARMUP the k6 setup() returns before seeding anything, so data-bearing paths go untrained, equally for all three. The report will say "duration-equal, not volume-equal", and since the fix config.txt records aot_train_reqs= next to the cache size.

What the rerun has to answer#

The caches are 82 to 105 MB per branch: 82,132,992 bytes for Quarkus imperative-jdbc-synth at the low end, 105,484,288 for Spring Boot reactive-synth at the top. The JVM memory-maps that file inside a 256 MB container, and every measured log carries these lines, Micronaut's here:

[...]
app-1  | [0.004s][info][aot] ArchiveRelocationMode: 1
app-1  | [0.004s][info][aot] ArchiveRelocationMode == 1: always map archive(s) at an alternative address
[...]
app-1  | [0.004s][info][aot] Mapped static  region #0 at base 0x0000000059001000 top 0x000000005b25b000 (ReadWrite)
app-1  | [0.004s][info][aot] Mapped static  region #1 at base 0x000000005b25b000 top 0x000000005dcbc000 (ReadOnly)

Mapped at another address means the pointers inside get patched at startup, and the patched pages turn private, charged to the container when the JVM starts. Those two regions span 36.0 MB and 44.4 MB. The fix batch added an smaps read of the app.aot mapping, and the first idle reads on all three frameworks agree: mostly private dirty pages, zero shared clean ones. Most of the cache is private, non-reclaimable memory inside the limit.

That decides which columns can be compared. RSS can. The JVM-reported non-heap number cannot: the cache lives outside Metaspace, so non-heap drops in this row alone. Whether the cache costs more than the metaspace it replaces is the measurement, and the rerun takes it.

The JDK is due to change underneath the tier anyway. The images run Temurin 25.0.4.1. The jdk25u backport of 8386852, "Lower peak throughput with AOTCache", is one line in the JIT's tiering policy:

-  CompLevel next_level = common<CallPredicate>(method, cur_level, THREAD, !TrainingData::have_data() && is_old(method));
+  CompLevel next_level = common<CallPredicate>(method, cur_level, THREAD, is_old(method));

It sits in jdk-25.0.5+1 through +7 and not in jdk-25.0.4.1-ga. On 17 October jdk25u had no jdk-25.0.5-ga tag yet. Until 25.0.5 ships, any throughput this row shows on 25.0.4.1 is a lower bound. And a 25.0.5 cache row never shares a delta with a 25.0.4.1 baseline: the same tags carry C2 fixes such as 8378713 and 8347901 that move the plain JVM too. Every row records its base image tag and digest.

For now, the one guarantee the tier offers is negative. If a row says jvm-aotcache-256mb, the JVM behind it opened and mapped a cache whose training served at least one real request. Anything else exits 1.

Filed under: java, jvm, leyden, benchmarks, micronaut, quarkus, spring-boot, docker

Sources#