Optimizing Nanosecond Operations: When the CPU Cache Matters with Andrey Minogin - JVM Weekly vol. 198

The piece is by Andrey Minogin, a software architect who has spent more than fifteen years finding out why data-heavy systems in production are slow, expensive or wrong. It first went out on his blog on 27 October and reached Foojay on 2 November, so it gets into the October roundup on a technicality. I am fine with that.

It is the first part of a series: resolve the classpaths of all 30,889 Apache projects on Maven Central at once, on a laptop, and make that faster one measured change at a time. Here he removes a check the profiler blamed for 29.2 seconds and gets 24.3 back. The rest of the cost moves to a line he never touched.

Thanks for reading JVM Weekly! Subscribe for free to receive new posts and support my work.

The code is Kotlin, but it reads like Java. The profiler, TickSnick, is his own, and he says so. His earlier post, "The flame graph was wrong by 57×", explains why he built it.

One thing to know before the diff: the CPU cache is a small, fast memory next to each core. When two lookups read the same memory one after the other, the first pays for the trip to main memory and the second gets the data cheap.

Optimizing nanosecond operations: when the CPU cache matters

first published on minogin.com and republished on Foojay by Andrey Minogin

A profiler tells you where the time goes. It's tempting to read that as a promise: remove the 29 seconds it points at, and you get 29 seconds back. This article is about a case where that promise didn't hold. The check we removed really was expensive, but part of its cost silently moved to a line of code we never touched.

The setting is a hot loop in which a single operation takes about 200 nanoseconds. At that scale the CPU cache stops being a detail and starts deciding what your code costs, and one operation can pay a bill that another one runs up.

Let's optimize a graph traversal together: step by step, measuring every step. We start with the simplest one.

The task

Maven Central gives us a large, natural graph to explore. As a sample task, let's resolve the classpaths of every Apache project at once: compile, runtime and test (the latest release only). The Goblin snapshot from April 2025 contains 16.2 million releases and 136 million edges - that will be our graph in memory, on a laptop. org.apache.* brings us 30,889 roots × 3 scopes.

Surprisingly, proper dependency resolution is an NP-complete problem on its own (Russ Cox, “Version SAT”). We’ll use Go’s much simpler rule, Minimal Version Selection: the highest requested version wins. The output is checked: every step of the optimization must print exactly the same.

The naive version

Resolving one classpath takes three walks. select collects everything reachable. reach walks again from the root, following only the highest versions and thus skipping branches reachable only by lower versions. via repeats reach from each direct dependency, to tell which one brings in each entry.

Implementation anyone begins with: releases as group:artifact:version strings, a graph as HashMap>, Breadth First Search with a HashSet of visited releases, roots split into parallel threads.

// For every release the walk visits: which of its dependencies to follow.
private fun passedOn(release: Release): List {
    val scopes = if (release == root) kind.rootScopes else kind.transitiveScopes
    // lookup 1: the release's dependencies
    return graph.dependencies.getValue(release)
        .filter {
            // compile, runtime or test
            it.scope in scopes &&
                    // not the root itself, at any version
                    it.artifact != rootArtifact &&
                    // lookup 2: does the target exist?
                    graph.existsOnCentral(it.artifact, it.version)
        }
}

There's a catch with Maven Central: it doesn't check that a release's dependencies exist. A POM can point at an artifact from another repository (androidx lives on Google's), a version range, a -SNAPSHOT. On our walks, 0.75% of the edges lead to a release that isn't in the graph, and without the check 13,155 of 30,889 compile classpaths fail. So every edge gets checked:

// Is "g:a:v" a release in the graph, i.e. published on Central?
fun existsOnCentral(artifact: Artifact, version: Version): Boolean =
    // builds "g:a:v", same 16 M map
    dependencies.containsKey(releaseOf(artifact, version))

The profile

To profile the code we will use TickSnick, my own profiler. Its main advantage is that it measures the operations you name, not the methods they happen to run through. You wrap each operation in op(...):

