Three Bugs in a Trenchcoat Pretending to Be One Hang

The CLAUDE.md for this project had a one-liner that persisted for a week: “Micronaut AOT hangs — keep disabled.”

Every developer who touched the project read that line, nodded, and moved on. AOT disabled. Property set to false. Life continued. Nobody questioned it because it was technically true — AOT had hung — and the project worked without it.

Then the benchmark numbers arrived. Non-heap at 119 MB. Container limit at 256 MB. JVM OOM-killing at 150 concurrent users. And a footnote in the Micronaut AOT docs: “build-time service loading reduces runtime metaspace by eliminating classpath scanning.”

So I turned it on. And it hung.

Bug 1: The Genuine Hang

property-source-loader.generate.enabled=true in aot-jar.properties. This flag tells Micronaut’s AOT plugin to convert YAML/properties configuration into generated Java code at build time. Faster config loading, no YAML parsing at startup.

With R2DBC + Liquibase on Micronaut 5.0.0, the build succeeds. The JAR packages. The container starts. The Micronaut banner prints. Then silence. No “Startup completed” message. No port binding. curl localhost:8181/health hangs indefinitely.

This is a real bug. The generated property source code interacts with R2DBC’s reactive connection factory initialization and Liquibase’s synchronous migration runner, creating a deadlock. The reactive event loop waits for Liquibase to finish database migration. Liquibase waits for a database connection. The connection factory waits for configuration that hasn’t finished loading because the generated property source is waiting for… the reactive event loop.

# MUST be false — deadlocks with R2DBC + Liquibase on Micronaut 5.0.0
property-source-loader.generate.enabled=false

This was the bug the CLAUDE.md documented. It’s real. But it was the only one of three problems that was actually AOT’s fault.

Bug 2: The Zombie Container

After fixing Bug 1, re-enable the other AOT optimizations. Build. Start. Wait for startup message.

08:14:22.115 [main] INFO  io.micronaut.runtime — Startup completed in 2847ms.

Nothing. No log line. Container must be hanging again.

Check the port:

$ curl localhost:8182/health
curl: (7) Failed to connect to localhost port 8182: Connection refused

Dead. AOT is still broken, right?

$ docker ps
CONTAINER ID   IMAGE                          STATUS
a1b2c3d4e5f6   micronaut-native-as-hell-app   Up 3 minutes
f6e5d4c3b2a1   micronaut-native-as-hell-app   Up 47 minutes    # <-- what

Two containers. The benchmark script uses timeout 30 docker compose up for the health check. When the previous debug run exceeded the timeout, timeout killed the shell process but not the container. Docker Compose detached. The old container held port 8182. The new container tried to bind, got Address already in use, and exited. The exit looked like a hang because nobody checked the logs — we checked the port.

$ docker compose down  # kill zombie
$ docker compose up -d
$ curl localhost:8182/health
{"status":"UP"}

AOT wasn’t broken. A zombie from 47 minutes ago was squatting on the port.

Bug 3: The Silent Application

Zombie killed. AOT enabled (with the three correct flags disabled). Container starts, port binds, health check passes. But the benchmark script still reports “startup not detected”:

# from the bench scenario script
timeout 60 bash -c 'until docker compose logs app 2>&1 | grep -q "Startup completed"; do sleep 1; done'

The script greps for “Startup completed” in the logs. The log never contains that string.

Why? logback.xml:

<logger name="io.micronaut" level="WARN" />

This suppresses everything below WARN for the entire io.micronaut namespace. Including io.micronaut.runtime.Micronaut, which logs the startup message at INFO.

There’s a more specific logger above it:

<logger name="io.micronaut.runtime" level="INFO" />

Logback processes loggers by specificity. The io.micronaut.runtime logger at INFO should take precedence over io.micronaut at WARN for classes under io.micronaut.runtime.

But the startup message is logged by io.micronaut.runtime.Micronaut using:

LOG.info("Startup completed in {}ms.", elapsedMillis);

This works. The logger hierarchy is correct. The app logs the startup message. The problem: when AOT’s logback.xml.to.java.enabled=true converts the XML to generated Java code, the logger ordering is flattened. The generated code doesn’t preserve XML document order — it iterates the model and registers loggers in a different sequence. The parent logger’s WARN level ends up taking precedence over the child’s INFO level.

The app was running. The app was healthy. The app was serving requests. The benchmark script couldn’t see it because the startup log line was suppressed. The “hang” was a grep finding nothing.

Fix:

<logger name="io.micronaut.runtime" level="INFO" />
<logger name="io.micronaut" level="WARN" />

Order already correct in the XML. The real fix: either disable logback.xml.to.java.enabled for the JVM JAR build, or accept that the generated logback code requires explicit logger configuration that doesn’t rely on XML document ordering.

Three Bugs, One Symptom

The CLAUDE.md said “AOT hangs.” One bug hangs. One bug was a stale container. One bug was a logging config interaction. All three presented identically: you enable AOT, the app “doesn’t start.”

The Punchline: 18 MB

Fix all three. Enable AOT with the working configuration:

# aot-jar.properties — the flags that work
cached.environment.enabled=true
serviceloading.jit.enabled=true
scan.reactive.types.enabled=true
deduce.environment.enabled=true
known.missing.types.enabled=true
logback.xml.to.java.enabled=true

# The three that must stay false
property-source-loader.generate.enabled=false    # deadlocks R2DBC + Liquibase
precompute.environment.properties.enabled=false   # DB config from runtime env vars
sealed.property.source.enabled=false              # DB config from runtime env vars

Also disable OpenAPI — the micronaut-openapi annotation processor generates swagger metadata classes that load into metaspace at runtime. This app is an API behind k6, not serving Swagger UI to anyone.

Run the full benchmark. JVM at 256 MB. Same Serial GC flags. Same Netty thread limits.

*119 MB measured from jvm-unlimited as proxy — jvm-256mb OOM’d before non-heap reached steady state.

Non-heap dropped from 119 MB to 101 MB. That’s 18 MB.

18 MB is the difference between 81.3% error rate and 0% error rate. Between 4,550 successful requests and 1,662,591. Between “the JVM can’t do this” and “the JVM does this fine.”

Build-time service loading eliminated runtime classpath scanning classes. Build-time reactive type detection eliminated reflection metadata. Build-time environment deduction eliminated environment-probing code. Removing OpenAPI eliminated swagger model classes from metaspace. Together: 18 MB of metaspace that was allocated at startup and never freed.

The code-level backpressure fixes from another branch — flatMap concurrency limits, pagination, bounded queries — weren’t even needed. They solve a real problem (memory under sustained load), but the AOT fix solves the startup problem (metaspace at idle). Different bugs, same symptom.

A one-line note in a CLAUDE.md, left unquestioned for a week, was hiding 18 MB of free memory. Three bugs wore a trenchcoat and pretended to be one. Nobody checked under the coat.

Sources

• Micronaut AOT Plugin Guide — optimization flags, property source generation
• Logback Logger Hierarchy — logger inheritance, effective level
• Docker Compose timeout behavior — container lifecycle on shell signal
• Part 4: Every GC Failed at 256 MB — Serial GC as sole survivor
• Part 5: Your JVM Reports 151 MB — invisible memory overhead