<div dir="ltr"><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">The counter's value in "Preloading" and "Missing" messages is taking from current MDO [1] and not from the entry<br>describing AOT code.<br></blockquote><div><br></div><div>That's right. </div><div><br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><br>I remember (Igor may confirm it) that CompilerCounters data is nulled for TD including _nof_decompiles value. That is<br>why we see 0 when loading code.<br clear="all"></blockquote><div><br></div><div>For "Missing" message, the counter is obtained from Method->method_data() which would return null if the MethodData<br></div><div>recorded in the training data is not yet installed in the Method. If Method->method_data() is null, then it prints 0 as the counter value.</div><div>This is the case I am seeing if I print the method data in the "Missing" message:</div><div><br></div><div><font face="monospace">[0.878s][info ][scc,nmethod ] Missing entry for 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z' (md: (nil), comp_level 4, decomp: 0, hash: 0x493f24e2)</font><br></div><div><font face="monospace"><br></font></div><div><font face="arial, sans-serif">Notice that md is null.</font></div><div><br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"> With one step workflow we should ignore decomp count because code is generated not<br> during execution but based on training data in forked VM - no deoptimization happens there.<br></blockquote><div><br></div><div>hmm, I see some entries marked as "made not entrant" in the output of PrintCompilation during the assembly phase of 1-step workflow.</div><div><br></div><div><font face="monospace"> S131 432 % 2 jdk.internal.util.ArraysSupport::unsignedHashCode @ 8 (36 bytes) made not entrant<br></font></div><div><font face="monospace"> S133 433 2 jdk.internal.util.ArraysSupport::unsignedHashCode (36 bytes) made not entrant<br></font></div><div><font face="monospace"> S158 506 2 java.util.HashMap::putVal (300 bytes) made not entrant</font><br></div><div><br></div><div>Thanks,<br></div><div><div dir="ltr" class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr">- Ashutosh Mehra</div></div></div><br></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Thu, Jul 25, 2024 at 8:18 PM Vladimir Kozlov <<a href="mailto:vladimir.kozlov@oracle.com" target="_blank">vladimir.kozlov@oracle.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">I looked on code and for "Preloading" nmethod we ignore decompile counter. We check it only when looking for "normal" <br>
AOT code.<br>
<br>
The counter's value in "Preloading" and "Missing" messages is taking from current MDO [1] and not from the entry <br>
describing AOT code.<br>
<br>
I remember (Igor may confirm it) that CompilerCounters data is nulled for TD including _nof_decompiles value. That is <br>
why we see 0 when loading code.<br>
<br>
It seems we are "lucky" in most cases because we deoptimize (and update counter) may be level 2 (C1) AOT code or <br>
"Preloaded" code. That is what I see in my runs which has opposite issue: we record AOT code with `decomp == 0` and when <br>
we load it "preload" AOT code was deoptimized and counter updated in MDO and check failed when we tried to load "normal" <br>
AOT code.<br>
<br>
Anyway. As I said, for one-step workflow we should not use decompile counter. I may actually save only latest version of <br>
"normal" nmethod even for 5-step workflow. The question is which nmethod version corresponds to saved MDO? For on-step <br>
workflow the answer is simple and we can ignore the counter. For 5 steps I need to check corresponding MDO to save <br>
correct version.<br>
<br>
Thanks,<br>
Vladimir K<br>
<br>
[1] <a href="https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp#L2868" rel="noreferrer" target="_blank">https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp#L2868</a><br>
[2] <a href="https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp#L317" rel="noreferrer" target="_blank">https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp#L317</a><br>
<br>
On 7/24/24 3:46 PM, Ashutosh Mehra wrote:<br>
> Hi Vladimir,<br>
> <br>
> Is this with one step workflow? With one step workflow we should ignore decomp count because code is generated not<br>
> during execution but based on training data in forked VM - no deoptimization happens there.<br>
> <br>
> <br>
> Yes, this is with the 1-step workflow.<br>
> <br>
> - Ashutosh Mehra<br>
> <br>
> <br>
> On Wed, Jul 24, 2024 at 3:56 PM Vladimir Kozlov <<a href="mailto:vladimir.kozlov@oracle.com" target="_blank">vladimir.kozlov@oracle.com</a> <mailto:<a href="mailto:vladimir.kozlov@oracle.com" target="_blank">vladimir.kozlov@oracle.com</a>>> wrote:<br>
> <br>
> Thank you for report, Ashutosh<br>
> <br>
> Is this with one step workflow? With one step workflow we should ignore decomp count because code is generated not<br>
> during execution but based on training data in forked VM - no deoptimization happens there.<br>
> <br>
> `decomp count` was introduced for 5 steps workflow when we generate aot code as we execute application with idea that<br>
> production run will follow the same compilation/deoptimization steps.<br>
> <br>
> Actually I implemented it before we start using TD to trigger compilation. May be this is the reason that 5 steps<br>
> workflow is slow now when we use TD. I need to check.<br>
> <br>
> Thanks,<br>
> Vladimir K<br>
> <br>
> On 7/24/24 7:54 AM, Ashutosh Mehra wrote:<br>
> > During the startup of a quarkus app, I see a particular method that gets C2 compiled almost every time in the<br>
> production<br>
> > run with the premain branch . I don't see this happening with the mainline.<br>
> > The reason this method caught my attention is the significant amount of memory its C2 compilation consumes (between<br>
> > 25-40 mb) compared to the other compilations.<br>
> > The method in question is<br>
> > jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z<br>
> ><br>
> > The assembly phase added two entries for this method in the code cache:<br>
> ><br>
> > [3.391s][info ][scc,nmethod ] 2631 (L4): Writing nmethod<br>
> > 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z'<br>
> (comp<br>
> > level: 4, decomp: 1, has clinit barriers) to Startup Code Cache 'quarkus-getting-started.cds.code'<br>
> > ...<br>
> > [7.215s][info ][scc,nmethod ] 4354 (L4): Writing nmethod<br>
> > 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z'<br>
> (comp<br>
> > level: 4, decomp: 1) to Startup Code Cache 'quarkus-getting-started.cds.code'<br>
> ><br>
> > In the production run the "preload" version was successfully loaded:<br>
> ><br>
> > [0.695s][info ][scc,nmethod ] 727 (L4): Preloading nmethod<br>
> > 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z'<br>
> (decomp:<br>
> > 0, hash: 0x493f24e2, has clinit barriers)<br>
> ><br>
> > The PrintTieredEventslogs indicate this method was also sent for compilation during replay training:<br>
> ><br>
> > 0.877593: [force-compile level=4<br>
> > [jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z] @-1<br>
> > queues=0,0 rate=0.000000 load=0.007812 k=1.00,1.00 total=56,0 mdo=0(0),0(0) max levels=4,0<br>
> > compilable=c1,c1-osr,c2,c2-osr status=idle mtd: mdo=18830(8306), 0(0), deps=0]<br>
> ><br>
> > Ideally this request should have been fulfilled by the second entry in the code cache. But instead I see this<br>
> message:<br>
> ><br>
> > [0.878s][info ][scc,nmethod] Missing entry for<br>
> > 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z'<br>
> > (comp_level 4, decomp: 0, hash: 0x493f24e2)<br>
> ><br>
> > This is followed by the C2 compilation of the method.<br>
> ><br>
> > It looks like the failure to find the second entry is due to a mismatch of the decomp count [0]. The decomp count is<br>
> > stored in the MethodData.<br>
> > Is it possible that the method data is not yet installed when replay training is done? If so, is that by design<br>
> or a bug?<br>
> ><br>
> > [0]<br>
> ><br>
> <a href="https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp#L938" rel="noreferrer" target="_blank">https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp#L938</a> <<a href="https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp*L938__;Iw!!ACWV5N9M2RV99hQ!MGy9Dev-630RGry8or7lUEBQ4OYoS8cYwif2Z56RKLsqk7kx5YSD65AzSK9yYycpOWGubLGwFIZSImuh3ykRKw$" rel="noreferrer" target="_blank">https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp*L938__;Iw!!ACWV5N9M2RV99hQ!MGy9Dev-630RGry8or7lUEBQ4OYoS8cYwif2Z56RKLsqk7kx5YSD65AzSK9yYycpOWGubLGwFIZSImuh3ykRKw$</a>><br>
> ><br>
> <<a href="https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp#L938" rel="noreferrer" target="_blank">https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp#L938</a> <<a href="https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp*L938__;Iw!!ACWV5N9M2RV99hQ!MGy9Dev-630RGry8or7lUEBQ4OYoS8cYwif2Z56RKLsqk7kx5YSD65AzSK9yYycpOWGubLGwFIZSImuh3ykRKw$" rel="noreferrer" target="_blank">https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp*L938__;Iw!!ACWV5N9M2RV99hQ!MGy9Dev-630RGry8or7lUEBQ4OYoS8cYwif2Z56RKLsqk7kx5YSD65AzSK9yYycpOWGubLGwFIZSImuh3ykRKw$</a>>><br>
> ><br>
> > Thanks,<br>
> > - Ashutosh Mehra<br>
> <br>
<br>
</blockquote></div>