private fun passedOn(release: Release): List = op(PASSED_ON) {
    val scopes = if (release == root) kind.rootScopes else kind.transitiveScopes
    op(DEPENDENCIES) { graph.dependencies.getValue(release) }
        .filter {
            it.scope in scopes &&
                    it.artifact != rootArtifact &&
                    op(ON_CENTRAL) { graph.existsOnCentral(it.artifact, it.version) }
        }
}

The report gives every operation its time, its calls and so its time per call, even for one that takes 100 ns. And the labels stay the same as the code changes, so the profiles of two versions diff row by row. (Why I built it: The flame graph was wrong by 57×.)

Turbo off, 18 GB heap, three measured batches per run, four runs of each version, alternated. TickSnick's report, naive implementation, run 1 of 4 (columns and rows trimmed):

COARSE OPERATIONS - wall time, inclusive, nested as it ran
runBatch                      82.0 s
  resolveRoot                 82.0 s   100%
    resolve                   82.0 s   100%
      select                  42.5 s    52%
        - merge        own    14.6 s    34%
        - onCentral    own    12.2 s    29%   29.2 s in all, under 4 operations
      via                     28.1 s    34%
        - onCentral    own    11.8 s    42%
      reach                   10.1 s    12%
        - onCentral    own    5.21 s    52%

COARSE AND FINE OPERATIONS - own time
Operation      Thread-time%  Thread-time        Calls   Thread-time per call
onCentral             28.1%        117 s  569,233,860   205 ns
merge                 14.1%       58.4 s  199,138,728   293 ns

The top row in the biggest walk is merge, 14.6 s. But onCentral, the Central check, is in all three walks: 29.2 s in all, 569 million calls at 205 ns. And its answer never changes: whether g:a:v exists depends only on the edge, not on the walk.

This immediately suggests an optimization: do the Central check just once.

centralEdges

centralEdges drops every edge to a release that doesn't exist - 4.2% of all edges in the graph - once, before any walk. The walks keep the scope and root checks only:

override fun prepare(graph: Graph): Graph {
    val dependencies = HashMap>(graph.dependencies.size * 4 / 3 + 1)
    for ((release, list) in graph.dependencies)
        dependencies[release] = list.filter { graph.existsOnCentral(it.artifact, it.version) }
    return Graph(dependencies)
}

The profile says the check took 29.2 s, so that's what we expect to save. Let's run it.

The diff

Let's look at TickSnick's diff of all four runs of each:

Diff          naive (4 runs) -> centralEdges (4 runs)
...
runBatch        82.4 s -> 58.1 s     -29%   +-1.3%  faster

Success: 82 s -> 58 s!

Three batches went from 82.4 s to 58.1 s: 24.3 s saved. Confirmed by four runs: TickSnick reports the 95% confidence interval, ±1.3%.

But the profile said the check took 29.2 s. Where are the other 4.9?

How do we find out? The same diff answers that too: it matches every operation by name across the two versions and shows what happened to each one.

Operation      Thread-time        change                  Per call            Calls
onCentral      118 s -> -                                 207 ns -> -         569,233,860 -> -
dependencies   23.2 s -> 43.1 s   +86%  +-5.5%  slower    104 ns -> 194 ns    222,178,167 =
passedOn       23.4 s -> 25.7 s   +9.9% +-6.8%  slower    105 ns -> 116 ns    222,178,167 =
merge          59.0 s -> 59.7 s   +1.1% +-3.2%  unclear   296 ns -> 300 ns    199,138,728 =
visit          58.5 s -> 59.1 s   +0.9% +-3.1%  unclear   104 ns -> 105 ns    562,928,865 =

Aha, here it is: dependencies got 86% slower. That's the label on lookup 1 in passedOn, graph.dependencies.getValue(release) - fetching the release's dependency list from the same 16 M map. A line we didn't touch. The same 222 million calls - each one just takes longer. Why would an untouched lookup get slower?

This is actually super interesting. Again, we didn't touch that line, but it got much slower - as if it had taken over part of onCentral's cost. When does that happen? When one part was helping another. But how? By caching!

