Error: 'null' for object '{"id":"$$locals-ndsf1310"}

[benoitcerrina]

Errors such as the one above are sometimes (not sure yet when) showing in the chrome console. The id format shows it has to do with some local variable but I am not sure where the error is coming from. When it happens the "local" tree to the right is not available

[benoitcerrina]

Also when it happens, if I type in the chrome console I get one new such error with a different id for each character typed. Those errors though look like Error: 'null' for object '{"id":"uid-10135"} so the object in question is not a local variable

[benoitcerrina]

When that happens I also have stacks looking like this in the ncdbg console Message handling error for domain Runtime com.sun.jdi.IncompatibleThreadStateException: null at com.sun.tools.jdi.InvokableTypeImpl.invokeMethod(InvokableTypeImpl.java:116) at com.programmaticallyspeaking.ncd.nashorn.StaticInvoker.$anonfun$applyDynamic$6(DynamicInvoker.scala:159) at com.programmaticallyspeaking.ncd.nashorn.Invoker.unpackError(DynamicInvoker.scala:100) at com.programmaticallyspeaking.ncd.nashorn.StaticInvoker.$anonfun$applyDynamic$5(DynamicInvoker.scala:159) at com.programmaticallyspeaking.ncd.nashorn.VirtualMachineExtensions$ExtVirtualMachine.withoutClassPrepareRequests(VirtualMachineExtensions.scala:21 at com.programmaticallyspeaking.ncd.nashorn.StaticInvoker.applyDynamic(DynamicInvoker.scala:159) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport.$anonfun$scriptBasedPropertyHolderFactory$2(ObjectPropertiesSupport.scala:110) at com.programmaticallyspeaking.ncd.nashorn.ScriptBasedPropertyHolderFactory.$anonfun$create$1(PropertyHolder.scala:244) at com.programmaticallyspeaking.ncd.nashorn.ScriptBasedPropertyHolder.properties(PropertyHolder.scala:286) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport$$anon$1.properties(ObjectPropertiesSupport.scala:74) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport.$anonfun$getObjectProperties$3(ObjectPropertiesSupport.scala:39) at scala.Option.map(Option.scala:146) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport.getProperties$1(ObjectPropertiesSupport.scala:39) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport.$anonfun$getObjectProperties$5(ObjectPropertiesSupport.scala:41) at scala.collection.mutable.HashMap.getOrElseUpdate(HashMap.scala:79) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport.getObjectProperties(ObjectPropertiesSupport.scala:41) at com.programmaticallyspeaking.ncd.nashorn.ObjectPropertiesSupport.getObjectProperties$(ObjectPropertiesSupport.scala:20) at com.programmaticallyspeaking.ncd.nashorn.NashornDebuggerHost.getObjectProperties(NashornDebuggerHost.scala:172) at sun.reflect.GeneratedMethodAccessor17.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.programmaticallyspeaking.ncd.infra.ExecutorProxy$Handler.$anonfun$invoke$3(ExecutorProxy.scala:42) at scala.util.Try$.apply(Try.scala:209) at com.programmaticallyspeaking.ncd.infra.ExecutorProxy$Handler.$anonfun$invoke$2(ExecutorProxy.scala:42) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Got error response from domain: ErrorResponse(661,null)

[provegard]

Do you get this error in paused state? Which Java version does the target run? Java version for running Ncdbg?

[provegard]

Also, are you running NCDbg from the repo? Which commit? Which Chrome version?

[benoitcerrina]

I do get this error in pause state, for instance when typing in the console (I think it is due to autocompletion attempt in that case)

ncdbg version. I was using the commit from 10/24/2017 d0a0d3eeac28c71aec6489e1f31687687451ec98

I just synced to the latest I will update this with wether the problem happens again by the end of the day

Chrome version 64.0.3282.186

Java Versions (from ncdb traces): Local Java version: 1.8.0_144 Remote VM information:

• Java Debug Interface (Reference Implementation) version 1.8
• Java Debug Wire Protocol (Reference Implementation) version 1.8
• JVM Debug Interface version 1.2
• JVM version 1.8.0_131 (Java HotSpot(TM) 64-Bit Server VM, mixed mode, sharing)

[provegard]

Ok, let me know what you find.

If the error remains with the lastest commit, would it be possible for you to share some details about the script you're debugging?

[benoitcerrina]

It is a bit difficult to share much details about the script in question for 2 reasons: 1) it is part of a fairly complex server side system which uses nashorn to write business logic and without the whole thing it would be hard to understand it. 2) I don't own the IP the company I work for does.

I can share some specific details if you have precise inquiries.

This being said I haven't reproduced the exact same situation this afternoon but I did see some similar cases. When it happened I was trying to step into a function and it would not do so.

