1% CPU and 6-Second Latency

The Memory Benchmark · Part 20

Part 20 of the Micronaut native image series. Follows Part 19, where a native image OOM’d at 256MB. Assumes familiarity with reactive Java and connection pooling.

Quarkus 3.33. Hibernate Reactive Panache. Mutiny. GraalVM native image in a 256MB container. Six endpoints, each fanning out to 28 mock APIs via Uni.combine, computing risk scores, persisting one row. The near-identical Spring WebFlux port did 100 req/s.

Quarkus did 18.8.

Average latency: 6.4 seconds. p95: 16 seconds. 33% of k6 checks failing. And the CPU was at 1%.

That last number is the one that matters. An app that’s slow because it’s doing too much work pins CPU. An app that’s slow at 1% CPU isn’t doing work at all — it’s waiting. Something is holding a lease on a pooled resource, and everything else is in line behind it.

The job was to find out what.

The code that looked fine

Every service method followed the same pattern — this is FullSurveyService, but all five were identical:

@WithTransaction
public Uni<FullSurveyResponse> execute() {
    // 28-API fan-out via Uni.combine (~3 seconds of HTTP calls)
    // Four blocks of 7-8 calls each, combined into Tuple8s
    var block1 = Uni.combine().all().unis(
            solarClient.solarFlares()
                .onFailure().recoverWithItem(EMPTY_SOLAR_FLARE),
            solarClient.cme()
                .onFailure().recoverWithItem(EMPTY_CME),
            // ... 26 more REST calls ...
    ).asTuple();

    // Combine all blocks, compute scores, then persist
    return Uni.combine().all().unis(block1, block2, block3, block4)
            .asTuple()
            .onItem().transformToUni(combined -> {
                // ... risk scoring, ~40 lines of math ...
                SurveyResult entity = new SurveyResult();
                entity.setSurveyType("full");
                entity.setResultSummary(summary);
                entity.setCreatedAt(Instant.now());
                return entity.persist().replaceWith(response);
            });
}

One annotation. Twenty-eight API calls. One INSERT. What could go wrong?

What @WithTransaction actually does

Hibernate Reactive’s @WithTransaction is a CDI interceptor. It opens a reactive session and acquires a database connection at method entry, then holds both until the returned Uni completes. The transaction commits (or rolls back) when the entire reactive chain finishes.

Read that again. The connection is acquired when execute() is called, not when entity.persist() is called. The 28-API fan-out — three seconds of network I/O that has nothing to do with the database — runs with a connection pinned.

The reactive pool had max-size=14. Fourteen connections. Fourteen requests could be in-flight. Request fifteen waited. Request three hundred waited a long time.

Prometheus confirmed it. The metric sql_pool_queue_size — the number of requests waiting for a connection — had hit 287.

Two hundred and eighty-seven requests queued behind fourteen connections, each held for ~3 seconds of HTTP fan-out, to eventually run a 0.2ms INSERT.

Fix 1: scope the transaction to the database operation

Remove the method-level annotation. Wrap only the persist:

public Uni<FullSurveyResponse> execute() {
    // ... same 28-API fan-out, same risk scoring ...

    return Panache.withTransaction(() -> entity.persist())
            .replaceWith(response);
}

The connection is now held for the duration of entity.persist() — about a millisecond — instead of the duration of the entire request.

Results:

MetricBeforeAfter fix 1
req/s18.833.5
avg latency6.4s3.5s
sql_pool_queue_size2876

Better. Not good. 33.5 req/s is still a third of what Spring does with the same code. And the CPU was still idle.

Fixing one bottleneck unmasked the next.

The second queue

Still 3.5 seconds average at near-zero CPU. Still waiting on something. Different something.

A different Prometheus metric this time: http_client_queue_delay_seconds_max. The maximum time a REST client request spent waiting — not for a response, but for a connection from the pool to send the request on. The value for the “science” client: 5.08 seconds.

The Quarkus REST client (built on Vert.x) defaults to a connection pool of 50 per client. Six of the ten client interfaces — SolarClient, SatelliteClient, SeismicClient, AtmosphereClient, OceanClient, AstronomyClient — share a single configKey called science and carry 24 of the 28 calls. At 300 virtual users, the offered concurrency vastly exceeds 50 connections. Calls pile up waiting for a slot.

Spring’s reactor-netty uses a default pool of 500 max connections. The same fan-out pattern, the same 300 VUs, and reactor-netty has 10x the headroom. This wasn’t a code difference — it was a framework-default difference.

Fix 2: raise the pool

# Vert.x rest-client pool defaults to 50 — too small for 24-way fan-out
quarkus.rest-client.science.connection-pool-size=200
quarkus.rest-client.nasa-neo.connection-pool-size=100

This one is a runtime property — no native rebuild needed, just change the config and restart. Not all Quarkus config is this forgiving.

Results after both fixes:

MetricOriginalAfter fix 1After both
req/s18.833.5100.3
avg latency6.4s3.5s1.16s
p95 latency16s2.7s
errors33%0.002%
sql_pool_queue_size2876
RSS213MB

100 req/s. At parity with Spring. Both stacks ultimately gated by the ~350ms mock-API latency, not the framework.

The diagnostic pattern

Both bottlenecks had the same signature: low CPU, high latency. The app wasn’t computing — it was in a queue. Neither showed up in application logs, stack traces, or error messages. Nothing was throwing. Nothing was timing out (yet). Everything was just… slow.

The diagnostic tool was queue-depth metrics:

  • sql_pool_queue_size — how many requests are waiting for a database connection. If this is nonzero and your queries take 0.2ms, the connections are pinned by something that isn’t the query.
  • http_client_queue_delay_seconds_max — how long an HTTP client request waited for a connection slot. If this is seconds, the pool is undersized for your concurrency pattern.

Both metrics come from Micrometer, scraped by Prometheus, and are available on any /q/metrics endpoint. They’re there. Nobody checks them until the latency numbers stop making sense.

Three rules fell out of this:

A transaction annotation is a resource lease. In a reactive stack, @WithTransaction pins a database connection for the lifetime of the returned Uni — the whole reactive chain, not just the database operations in it. Wrapping a 3-second fan-out in a transaction means holding a connection for 3 seconds to run a 0.2ms INSERT. Scope transactions to the database operation, always.

Framework defaults are invisible throttles. Vert.x’s 50-connection pool is reasonable for ordinary request patterns. Reactor-netty’s 500 is reasonable for theirs. Neither is documented as a performance-critical setting. When your concurrency pattern doesn’t match the framework’s assumptions, the default becomes a bottleneck you can’t see in a stack trace.

Fixing one bottleneck unmasks the next. The connection-pool queue was invisible until the transaction pinning was fixed, because the DB bottleneck limited concurrency below the level where the HTTP pool would saturate. Measure again after every fix.

Sources