The onCentral check we removed looked up g:a:v in the same 16-million-entry map, for the release the walk fetches next. It paid the trip to main memory, and the walk's lookup found the entry in cache. Without the check, the lookup now goes to main memory.

Can we prove this guess? If it's right, putting just the check back should make the lookup fast again. So: centralEdgesRecheck, the pruned graph with the check put back - it always passes now, so all it does is touch the memory. Three runs of each, a separate set:

Operation      Thread-time        change                  Per call            Calls
onCentral      - -> 111 s                                 - -> 196 ns         - -> 564,888,102
dependencies   41.1 s -> 22.2 s   -46%  +-3.2%  faster    185 ns -> 99.9 ns   222,178,167 =

Yes: 185 ns back to 99.9 ns, about where it was in naive.

Conclusions

What the profile told us: where the time went. 29.2 s in a check whose answer never changes. We moved it out of the walk and gained 24.3 s.

What it couldn't tell us: what the optimization would save. Part of the check's cost was a trip to memory, and that trip didn't go away - the next line that needed the same entry paid for it.

So after every step, look at what got more expensive, not only at what got cheaper. Same calls, slower each - that's a line paying someone else's bill.

Next: merge now leads, and the lookup at 194 ns points at the memory layout itself. It only gets more interesting from here. Stay tuned.

And now... Rest of the highlights of the month at Foojay!

Foojay Podcast #103: Killing Reflection at Build Time with Dmitry Moskalyuk and Shai Almog

Frank Delporte talks to two guests who moved reflection to build time, from opposite ends of the JVM world. Dmitry Moskalyuk has a backend model layer that reads JSON, XML, YAML and TOML and writes Avro. Shai Almog works on Codename One, a cross-platform UI framework, where the goal is "no reflection, no service loader, no Class.forName". They also get to generated code (Lombok, Manifold, jOOQ), what Records and Project Leyden change, and whether a new project should still reach for reflection.

Upgrading from Java 21 to 25: What Actually Breaks

Gerard Marimon Caparrós, who builds NextPatch, ran every example on both JDKs and sorted the breakages by how loudly they fail. The quiet ones are the reason to read it. Since JDK 23, javac no longer runs annotation processors it merely finds on the class path, and on JDK 25 the same build prints nothing and exits with status 0. Lombok tells you at once with "cannot find symbol". A processor that writes optional metadata may not tell you until runtime. The fix is annotationProcessorPaths or full.

What jstack Misses When Your Java Service Uses Virtual Threads

Felipe Maschio, founder of ThreadMine and here in vol. 195 with thread dump masking, starts from a service with about 5,000 requests in flight. jstack shows 43 platform threads and almost no CPU use, so the service looks idle. On JDK 21 through 25 the traditional dump does not list virtual threads, and the waiting requests are simply not in the file. Use jcmd Thread.dump_to_file instead. His summary: "Virtual threads make waiting cheaper. The database still has to do the work."

The Maven Build Cache in Practice

Maarten Mulders and Kasper van de Wetering from Info Support turned on the Maven Build Cache extension in Azure DevOps. The extension hashes the inputs of each module and restores its outputs when nothing changed. Most of the article is about what broke next: JaCoCo reports, sonar:sonar and the reactor. Pull request builds went from about 18 minutes to about 9. The deployment pipeline stays without the cache, because a deployed artifact should come from a clean build.

JVM on Unikernel Nanos: GC trade-offs and heap uncommit

Angelo Rubini ran an unmodified Temurin 25 on Nanos, a unikernel (your application plus only the parts of an operating system it needs, in one image on the hypervisor). All five collectors work, and Parallel against G1 came out close to what Akamas measured on Linux. The part that applies to any JVM is uncommit. ZGC and Shenandoah released memory once -Xms was below -Xmx. Set them equal and uncommit is off, and the ZGC log says so: "Implicitly Disabled (-Xms equals -Xmx)".

And that's all, folks.

PS: From the JVM Weekly in Strange Places series: Junk & Java in Westerly, Rhode Island, a stop on the road from Boston to New York.

Thanks for reading JVM Weekly!

Thanks for reading JVM Weekly! Subscribe for free to receive new posts and support my work.