Collections Empty Map Defeats JIT Scalar Replacement for AbstractCompositeMeter

[belugabehr]

The CompositeCounter stores its 'children' in an IdentityHashMap. Consider using a different data structure, or if necessary, two data structures for this use case.

I am working on a high-performance application with many updates to the counters. From a recent Java Flight Recording, I noted that my application had generated 50GB on heap of Iterators from this class during a test run. Consider keeping an ArrayList of children (in addition to / instead of) a Map such that accessing the Collection of children becomes a heap-free operation.

micrometer/micrometer-core/src/main/java/io/micrometer/core/instrument/composite/CompositeCounter.java

Lines 31 to 33 in 2d9abb2

	for (Counter c : getChildren()) {
	c.increment(amount);
	}

[belugabehr]

Consider if this can just use an ArrayList under the covers instead as I imagine reads are a lot more frequent then writes and that the writes of new registries are relatively small, infrequent, and trivial.

[jonatan-ivanov]

Thank you for the issue!

Could you please tell us what you are doing? You just create a counter and increment it using a composite registry?
Could you please also show us (e.g.: in a draft PR) what you mean by the improvements you described above and that it improves performance (JMH tests)?

I only took a quick look at it but I don't think using a List instead of a Map would work since composite meters should know what registries their children in so that they can remove those (when CompositeMeterRegistry#remove calls AbstractCompositeMeter#remove(MeterRegistry)).

Also, I'm not sure how much using a List in addition to a Map would help since ArrayList.iterator does allocate a new iterator object on the heap, I'm not sure I understand what you mean by being it a "heap-free operation" but we will have extra references and extra CPU cycles because of maintaining an extra ArrayList.

[belugabehr]

Hello!

Thanks for the feedback.

To your point, I am trying to craft a JMH test and thus far have been unsuccessful in demonstrating the issue, so I am trying to figure out if my test is the issue or something about my product/environment.

Thanks!

[belugabehr]

Okay, I made some progress - analysis to follow when I have time, but basically, it's not a micrometer issue per se, it's a JVM optimization issue - it's being defeated in our application. I'll see if I can write up something more formally to share as an FYI to you.

[jonatan-ivanov]

Thank you for taking a look! Please share what you found.
In the meantime, let me close this issue but please feel free to comment on it if you want us to reopen it, you found something interesting, or just have a question.

[belugabehr]

@jonatan-ivanov

Okay! This is a wild story! I've been doing Java a long time and never came across this before.

There is an odd edge-case by which micrometer does not play well with the JVM Scalar Replacement optimization:

In Java, Escape Analysis (EA) is a compiler optimization technique used by the HotSpot JVM's JIT compiler to determine the scope of object references. It analyzes whether an object "escapes" the method or thread in which it is created. If an object is determined not to escape, the JVM can perform several optimizations, including Scalar Replacement and potentially Stack Allocation.

Scalar Replacement is a key optimization enabled by Escape Analysis. If an object is determined not to escape a method (meaning its reference is not passed out of the method or stored in a field accessible by other threads), the JIT compiler can decompose the object into its individual fields, effectively treating them as local variables.

What I was observing is that our application was putting a lot of IndentityHashMap iterators onto the heap when normally I would expect them to simply be allocated to the stack - how slow would Java be if it never did this trick and then introduced the enhance for-loop as the default pattern? I could not understand why this was happening.

Anyway, I was doing a lot of Google searches, and after many attempts, finally landed on the nugget of information that I needed:

(paraphrasing) The JIT compiler needs the target class implementation to never change in order for scalar replacement to work.

I found that in fact, AbstractCompositeMeter has two different Collections that it can use.

1. java.util.Collections.emptyMap()
2. java.util.IdentityHashMap

From my analysis of the JIT logs, I could see that both implementation had been encountered at one point or another in the execution of the application, and thus Scalar Replacement was not happening.

                    // Compilation logging
                    "-XX:+PrintCompilation",            // Show when methods compile
                    "-XX:+PrintInlining",               // Show inlining decisions
                    "-XX:+LogCompilation",              // Detailed compilation log

So I needed to figure out how that was getting into this state. Well, debugger gave it away: the emptyMap() code path was executed by adding a Counter to un otherwise uninitialized Metrics.globalRegistry. Right or wrong (still need to dive on that), that is what is happening. This code path just needs to execute once at any point in the lifecycle of the application and it will disable the Scalar Replacement, it does not matter if at some later point registries are added to the global registry.

In my testing, I temporarily addressed the issue by adding a SimpleMeterRegistry to the globalRegistry first thing in the application.

So, the ask here is simple: can you please update AbstractCompositeMeter to use a new IdentityHashMap(0) as the base case?

[belugabehr]

Here is the JMH code to demonstrate the issue:

# JMH version: 1.37
# VM version: JDK 17.0.16, OpenJDK 64-Bit Server VM, 17.0.16+8-Ubuntu-0ubuntu124.04.1

Note the use of the UseEpsilonGC - this is a specialized GC that is a no-op, so if there is a memory leak somewhere, it will just OOM.

import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.Metrics;
import io.micrometer.core.instrument.composite.CompositeMeterRegistry;
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.infra.Blackhole;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import java.util.concurrent.TimeUnit;

@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@State(Scope.Benchmark)
@Fork(1)
@Warmup(iterations = 2, time = 5, timeUnit = TimeUnit.SECONDS)
@Measurement(iterations = 2, time = 5, timeUnit = TimeUnit.SECONDS)
public class CompositeCounterBenchmark {

    public static final Counter COMPOSITE_COUNTER;
    public static final Counter COMPOSITE_EMPTY_COUNTER;

    static {
        // Create a counter - this will automatically create a CompositeCounter one registry
        COMPOSITE_COUNTER = new CompositeMeterRegistry().add(new SimpleMeterRegistry()).counter("test.counter");

        COMPOSITE_EMPTY_COUNTER = Metrics.globalRegistry.counter("test.counter.empty");
    }

    /** This runs fine - no issues */
    @Benchmark
    public void benchmarkCompositeCounterIncrement(Blackhole bh) {
        // Simple increment call with amount
        COMPOSITE_COUNTER.increment(1.0);

        bh.consume(COMPOSITE_COUNTER.count());
    }

    /** This will OOM as updating the empty counter will defeat Scalar Replacement */
    /** The Iterators will end up on the heap */
    @Benchmark
    public void benchmarkCompositeCounterIncrement_GlobalRegistry(Blackhole bh) {
       // Global registry
        COMPOSITE_EMPTY_COUNTER.increment(1.0);

        // Simple increment call with amount
        COMPOSITE_COUNTER.increment(1.0);

        bh.consume(COMPOSITE_COUNTER.count());
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(CompositeCounterBenchmark.class.getSimpleName())
                .jvmArgs("-Xms128M", "-Xmx128M", "-XX:+UnlockExperimentalVMOptions", "-XX:+UseEpsilonGC")
                .build();

        new Runner(opt).run();
    }
}

[belugabehr]

Could maybe be related to #6148

[shakuzen]

Thanks for all the investigation @belugabehr. I'll have to take a closer look after I get caught up on some other things.

It's somewhat beside the point, but do you need multiple registries in your application at all? You could avoid composite types altogether if you don't.

In my testing, I temporarily addressed the issue by adding a SimpleMeterRegistry to the globalRegistry first thing in the application.

Do you mean if a registry is added to the composite before any meters are registered the issue is avoided? I would say that is best practice regardless. Ideally, configuration such as adding registries (and configuring MeterFilters etc on each) should be done before meters are registered. Are you using the global registry and registering meters with the static methods, e.g. Metrics.counter?