Does anyone know what exactly the JIT log "already compiled into a big method" mean?

[rick.ow...@gmail.com]

I am going through the JIT HotSpot compiler logs (-XX:+PrintCompilation -XX:+UnlockDiagnosticVMOptions -XX:+PrintInlining) to make sure an important method is being optimized/compiled. The method shows:

"already compiled into a big method"

What does that mean? Is my method being correctly optimized/inlined by JIT?

[Vitaly Davidovich]

https://wikis.oracle.com/display/HotSpotInternals/Server+Compiler+Inlining+Messages

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-symp...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[rick.ow...@gmail.com]

Thanks, Vitaly. I had already seen that, but unfortunately it did not take me to any conclusion. What does that mean? Does it mean my code was optimized/inlined or the HotSpot is now skipping it because it is compiled somewhere else?

"already compiled into a big method: there is already compiled code for the method that is called from the call site and the code that was generated for is larger than InlineSmallCode"

On Monday, July 6, 2015 at 2:01:43 PM UTC-4, Vitaly Davidovich wrote:

https://wikis.oracle.com/display/HotSpotInternals/Server+Compiler+Inlining+Messages

On Mon, Jul 6, 2015 at 1:57 PM, <rick.ow...@gmail.com> wrote:

I am going through the JIT HotSpot compiler logs (-XX:+PrintCompilation -XX:+UnlockDiagnosticVMOptions -XX:+PrintInlining) to make sure an important method is being optimized/compiled. The method shows:

"already compiled into a big method"

What does that mean? Is my method being correctly optimized/inlined by JIT?

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-sympathy+unsub...@googlegroups.com.

[Vitaly Davidovich]

You have a case like this:

methodBeingCompiled():

   foo();

It's saying that while compiling methodBeingCompiled() it did not inline foo() because there was already native code compiled for foo() (i.e. it's a hot method in multiple places) and the size of the generated native code is larger than InlineSmallCode tunable.  So no, foo() was not inlined.  Is the method in question actually large or does it have slow/uncommon and fast/common paths intermingled?

https://wikis.oracle.com/display/HotSpotInternals/Server+Compiler+Inlining+Messages

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-symp...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-symp...@googlegroups.com.

[rick.ow...@gmail.com]

Hi Vitaly,

It does not look like the the JIT log tells you *from where* foo() is being called, in other words, which method got too big and because of that did not inline foo().

I guess I can just do "Open Call Hierarchy" on my IDE to find all callers of foo(). Still, if it is called from many places, it will be hard to determine that, no?

So one approach would be to make the method that calls foo smaller, so it can inline foo, correct?

Here is what I see when I grep for foo(), in my case, mainLoop(). I am using JDK7.

$ grep mainLoop server_7.txt 

    211   31             com.tradex.platform::mainLoop (254 bytes)

                            @ 365   com.tradex.platform::mainLoop (254 bytes)   already compiled into a big method

                            @ 365   com.tradex.platform::mainLoop (254 bytes)   already compiled into a big method

   9191   31             com.tradex.platform::mainLoop (254 bytes)   made not entrant

   9194   48             com.tradex.platform::mainLoop (254 bytes)

   9229   48             com.tradex.platform::mainLoop (254 bytes)   made not entrant

                            @ 365   com.tradex.platform::mainLoop (254 bytes)   inline (hot)

   9279   82             com.tradex.platform::mainLoop (254 bytes)

                            @ 365   com.tradex.platform::mainLoop (254 bytes)   already compiled into a big method

 105475   82             com.tradex.platform::mainLoop (254 bytes)   made not entrant

 105475  329 %           com.tradex.platform::mainLoop @ 6 (254 bytes)

 105491  330             com.tradex.platform::mainLoop (254 bytes)

                            @ 365   com.tradex.platform::mainLoop (254 bytes)   already compiled into a big method

On Monday, July 6, 2015 at 2:23:57 PM UTC-4, Vitaly Davidovich wrote:

You have a case like this:

methodBeingCompiled():

   foo();

It's saying that while compiling methodBeingCompiled() it did not inline foo() because there was already native code compiled for foo() (i.e. it's a hot method in multiple places) and the size of the generated native code is larger than InlineSmallCode tunable.  So no, foo() was not inlined.  Is the method in question actually large or does it have slow/uncommon and fast/common paths intermingled?

On Mon, Jul 6, 2015 at 2:13 PM, <rick.ow...@gmail.com> wrote:

Thanks, Vitaly. I had already seen that, but unfortunately it did not take me to any conclusion. What does that mean? Does it mean my code was optimized/inlined or the HotSpot is now skipping it because it is compiled somewhere else?

"already compiled into a big method: there is already compiled code for the method that is called from the call site and the code that was generated for is larger than InlineSmallCode"

