Difficulty profiling a Java application: Missing method in profiling results despite disabling optimizations. YourKit trivial method

Question

Not so far ago I had been profiling an application and noticed an interesting optimization that applies to the compiled byte code.

Here is my program:

public class InstanceOnly {

    public static void main(final String[] args) throws InterruptedException {
        int sum = 0;
        for (int i = 0; i < Integer.MAX_VALUE; ++i) {
            Book b = new Discounted(new Prime(i));
            sum += b.price();
            Thread.sleep(10);
        }
        System.out.printf("Total: %d\n", sum);
    }

    interface Book {
        int price();
    }

    static class Discounted implements Book {
        private final Book book;

        Discounted(final Book b) {
            this.book = b;
        }

        @Override
        public int price() {
            return this.book.price() / 2;
        }
    }

    static class Prime implements Book {
        private final int usd;

        Prime(final int u) {
            this.usd = u;
        }

        @Override
        public int price() {
            return this.usd * 3;
        }
    }
}

As you might notice it is rather simple - we just use decorator pattern here in order to calculate the total price of all books. The application will run very long time, so I have enough time to profile it. I’m using YourKit java profiling which use bytecode instrumentation in order to get precise number of invocations of the each method. I profile the application during one minute and get the next results:

"verification.instances.InstanceOnly.main(String[]) InstanceOnly.java","1"
"java.lang.Thread.sleep(long) Thread.java (native)", "5307"
"verification.instances.InstanceOnly$Prime.<init>(int) InstanceOnly.java", "5307"
"verification.instances.InstanceOnly$Discounted.price() InstanceOnly.java","5307"
"verification.instances.InstanceOnly$Discounted.<init>(InstanceOnly$Book) InstanceOnly.java","5307"

But where is the verification.instances.InstanceOnly$Prime.price() call? I can see that we only invoke the Prime constructor. I initially suspected that it might be a problem with JIT optimizations, where the method gets inlined. To address this, I disabled all optimizations by using the -Djava.compiler=NONE Java parameter. However, even with this configuration, the targeted method is still missing from the profiling results

I also attempted to add a dummy statement like System.out.println:

@Override
public int price() {
   System.out.println("Dummy println");
   return this.usd * 3;
}

And only in this case did I finally observe the desired method:

InstanceOnly$Prime.price() 

So, I'm completely confused because I can't understand who is actually performing the optimization and how I can disable it to see the InstanceOnly$Prime.price() in the profiling results without adding dummy statements. Does anyone know what this could be?

Answer 1

Firstly, I would like to express my gratitude to Holger and boneill for their help in pinpointing the original problem and in identifying the root cause of the issue.

The actual problem lies not with the JIT compiler or build optimizations. Holger's comment provides a clear and concise explanation of it:

This is not how a JIT compiler works. After the profiler injected the code, it is part of the method and inlining the method implies retaining the behaviour of the entire code, including the injected code.

So, the issue clearly lies with the YourKit profiler, which incorporates a concept of "trivial methods". These methods are intentionally ignored during profiling in CPU tracing mode as a means to reduce profiling overhead:

CPU profiling: the range of trivial methods like getters and setters excluded from CPU tracing instrumentation for performance consideration has been extended. Now it includes methods whose bytecode satisfies the following conditions:

• does not exceed 32 bytes;
• does not contain cycles;
• contains only these instructions: load, store and other stack operations, field access, bit and arithmetic operations, comparison operations, return. In particular, this means that these methods cannot call other methods nor create objects.

You can find more information about this in the YourKit profiler documentation.

If we closely examine the generated bytecode of our method, we will come across the following statements:

  public price()I
   L0
    LINENUMBER 44 L0
    ALOAD 0
    GETFIELD verification/instances/InstanceOnly$Prime.usd : I
    ICONST_3
    IMUL
    IRETURN
   L1
    LOCALVARIABLE this Lverification/instances/InstanceOnly$Prime; L0 L1 0
    MAXSTACK = 2
    MAXLOCALS = 1

Which perfectly aligns with the characteristics of a "trivial method". As a result, the price() method was not instrumented during profiling. To disable this behavior, you can utilize the _instrument_all_methods option in YourKit profiling. From the official docs:

Note: to force instrumentation of these methods specify startup option _instrument_all_methods

In my case, I am using the CLI API to initiate profiling. Therefore, I am employing the following command to specify the desired startup option:

java -agentpath:$PROFILER_AGENT_PATH=_instrument_all_methods -jar $APPLICATION_JAR

You can find further information on specifying YourKit startup options here.