NPE on "Chain" button
alexei-osipov opened this issue · 11 comments
alexei-osipov commented
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
java.lang.NullPointerException
at org.adoptopenjdk.jitwatch.ui.compilechain.CompileChainStage.buildTree (CompileChainStage.java:375)
at org.adoptopenjdk.jitwatch.ui.compilechain.CompileChainStage.compilationChanged (CompileChainStage.java:132)
at org.adoptopenjdk.jitwatch.ui.main.JITWatchUI.openCompileChain (JITWatchUI.java:1271)
at org.adoptopenjdk.jitwatch.ui.triview.TriView$1.handle (TriView.java:161)
at org.adoptopenjdk.jitwatch.ui.triview.TriView$1.handle (TriView.java:155)
at com.sun.javafx.event.CompositeEventHandler.dispatchBubblingEvent (CompositeEventHandler.java:86)
at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent (EventHandlerManager.java:234)
at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent (EventHandlerManager.java:191)
at com.sun.javafx.event.CompositeEventDispatcher.dispatchBubblingEvent (CompositeEventDispatcher.java:59)
at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent (BasicEventDispatcher.java:58)
at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent (EventDispatchChainImpl.java:114)
at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent (BasicEventDispatcher.java:56)
at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent (EventDispatchChainImpl.java:114)
at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent (BasicEventDispatcher.java:56)
at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent (EventDispatchChainImpl.java:114)
at com.sun.javafx.event.EventUtil.fireEventImpl (EventUtil.java:74)
at com.sun.javafx.event.EventUtil.fireEvent (EventUtil.java:49)
at javafx.event.Event.fireEvent (Event.java:198)
at javafx.scene.Node.fireEvent (Node.java:8792)
at javafx.scene.control.Button.fire (Button.java:203)
at com.sun.javafx.scene.control.behavior.ButtonBehavior.mouseReleased (ButtonBehavior.java:208)
at com.sun.javafx.scene.control.inputmap.InputMap.handle (InputMap.java:274)
at com.sun.javafx.event.CompositeEventHandler$NormalEventHandlerRecord.handleBubblingEvent (CompositeEventHandler.java:247)
at com.sun.javafx.event.CompositeEventHandler.dispatchBubblingEvent (CompositeEventHandler.java:80)
at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent (EventHandlerManager.java:234)
at com.sun.javafx.event.EventHandlerManager.dispatchBubblingEvent (EventHandlerManager.java:191)
at com.sun.javafx.event.CompositeEventDispatcher.dispatchBubblingEvent (CompositeEventDispatcher.java:59)
at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent (BasicEventDispatcher.java:58)
at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent (EventDispatchChainImpl.java:114)
at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent (BasicEventDispatcher.java:56)
at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent (EventDispatchChainImpl.java:114)
at com.sun.javafx.event.BasicEventDispatcher.dispatchEvent (BasicEventDispatcher.java:56)
at com.sun.javafx.event.EventDispatchChainImpl.dispatchEvent (EventDispatchChainImpl.java:114)
at com.sun.javafx.event.EventUtil.fireEventImpl (EventUtil.java:74)
at com.sun.javafx.event.EventUtil.fireEvent (EventUtil.java:54)
at javafx.event.Event.fireEvent (Event.java:198)
at javafx.scene.Scene$MouseHandler.process (Scene.java:3897)
at javafx.scene.Scene.processMouseEvent (Scene.java:1878)
at javafx.scene.Scene$ScenePeerListener.mouseEvent (Scene.java:2623)
at com.sun.javafx.tk.quantum.GlassViewEventHandler$MouseEventNotification.run (GlassViewEventHandler.java:411)
at com.sun.javafx.tk.quantum.GlassViewEventHandler$MouseEventNotification.run (GlassViewEventHandler.java:301)
at java.security.AccessController.doPrivileged (Native Method)
at com.sun.javafx.tk.quantum.GlassViewEventHandler.lambda$handleMouseEvent$2 (GlassViewEventHandler.java:450)
at com.sun.javafx.tk.quantum.QuantumToolkit.runWithoutRenderLock (QuantumToolkit.java:424)
at com.sun.javafx.tk.quantum.GlassViewEventHandler.handleMouseEvent (GlassViewEventHandler.java:449)
at com.sun.glass.ui.View.handleMouseEvent (View.java:557)
at com.sun.glass.ui.View.notifyMouse (View.java:943)
at com.sun.glass.ui.win.WinApplication._runLoop (Native Method)
at com.sun.glass.ui.win.WinApplication.lambda$runLoop$3 (WinApplication.java:184)
at java.lang.Thread.run (Thread.java:829)
alexei-osipov commented
In class CompileChainStage on line
title += rootMemberName + " " + root.getCompilation().getSignature(); variable root is null.
chriswhocodes commented
Hi @alexei-osipov ,
Thanks for reporting. I'll investigate why this is happening and put in a fix.
Kind regards,
Chris
alexei-osipov commented
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 ()Z
and 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
"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
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
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
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
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);
}
alexei-osipov commented
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
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
Thank you!