On Monday, July 6, 2015 at 2:01:43 PM UTC-4, Vitaly Davidovich wrote:

https://wikis.oracle.com/display/HotSpotInternals/Server+Compiler+Inlining+Messages

On Mon, Jul 6, 2015 at 1:57 PM, <rick.ow...@gmail.com> wrote:

I am going through the JIT HotSpot compiler logs (-XX:+PrintCompilation -XX:+UnlockDiagnosticVMOptions -XX:+PrintInlining) to make sure an important method is being optimized/compiled. The method shows:

"already compiled into a big method"

What does that mean? Is my method being correctly optimized/inlined by JIT?

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-sympathy+unsub...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-sympathy+unsub...@googlegroups.com.

[Vitaly Davidovich]

You should add -XX:UnlockDiagnosticVMOptions -XX:+PrintInlining which will also show you the call chain being inlined (or not).

The issue here isn't the caller of mainLoop being too big, but rather mainLoop already having compiled code that's too big to inline into one of its callers.  This is basically trying to prevent large native code from being replicated in many places and increasing code cache footprint.  mainLoop itself is 254 bytes of bytecode, which is well under the default limit for hot methods (325 on x64); this is why you see it inlined in some places (the "inline (hot)" lines).  It also looks like there's an OSR compilation inside this method, which makes sense given the name of this method.

So, add inlining diagnostic and see which callsite fails to inline it.  It also sounds like this method is non trivial, and so perhaps there may not be much to gain by inlining (depends on what further optos could be done though from the callsite).

sent from my phone

https://wikis.oracle.com/display/HotSpotInternals/Server+Compiler+Inlining+Messages

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-symp...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-symp...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "mechanical-sympathy" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mechanical-symp...@googlegroups.com.

[Chris Newland]

Hi Rick,

The logic for this inlining decision is in <OpenJDK>/hotspot/src/share/vm/opto/bytecodeInfo.cpp:

  if (callee_method->has_compiled_code() &&
      callee_method->instructions_size() > InlineSmallCode) {
    set_msg("already compiled into a big method");
    return true;
  }

As Vitaly said, it's to prevent the same method from being compiled in too many places (potentially filling up the compiled code cache).

Looking in <OpenJDK>/hotspot/src/share/vm/ci/ciMethod.cpp:

// ------------------------------------------------------------------
// ciMethod::instructions_size
//
// This is a rough metric for "fat" methods, compared before inlining
// with InlineSmallCode.  The CodeBlob::code_size accessor includes
// junk like exception handler, stubs, and constant table, which are
// not highly relevant to an inlined method.  So we use the more
// specific accessor nmethod::insts_size.
int ciMethod::instructions_size() {
  if (_instructions_size == -1) {
    GUARDED_VM_ENTRY(
                     nmethod* code = get_Method()->code();
                     if (code != NULL && (code->comp_level() == CompLevel_full_optimization)) {
                       _instructions_size = code->insts_end() - code->verified_entry_point();
                     } else {
                       _instructions_size = 0;
                     }
                     );
  }
  return _instructions_size;
}

The InlineSmallCode limit for x86 is set at 1000 bytes in hotspot/src/cpu/x86/vm/globals_x86.hpp:

define_pd_global(intx, InlineSmallCode,          1000);

But can be increased to 2000 bytes (x86) in hotspot/src/share/vm/runtime/advancedThresholdPolicy.cpp:

void AdvancedThresholdPolicy::initialize() {
/* snip */

  // Some inlining tuning
#ifdef X86
  if (FLAG_IS_DEFAULT(InlineSmallCode)) {
    FLAG_SET_DEFAULT(InlineSmallCode, 2000);
  }
#endif

If you run java -XX:+UnlockDiagnosticVMOptions -XX:+PrintFlagsFinal | grep -i InlineSmallCode

it looks like the AdvancedThresholdPolicy is executed by default to give a limit of 2000 bytes:

intx InlineSmallCode            = 2000          {pd product}

If you think HotSpot is making the wrong inlining decisions for your program then it's probably better to try and reorganise your code than to increase this parameter because of possible program-wide side-effects. (Try both approaches and measure?).

<sales pitch>
If you're interested in the JIT decisions made by HotSpot then you might like to take a look at JITWatch (https://github.com/AdoptOpenJDK/jitwatch) which is a tool to visualise the JIT logs and (hopefully) make them more understandable.
It's free and open source (Disclaimer - I'm the author).
</sales pitch>

I think the ability to locate existing compile sites when you get an "already compiled into a <big|medium> method" message would be a great feature so I'll add an issue for it.

Cheers,

Chris
@chriswhocodes

[Vitaly Davidovich]

Minor note, but the default 2000 value set by AdvancedThresholdPolicy is only if tiered compilation is enabled; it's 1000 otherwise.  Rick's on java 7, so will be getting 1000 by default.