Here are the console outputs (the first 2 lines are normal, I am typing a local var in the console and the value is printed. Then come the errors

contentTypeForPredicate ["dsxplan:TaskInstance"] Error: 'null' for object '{"id":"$$locals-ndsf1126"}' Error: 'null' for object '{"id":"uid-20904"}' Error: 'null' for object '{"id":"$$locals-ndsf1224"}' Error: 'null' for object '{"id":"$$locals-ndsf1322"}' Error: 'null' for object '{"id":"$$locals-ndsf1420"}'

The traces of ncdbg are much more interesting though (see below), it seems that the location in the script was not recognized, and everything went haywire. Note that I then restarted both the debugged jvm and ncdbg and redid my scenario, the error showed up again in the console but the breakpoints were recognized and I could step into in the exact same place :

Enabling domain Profiler Failed to handle message: Cannot create domain method Debugger.setAsyncCallStackDepth because the domain and/or method are unknown Failed to handle message: Cannot create domain method Debugger.setBlackboxPatterns because the domain and/or method are unknown Failed to handle message: Not a domain actor: com.programmaticallyspeaking.ncd.chrome.domains.HeapProfiler Enabling domain Runtime Enabling domain Debugger Enabling debugging, sending all parsed scripts to the client. Will pause on breakpoints Setting an unresolved breakpoint with ID ndb1 at line 1039 in script with URL xplan/xPlanDSLCCommandImplementation Setting an unresolved breakpoint with ID ndb2 at line 233 in script with URL xplan/xPlanDSLCCommandImplementationAdd Setting an unresolved breakpoint with ID ndb3 at line 1191 in script with URL xplan/xPlanDSLCCommandImplementation Resolving breakpoint ndb3 with location 1191:13 in script nds20 Stepping with type StepOver Resuming virtual machine Stepping with type StepInto Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:36) since we don't recognize it. Stepping with type StepInto Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:37) since we don't recognize it. Stepping with type StepInto Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:38) since we don't recognize it. Stepping with type StepInto Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$83$667A$\^eval_#142!9\^eval_:21) since we don't recognize it. Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:38) since we don't recognize it. Stepping with type StepInto Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:38) since we don't recognize it. Stepping with type StepInto Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$84$13479A$\^eval_:408) since we don't recognize it. Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:38) since we don't recognize it. Setting an unresolved breakpoint with ID ndb4 at line 36 in script with URL xplan/QueryUtil Stepping with type StepOver Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$84$13479A$\^eval_:409) since we don't recognize it. Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:38) since we don't recognize it. Stepping with type StepOver Resuming virtual machine Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$\^eval_#142!9\^eval_:38) since we don't recognize it. Setting a breakpoint with ID ndb5 for location(s) nds20:1195 (jdk.nashorn.internal.scripts.Script$Recompilation$288$45689AA$\^eval_#142!9\^eval_:1195) in scr ipt with URL xplan/xPlanDSLCCommandImplementation Resuming virtual machine Pausing at breakpoint ndb5 at xplan/xPlanDSLCCommandImplementation:1195: var createInstanceURI = rdf.rql(addLinkContentToParent, addLnkCtnPatVersion ); Resuming virtual machine Stepping with type StepOver Resuming virtual machine Stepping with type StepOver Resuming virtual machine Stepping with type StepOver Resuming virtual machine Resuming virtual machine <==========---> 83% EXECUTING [3m 41s]

:run Terminate batch job (Y/N)?

[provegard]

Thanks, a few quick questions:

• Evaluation of the local variable happens before you try to step into the function, right? So it belongs to the caller location?
• How is the local declared? Is it a var, or a function parameter, or something else?
• Won't create a stack frame for location (jdk.nashorn.internal.scripts.Script$Recompilation$82$1164AA$^eval_#142!9^eval_:36) since we don't recognize it. - interesting, I'll see if I can improve logging here.
• I'm curious about two evals in the message above. Do you create the function by evaling code?
• Could you share ncdbg.log instead? It should contain more detailed logging. You might want to trim it first though, and scrub it from sensitive script details (source code) before publishing. If you don't want to attach it here, you can send it to me by email.

[provegard]

Perhaps there are two separate problems in this issue?

[benoitcerrina]

Very possibly. I can send you the ncdbg.log from next time I see the issue which will likely be today. In the case I showed above the local was declared with a var and it does belong to the caller location.

Regarding the evals, yes the scripts which are running are stored in a server side db and evaled by the server code. It is loaded either by:

ScriptObjectMirror som = (ScriptObjectMirror)scriptEngine.eval("load('" + modulePath + "');");

or som = (ScriptObjectMirror)scriptEngine.eval(moduleJsCode);

[provegard]

I tried to reproduce by playing around with local variables, but no luck. Do you think you can reproduce with a minimal and shareable example?

[benoitcerrina]

Not sure yesterday it didn't happen. And usually when it happens if I restart both the debugged vm and the debugger the same scenario won't display the issue. I am making sure to erase the logs prior to each debug run so I can hopefully get a log of when it happens. I know how frustrating hard to reproduce bugs can be so I am really sorry about that.

[provegard]

I think I have fixed the problem now. The wrong thread was reused for property extraction. The fix ensures that the currently paused thread is used. Could you please test?

[benoitcerrina]

No problems today. It is not necessarily conclusive but I did spend about an hour in the debugger without running into this.
I think this can be closed and if it resurface either reopened or another one opened. Thanks for the hard work.