User code is 1–4 % of a Ktor service's CPU: a negative result for a bytecode optimiser

github/youndie/zavarnik

The plan was a Gradle plugin with two engines: a K2 IR pass over user code — boxing at suspend boundaries, fused collection chains, lazy logging, hoisted constants — and an ASM transform over the whole runtime classpath. The brief put a gate in front of it: measure what share of a real Ktor CIO service's profile user code actually owns, and what R8 with a sensible server configuration already delivers, because those two numbers bound what such a plugin can ever move. This is the result of that gate. The plugin was not built; the stand, the harness and the research document are in zavarnik under bench/ and docs/research/research-optimizer.md.

The stand

  • Service: Ktor 3.5.2 on CIO, kotlinx.serialization 1.11.0, slf4j-simple. Three endpoints: /echo, /items (JSON CRUD over an in-memory store), /business (collection chains, a regex validation, three logger.debug templates per request with debug disabled).
  • Load: oha, 64 connections, keep-alive; JVM pinned to cores 0–7, generator to 8–15, -Xms1g -Xmx1g -XX:+UseG1GC.
  • Profiler: async-profiler 4.5, cpu for 120 s then alloc for 120 s after 60 s of warm-up.
  • Machine: Ubuntu 24.04 in WSL2, Core Ultra 7 255HX, OpenJDK 25.0.4.
  • Attribution: every sample is classified twice. Self is the leaf frame; owner is the first frame from the leaf that is neither JDK nor JVM — whose code asked for this. Owner is the number that matters: it is the ceiling for anything that rewrites that code.

The share

Endpoint rps p99 user CPU, self / owner user alloc, self / owner
/echo 35 740 11.4 ms 0.0 % / 0.0 % 0.2 % / 0.2 %
/items?limit=20 38 008 8.0 ms 0.8 % / 0.8 % 0.3 % / 0.3 %
/business 33 935 10.2 ms 1.1 % / 2.1 % 3.6 % / 9.9 %

On the endpoint written to give user code the most to do, user code owns 2.1 % of CPU and 9.9 % of allocated bytes. Three further CPU profiles of the same endpoint, taken while checking a hypothesis about core pinning, gave 1.7–2.0 %. The rest of /business by owner: CPU — kotlinx 73.9 %, Ktor 15.5 %, stdlib 8.4 %; allocations — Ktor 36.8 %, kotlinx 26.4 %, stdlib 26.8 %.

A stand can be accused of being written for the answer, so the same harness was run inside the container of a service that was not written for it: konekt, my own reference project — an eSIM operator's account backend on Ktor CIO with Exposed and Postgres, twelve JVM modules — under its own k6 scenario at a constant arrival rate, one core and 1 GiB. A reference project, not production traffic; what it adds is a database, a serialiser and a framework stack that the stand does not have.

Rate p95 user CPU, self / owner user alloc, self / owner
50 rps 3.97 ms 2.5 % / 4.0 % 1.0 % / 3.4 %
200 rps 2.93 ms 0.5 % / 0.9 % 1.3 % / 5.4 %

konekt is a database driver, a serialiser and a framework with a thin layer of user code on top; the share is lower than on the stand, not higher. Its biggest allocation owners were stdlib (26.6 %), Ktor (24.8 %), kotlinx (13.6 %) and Exposed (13.5 %) — none of them the territory of a pass over user code.

Where the profile actually is

A third of /business CPU is the coroutine dispatcher's queue: LockFreeTaskQueue.removeFirstOrNull at 30.1 % self plus LockFreeTaskQueueCore.removeFirstOrNull at 5.9 %, 36 % together, under LimitedDispatcher. I took it for an artefact of pinning the JVM to 8 cores while availableProcessors saw 20, and measured it three more ways: pinned, pinned with -XX:ActiveProcessorCount=8, and unpinned. The third of CPU is there in all three, with the frames shifting between removeFirstOrNull and obtainTaskOrDeallocateWorker. It is a property of CIO under this load — 64 keep-alive connections, sub-millisecond handlers — not of the harness, and neither an IR pass nor a bytecode peephole can touch it. Netty against CIO under the same protocol is the obvious next measurement; it is not in this post.

The rest, by size:

  • The top of the allocation profile is byte[] at 18.4 %, String 6.8 %, Object[] 5.9 %: Ktor's I/O buffers and JSON parsing.
  • kotlin.reflect.jvm.internal.KClassImpl.toString runs on every call.receive<T>(), from the default body transformations, and costs 1.98 % of all bytes on /business.
  • Boxing — Integer, Long, Double — is 1.26 % of allocated bytes. The brief's red line for a boxing pass was 3 %.

What user code does spend, all on /business: a Regex constructed inside the handler, 6.45 % of bytes including the Matcher and its arrays; intermediate collections of filter/map chains, about 4.6 %; the three debug templates, 1.57 %. The first two are fixed by moving one line each. Nothing else is above 2 %.

R8 as the baseline

