alexei-osipov
commented
2 years ago In class CompileChainStage on line
title += rootMemberName + " " + root.getCompilation().getSignature(); variable root is null.
Closed alexei-osipov closed 2 years ago
alexei-osipov
commented
2 years ago In class CompileChainStage on line
title += rootMemberName + " " + root.getCompilation().getSignature(); variable root is null.
chriswhocodes
commented
2 years ago Hi @alexei-osipov , Thanks for reporting. I'll investigate why this is happening and put in a fix. Kind regards, Chris
alexei-osipov
commented
2 years ago I've noticed that there a lot of errors in the parser log:
Could not parse line 3798 : java.lang.invoke.LambdaForm$MH.0x0000000800060440 invoke (Ljava.lang.Object;)Ljava.lang.Object; : MetaMember not found for java.lang.invoke.LambdaForm$MH.0x0000000800060440 invoke (Ljava.lang.Object;)Ljava.lang.Object;
Could not parse line 3807 : java.lang.invoke.LambdaForm$MH.0x0000000800060440 invoke (Ljava.lang.Object;)Ljava.lang.Object; : MetaMember not found for java.lang.invoke.LambdaForm$MH.0x0000000800060440 invoke (Ljava.lang.Object;)Ljava.lang.Object;
Could not parse line 4661 : java.util.stream.StreamSpliterators$WrappingSpliterator$$Lambda$179.0x000000080023a040 getAsBoolean ()Z : MetaMember not found for java.util.stream.StreamSpliterators$WrappingSpliterator$$Lambda$179.0x000000080023a040 getAsBoolean ()Zand so on (hundreds of them).
Example log content for lines 3806-3709:
<task_queued compile_id='1363' method='java.lang.Object <init> ()V' bytes='1' count='768' iicount='768' level='1' stamp='1.568' comment='tiered' hot_count='768'/>
<writer thread='33624'/>
<nmethod compile_id='1361' compiler='c1' level='1' entry='0x0000018e449c2540' size='768' address='0x0000018e449c2390' relocation_offset='376' insts_offset='432' stub_offset='592' scopes_data_offset='664' scopes_pcs_offset='680' dependencies_offset='744' nul_chk_table_offset='752' oops_offset='648' metadata_offset='656' method='java.lang.invoke.LambdaForm$MH/0x0000000800060440 invoke (Ljava/lang/Object;)Ljava/lang/Object;' bytes='8' count='381' iicount='381' stamp='1.568'/>
<nmethod compile_id='1363' compiler='c1' level='1' entry='0x0000018e449c28c0' size='696' address='0x0000018e449c2710' relocation_offset='376' insts_offset='432' stub_offset='560' scopes_data_offset='624' scopes_pcs_offset='640' dependencies_offset='688' metadata_offset='616' method='java.lang.Object <init> ()V' bytes='1' count='797' iicount='797' stamp='1.569'/>Example log content for lines 4660-4663:
<task_queued compile_id='1363' method='java.lang.Object <init> ()V' bytes='1' count='768' iicount='768' level='1' stamp='1.568' comment='tiered' hot_count='768'/>
<writer thread='33624'/>
<nmethod compile_id='1361' compiler='c1' level='1' entry='0x0000018e449c2540' size='768' address='0x0000018e449c2390' relocation_offset='376' insts_offset='432' stub_offset='592' scopes_data_offset='664' scopes_pcs_offset='680' dependencies_offset='744' nul_chk_table_offset='752' oops_offset='648' metadata_offset='656' method='java.lang.invoke.LambdaForm$MH/0x0000000800060440 invoke (Ljava/lang/Object;)Ljava/lang/Object;' bytes='8' count='381' iicount='381' stamp='1.568'/>Example log content for lines 4660-4663:
<task_queued compile_id='1682' method='java.util.Spliterators$ArraySpliterator tryAdvance (Ljava/util/function/Consumer;)Z' bytes='58' count='256' iicount='256' level='1' stamp='1.976' comment='tiered' hot_count='256'/>
<task_queued compile_id='1683' method='java.util.stream.AbstractSpinedBuffer count ()J' bytes='31' count='256' iicount='256' level='1' stamp='1.976' comment='tiered' hot_count='256'/>
<task_queued compile_id='1684' method='java.util.stream.StreamSpliterators$WrappingSpliterator$$Lambda$179/0x000000080023a040 getAsBoolean ()Z' bytes='8' count='256' iicount='256' level='1' stamp='1.976' comment='tiered' hot_count='256'/>
<task_queued compile_id='1685' method='java.util.stream.StreamSpliterators$WrappingSpliterator lambda$initPartialTraversalState$0 ()Z' bytes='14' count='256' iicount='256' level='1' stamp='1.976' comment='tiered' hot_count='256'/>Note that it seems that error log messages point to a bit wrong line numbers. Error mentions log line 4661 but the relevant content seems to be on line 4662.
chriswhocodes
commented
2 years ago "Could not parse" for lambdas is a known problem. The solution requires a bit of a redesign which is currently in (slow) progress.
Looks like there's an off-by-one in reporting the errors lines. Will fix that :)
alexei-osipov
commented
2 years ago I guess that parsing issue is not actually related to the NPE problem then.
Is there any information that might be helpful for you?
chriswhocodes
commented
2 years ago Could you let me know what kind of JIT log exhibits the error? One from the Sandbox examples or collected from your own program (-XX:+LogCompilation) ? Thanks
alexei-osipov
commented
2 years ago It's collected from my own app. JVM flags used:
-XX:+UnlockDiagnosticVMOptions -XX:+TraceClassLoading -XX:+LogCompilation -XX:-PrintAssembly -XX:LogFile=server_jit.log(PrintAssembly is turned off for now)
alexei-osipov
commented
2 years ago I've just opened sanbox log and it works fine. The problem occurs only on my log.
I'm not sure that this id directly useful but this branch from AbstractLogParser#handleMember is executed for sandbox but not executed for my log:
case TASK:
{
setTagTask((Task) tag, metaMember);
currentMember = metaMember;
model.updateStats(metaMember, attrs);
}Oh, it seems the main difference that I've opened log on the running app. So the log was incomplete. After the app shutdown JITWatch was able to properly show call/inline chain.
However it's a bit strange that this resulted in NPE.
chriswhocodes
commented
2 years ago Thanks for tracking this down. I'll put in a null check so you see an empty call chain instead of it blowing up :)
alexei-osipov
commented
2 years ago Thank you!
Any attempt to open "Chain" view for any method results in NPE.
Checked current "master" branch and tag "1.4.7".
JDK version: 11.0.13.8, 11.0.15.10