<div dir="ltr">Yes, this seems to work. I don't see the "Missing entry" message for StackMapGenerator::processBlock any more,<div>and it is now able to locate the c2 compiled version in the code cache and use it.</div><div><br></div><div><font face="monospace">[0.911s][info ][scc,nmethod ] 2662 (L4): Reading nmethod 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z' (md: 0x7f99f00c5f68, decomp: 0, hash: 0x493f24e2)</font><br></div><div><font face="monospace"><br></font></div><div>Thanks,<br clear="all"><div><div dir="ltr" class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr">- Ashutosh Mehra</div></div></div><br></div></div><br><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Fri, Jul 26, 2024 at 12:28 PM Vladimir Kozlov <<a href="mailto:vladimir.kozlov@oracle.com">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">Ashutosh, please try this patch:<br>
<br>
diff --git a/src/hotspot/share/code/SCCache.cpp b/src/hotspot/share/code/SCCache.cpp<br>
index 551f80e1411..87f2d718320 100644<br>
--- a/src/hotspot/share/code/SCCache.cpp<br>
+++ b/src/hotspot/share/code/SCCache.cpp<br>
@@ -934,8 +934,7 @@ static bool check_entry(SCCEntry::Kind kind, uint id, uint comp_level, uint deco<br>
if (entry->kind() == kind) {<br>
assert(entry->id() == id, "sanity");<br>
if (kind != SCCEntry::Code || (!entry->not_entrant() && !entry->has_clinit_barriers() &&<br>
- entry->comp_level() == comp_level &&<br>
- (comp_level == CompLevel_limited_profile || entry->decompile() == decomp))) {<br>
+ (entry->comp_level() == comp_level))) {<br>
return true; // Found<br>
}<br>
}<br>
<br>
<br>
Thanks,<br>
Vladimir K<br>
<br>
On 7/26/24 8:17 AM, Ashutosh Mehra wrote:<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>
> <br>
> That's right.<br>
> <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>
> <br>
> For "Missing" message, the counter is obtained from Method->method_data() which would return null if the MethodData<br>
> recorded in the training data is not yet installed in the Method. If Method->method_data() is null, then it prints 0 as <br>
> the counter value.<br>
> This is the case I am seeing if I print the method data in the "Missing" message:<br>
> <br>
> [0.878s][info ][scc,nmethod ] Missing entry for <br>
> 'jdk.internal.classfile.impl.StackMapGenerator::processBlock(Ljdk/internal/classfile/impl/RawBytecodeHelper;)Z' (md: <br>
> (nil), comp_level 4, decomp: 0, hash: 0x493f24e2)<br>
> <br>
> Notice that md is null.<br>
> <br>
> 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>
> hmm, I see some entries marked as "made not entrant" in the output of PrintCompilation during the assembly phase of <br>
> 1-step workflow.<br>
> <br>
> S131 432 % 2 jdk.internal.util.ArraysSupport::unsignedHashCode @ 8 (36 bytes) made not entrant<br>
> S133 433 2 jdk.internal.util.ArraysSupport::unsignedHashCode (36 bytes) made not entrant<br>
> S158 506 2 java.util.HashMap::putVal (300 bytes) made not entrant<br>
> <br>
> Thanks,<br>
> - Ashutosh Mehra<br>
> <br>
> <br>
> 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> <mailto:<a href="mailto:vladimir.kozlov@oracle.com" target="_blank">vladimir.kozlov@oracle.com</a>>> wrote:<br>
> <br>
> 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<br>
> when<br>
> we load it "preload" AOT code was deoptimized and counter updated in MDO and check failed when we tried to load<br>
> "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<br>
> 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>
> <<a href="https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp*L2868__;Iw!!ACWV5N9M2RV99hQ!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYcRh3ntYA$" rel="noreferrer" target="_blank">https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp*L2868__;Iw!!ACWV5N9M2RV99hQ!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYcRh3ntYA$</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>
> <<a href="https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp*L317__;Iw!!ACWV5N9M2RV99hQ!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYe9CuvRDQ$" rel="noreferrer" target="_blank">https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/premain/src/hotspot/share/code/SCCache.cpp*L317__;Iw!!ACWV5N9M2RV99hQ!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYe9CuvRDQ$</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<br>
> 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>><br>
> <mailto:<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<br>
> 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<br>
> 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<br>
> (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>
> > ><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>
> > ><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>
> > ><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>
> > ><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>
> > ><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<br>
> 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<br>
> design<br>
> > or a bug?<br>
> > ><br>
> > > [0]<br>
> > ><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!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYcE3EES5w$" rel="noreferrer" target="_blank">https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp*L938__;Iw!!ACWV5N9M2RV99hQ!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYcE3EES5w$</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> <<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>
> > <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!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYcE3EES5w$" rel="noreferrer" target="_blank">https://urldefense.com/v3/__https://github.com/openjdk/leyden/blob/ec5eb99653624d02a923a314ce40086753b240fc/src/hotspot/share/code/SCCache.cpp*L938__;Iw!!ACWV5N9M2RV99hQ!MUQ7NwYRlq4ggiM1yNmZO3xJb1OV-cpfGFcPgPZ9zA7vbDKlPtPvsVtsm-gca03z_WTzgi8AUzOWOYcE3EES5w$</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> <<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>
<br>
</blockquote></div>