The brief asked for R8 with a server configuration — no obfuscation, keeps on serialisation, Ktor, coroutines and slf4j, -assumenosideeffects on Intrinsics.check* — as the line a plugin must beat. R8 9.4.17 processes the 26 jars in 26 s, 6503 classes to 5416. The result does not start:

java.lang.VerifyError: Bad invokespecial instruction: interface method to invoke is not in a direct superinterface
    at kotlinx.coroutines.CompletableDeferred.access$cancel$jd

The mechanism is visible in javap. Kotlin compiles the synthetic accessor as invokespecial InterfaceMethod CompletableDeferred.cancel:()V, a call to a default method through the current interface. R8 rebinds the reference to the declaring interface, invokespecial InterfaceMethod Job.cancel:()V, and the verifier requires the interface in an invokespecial to be the current class or a direct superinterface; Job is reached through Deferred. -dontoptimize -dontshrink gives the same error, so does --no-desugaring, so does 9.5.10-dev; keeping coroutines out of the input moves the error into Ktor's Routing. kotlinc had the same bug on its side until 1.5.0 (KT-42753). Any Kotlin interface compiled with -Xjvm-default=all is affected, which is the whole coroutines and Ktor stack. The rule is a classfile rule; DEX has no equivalent, which is presumably why the classfile backend never met it.

What can be measured is R8 over the user jar alone, with the 25 library jars on --classpath. That removes all 56 Intrinsics.check* calls from user code and cuts its bytecode by 35 %. The effect on the service, same protocol:

Endpoint alloc/req, baseline alloc/req, R8 rps A/B median, baseline rps A/B median, R8
/echo 14.6 KiB 14.6 KiB 36 990 41 434
/items 23.7 KiB 23.2 KiB 37 439 37 143
/business 33.8 KiB 34.0 KiB 27 531 28 241

Allocations per request did not move (within 2 %): null checks do not allocate, and inlining inside 39 classes changed nothing. Throughput was measured separately, without profilers, both variants alternating, three runs each, medians. /echo — where there is no user code and R8 had nothing to change — came out 12 % faster under B. That number is the noise ruler of this stand, and the /business delta of +2.6 % sits inside it.

What the stand taught about measuring

  • A CPU profiler at 1 ms costs throughput: /echo served 35 740 rps under it and 44 906 rps in the allocation window of the same run. Profile and throughput are two protocols, not one.
  • Run-to-run spread on this machine is ±15 % even on the endpoint nothing changed on. WSL2 exposes neither cpufreq nor intel_pstate; frequency belongs to the Windows host. One run per variant is not a measurement.
  • The first inlining log had zero mentions of user code and looked like a clean negative. It was taken without -XX:+PrintCompilation, which is what names the compilation roots. With it, five refusals name user methods, all of them "hot method too big" — Pricing.quote at 1827 bytes against C2's FreqInlineSize of 325.

Verdict

The gate had two conditions: green if user code owns at least 25 % of allocations, or if R8 improves the service by less than 3 % — the second on the assumption that R8 sets the bar and a plugin has room above it. By that letter the result is green: R8 moved nothing. But the reason it moved nothing is not that R8 is weak; it is that there was nothing to move. The ceiling of a pass over user code is the share of the profile user code owns, and that share is 2.1 % of CPU and 9.9 % of allocations on the stand, 1–4 % and 3–5 % on konekt. Removing every user allocation would shift alloc/req by a tenth; the brief's own kill criterion — 5 % of throughput or 10 % of allocations with every pass on — is unreachable by construction. The ASM layer reaches the whole process, but what is large in the profile — the dispatcher queue, the I/O buffers, KClassImpl.toString — is not a peephole. The plugin was not built.

What survived: a method-size diagnostic (10 of 283 user methods over 325 bytes, three of them refused as hot) now lives as a lint task in the portfolio's build conventions, and the stand stays in zavarnik as the harness for its warm-up measurements.

Limitations

  • One machine, a mobile CPU in WSL2, with no way to fix the clock. Shares by owner are ratios inside one process and were stable across repeats; throughput figures are not.
  • Allocation bytes are sampled by async-profiler; alloc/req is comparable between variants, not an absolute.
  • One real service, one scenario. A service whose handlers do their own arithmetic would score higher; none of mine do.
  • R8 was tried at 9.4.17 and 9.5.10-dev on a Kotlin 2.4.10 / coroutines 1.11.0 classpath. I have not filed it upstream, and I could not establish whether it is already known: the R8 tracker on issuetracker.google.com is searchable only after sign-in, and the classfile backend is documented as secondary to DEX. The javap before/after and the reproducer are in bench/profile/ for anyone who wants to.

Source: github.com/youndie/zavarnikbench/ for the service and the harness, bench/profile/results/ for every profile cited, docs/research/research-optimizer.md for the fact tables with their addresses. The first phase of the same repository, the AOT cache, has its own post: OpenJDK 25.0.0–25.0.3 uses a stale AOT cache without saying so.