On 12/31/16 20:37, Alan Ruttenberg wrote:
I'm getting backtraces that are noisy and therefore impede comprehension.
For example, in the following stack trace, frames 68-4 seem to recapitulate, for the most part, the java stack corresponding to frames 87-69
The ABCL backtrace abstraction is perhaps a little bit leaky and noisy with respect to its representation of Java calls, but it has been useful in improving the implementation in its present form since Tobias and I introduced it back in 2006-7 (?).
My strong claim is that a user of ABCL never will see Java calls in the backtrace, as they only result in errors in the ABCL implementation which causes the "Lisp computation" to fail, thunking out into the surrounding Java Try/Catch/Exception mechanism. So, "normally" (i.e. when there are more bugs in your code than the implementation), these verbose, confusing messages are not seen by the user.
In your example, frames 87-69 show the Lisp-side computation which got to the error being signaled in the ABCL implmentation. Then frames 4-68 provide the trace of Java attempting to deal with the error signaled by the JVM when executing Primitives.java:2845. Frames 0-2 show the error propagating back into the Lisp-side debugger machinery.
I think the only real information I get as a developer here is that there is an error occuring in org.armedbear.lisp.Primitives:2845; the rest of the Java calls don't need to be shown. The backtrace from 4-67 can confirm/deny hypothesis about what exacly caused the Java error on that line, but usually I would figure things out by starting ABCL under JPDA, setting a break point before Primitives:2845, replicating the error, and single-stepping through the JVM execution until I understand the problem.
The "logic" of javaPushStackFrames() (my code) is trying to elide noisy frames. Here it fails to elide frames in your example, as the entry point is in Primitive.java not Primitives.java, so this code should be changed. I would go with a simpler implementation of javaPushStackFrames() that doesn't try to elide frames, and place such a mechanism on actually viewing the stack. Perhaps we can get SLIME to "collapse" the Java portion of the backtrace (ala "the inspector") into a single statement of the source location that the Lisp computation enter the JVM error condition?
Hopefully that provides some background for a proposal for a less noisy backtrace for your purposes to be possible. Since I often get bug reports consisting of little or more reproduction instructions than: "I have a problem with ABCL: it gave me this error." and a paste of the stack trace, it has been useful to have more information present than not.
One could certainly somehow collapse frames 0-3 somehow into a single frame that represents the debugger invocation.
Thanks, Alan
The value CL-UTILS::FORMS is not of type LIST. [Condition of type TYPE-ERROR]
Restarts: 0: [RETRY] Retry compiling #<ASDF/LISP-ACTION:CL-SOURCE-FILE "jnil" "cl-utils">. 1: [ACCEPT] Continue, treating compiling #<ASDF/LISP-ACTION:CL-SOURCE-FILE "jnil" "cl-utils"> as having been successful. 2: [RETRY] Retry ASDF operation. 3: [CLEAR-CONFIGURATION-AND-RETRY] Retry ASDF operation after resetting the configuration. 4: [ABORT] Abort compilation. 5: [*ABORT] Return to SLIME's top level. --more--
Backtrace: 0: (#<LOCAL-FUNCTION IN MAKE-INVOKE-DEBUGGER-HOOK {5108C7A9}> #<TYPE-ERROR {D3CDE50}> #<LOCAL-FUNCTION IN MAKE-INVOKE-DEBUGGER-HOOK {5108C7A9}>) 1: (APPLY #<LOCAL-FUNCTION IN MAKE-INVOKE-DEBUGGER-HOOK {5108C7A9}> (#<TYPE-ERROR {D3CDE50}> #<LOCAL-FUNCTION IN MAKE-INVOKE-DEBUGGER-HOOK {5108C7A9}>)) 2: (SYSTEM::RUN-HOOK SYSTEM::*INVOKE-DEBUGGER-HOOK* #<TYPE-ERROR {D3CDE50}> #<LOCAL-FUNCTION IN MAKE-INVOKE-DEBUGGER-HOOK {5108C7A9}>) 3: (INVOKE-DEBUGGER #<TYPE-ERROR {D3CDE50}>) 4: org.armedbear.lisp.Lisp.error(Lisp.java:382) 5: org.armedbear.lisp.Lisp.type_error(Lisp.java:435) 6: org.armedbear.lisp.LispObject.car(LispObject.java:165) 7: org.armedbear.lisp.precompiler_51.execute(precompiler.lisp:381) 8: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 9: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 10: org.armedbear.lisp.precompiler_48.execute(precompiler.lisp:350) 11: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 12: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 13: org.armedbear.lisp.precompiler_51.execute(precompiler.lisp:381) 14: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 15: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 16: org.armedbear.lisp.precompiler_48.execute(precompiler.lisp:350) 17: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 18: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 19: org.armedbear.lisp.precompiler_51.execute(precompiler.lisp:381) 20: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 21: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 22: org.armedbear.lisp.precompiler_48.execute(precompiler.lisp:350) 23: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 24: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 25: org.armedbear.lisp.precompiler_51.execute(precompiler.lisp:381) 26: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 27: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 28: org.armedbear.lisp.precompiler_48.execute(precompiler.lisp:350) 29: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 30: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 31: org.armedbear.lisp.precompiler_51.execute(precompiler.lisp:381) 32: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 33: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 34: org.armedbear.lisp.precompiler_48.execute(precompiler.lisp:350) 35: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 36: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 37: org.armedbear.lisp.precompiler_73.execute(precompiler.lisp:643) 38: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 39: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 40: org.armedbear.lisp.precompiler_48.execute(precompiler.lisp:350) 41: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 42: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 43: org.armedbear.lisp.precompiler_105.execute(precompiler.lisp:988) 44: org.armedbear.lisp.CompiledClosure.execute(CompiledClosure.java:121) 45: org.armedbear.lisp.Symbol.execute(Symbol.java:826) 46: org.armedbear.lisp.compiler_pass2_362.execute(compiler-pass2.lisp:7380) 47: org.armedbear.lisp.Symbol.execute(Symbol.java:867) 48: org.armedbear.lisp.LispThread.execute(LispThread.java:918) 49: org.armedbear.lisp.compile_file_19.execute(compile-file.lisp:175) 50: org.armedbear.lisp.Symbol.execute(Symbol.java:814) 51: org.armedbear.lisp.LispThread.execute(LispThread.java:832) 52: org.armedbear.lisp.compile_file_51.execute(compile-file.lisp:655) 53: org.armedbear.lisp.Symbol.execute(Symbol.java:826) 54: org.armedbear.lisp.LispThread.execute(LispThread.java:851) 55: org.armedbear.lisp.compile_file_59.execute(compile-file.lisp:780) 56: org.armedbear.lisp.compiler_pass2_370.execute(compiler-pass2.lisp:7450) 57: org.armedbear.lisp.CompiledClosure.execute(CompiledClosure.java:98) 58: org.armedbear.lisp.Symbol.execute(Symbol.java:803) 59: org.armedbear.lisp.LispThread.execute(LispThread.java:814) 60: org.armedbear.lisp.compile_file_57.execute(compile-file.lisp:780) 61: org.armedbear.lisp.Symbol.execute(Symbol.java:914) 62: org.armedbear.lisp.LispThread.execute(LispThread.java:986) 63: org.armedbear.lisp.compile_file_68.execute(compile-file.lisp:962) 64: org.armedbear.lisp.CompiledClosure.execute(CompiledClosure.java:150) 65: org.armedbear.lisp.Symbol.execute(Symbol.java:852) 66: org.armedbear.lisp.LispThread.execute(LispThread.java:894) 67: org.armedbear.lisp.Lisp.funcall(Lisp.java:180) 68: org.armedbear.lisp.Primitives$pf_apply.execute(Primitives.java:2845) 69: (PRECOMPILER::PRECOMPILE-FUNCTION-CALL (CL-UTILS::KEY . CL-UTILS::FORMS)) 70: (PRECOMPILER::PRECOMPILE1 (CL-UTILS::KEY . CL-UTILS::FORMS)) 71: (PRECOMPILER::PRECOMPILE-FUNCTION-CALL (CL-UTILS::LOOP CL-UTILS::FOR (CL-UTILS::KEY . CL-UTILS::FORMS) CL-UTILS::IN CL-UTILS::CLAUSES CL-UTILS::DO ...)) 72: (PRECOMPILER::PRECOMPILE1 (CL-UTILS::LOOP CL-UTILS::FOR (CL-UTILS::KEY . CL-UTILS::FORMS) CL-UTILS::IN CL-UTILS::CLAUSES CL-UTILS::DO ...)) 73: (PRECOMPILER::PRECOMPILE-FUNCTION-CALL (CL-UTILS::LET ((CL-UTILS::CLAUSE-COLLECTION (CL-UTILS::LIST))) ..)) 74: (PRECOMPILER::PRECOMPILE1 (CL-UTILS::LET ((CL-UTILS::CLAUSE-COLLECTION (CL-UTILS::LIST))) ..)) 75: (PRECOMPILER::PRECOMPILE-FUNCTION-CALL (CL-UTILS::WITH-GENSYMS (CL-UTILS::TEST) ..)) 76: (PRECOMPILER::PRECOMPILE1 (CL-UTILS::WITH-GENSYMS (CL-UTILS::TEST) ..)) 77: (PRECOMPILER::PRECOMPILE-FUNCTION-CALL (CL-UTILS::DEFMACRO CL-UTILS::CASE* (CL-UTILS::KEYFORM CL-UTILS::&REST CL-UTILS::CLAUSES) ..)) 78: (PRECOMPILER::PRECOMPILE1 (CL-UTILS::DEFMACRO CL-UTILS::CASE* (CL-UTILS::KEYFORM CL-UTILS::&REST CL-UTILS::CLAUSES) ..)) 79: (PRECOMPILER::PRECOMPILE-LAMBDA (LAMBDA NIL ..)) 80: (PRECOMPILER::PRECOMPILE1 (LAMBDA NIL (CL-UTILS::DEFMACRO CL-UTILS::CASE* (CL-UTILS::KEYFORM CL-UTILS::&REST CL-UTILS::CLAUSES) (CL-UTILS::WITH-GENSYMS (CL-UTILS::TEST) (CL-UTILS::LET # # #))))) 81: (JVM:COMPILE-DEFUN NIL (LAMBDA NIL (CL-UTILS::DEFMACRO CL-UTILS::CASE* (CL-UTILS::KEYFORM CL-UTILS::&REST CL-UTILS::CLAUSES) (CL-UTILS::WITH-GENSYMS (CL-UTILS::TEST) (CL-UTILS::LET # # #)))) NIL #P"/U.. 82: (SYSTEM::CONVERT-TOPLEVEL-FORM (CL-UTILS::DEFMACRO CL-UTILS::CASE* (CL-UTILS::KEYFORM CL-UTILS::&REST CL-UTILS::CLAUSES) ..) NIL) 83: (SYSTEM::PROCESS-TOPLEVEL-FORM (CL-UTILS::DEFMACRO CL-UTILS::CASE* (CL-UTILS::KEYFORM CL-UTILS::&REST CL-UTILS::CLAUSES) ..) #<FILE-STREAM {1773B7E}> NIL) 84: (JVM::%WITH-COMPILATION-UNIT #<LOCAL-FUNCTION IN COMPILE-FROM-STREAM {1FEBE62E}>) 85: (SYSTEM::COMPILE-FROM-STREAM #<FILE-STREAM {744E75DD}> #P"/Users/lori/.cache/common-lisp/abcl-1.5.0-dev-fasl43-macosx-x64/Volumes/upstairs/repos/jnil/lisp/jnil/cl-utils-tmpUYPFRO0B.abcl" #P"/Users/lor.. 86: (COMPILE-FILE #P"/Volumes/upstairs/repos/jnil/lisp/jnil/cl-utils.lisp" :OUTPUT-FILE #P"/Users/lori/.cache/common-lisp/abcl-1.5.0-dev-fasl43-macosx-x64/Volumes/upstairs/repos/jnil/lisp/jnil/cl-utils-tm.. 87: (APPLY COMPILE-FILE #P"/Volumes/upstairs/repos/jnil/lisp/jnil/cl-utils.lisp" :OUTPUT-FILE #P"/Users/lori/.cache/common-lisp/abcl-1.5.0-dev-fasl43-macosx-x64/Volumes/upstairs/repos/jnil/lisp/jnil/cl-ut..
private static final void pushJavaStackFrames() { final LispThread thread = LispThread.currentThread(); final StackTraceElement[] frames = thread.getJavaStackTrace();
// frames[0] java.lang.Thread.getStackTrace // frames[1] org.armedbear.lisp.LispThread.getJavaStackTrace // frames[2] org.armedbear.lisp.Lisp.pushJavaStackFrames if (frames.length > 5 && frames[3].getClassName().equals("org.armedbear.lisp.Lisp") && frames[3].getMethodName().equals("error") && frames[4].getClassName().startsWith("org.armedbear.lisp.Lisp") && frames[4].getMethodName().equals("eval")) { // Error condition arising from within Lisp.eval(), so no // Java stack frames should be visible to the consumer of thestack abstraction return; } // Search for last Primitive in the StackTrace; that was the // last entry point from Lisp. int last = frames.length - 1; for (int i = 0; i<= last; i++) { if (frames[i].getClassName().startsWith("org.armedbear.lisp.Primitive")) last = i; } // Do not include the first three frames which, as noted above, constitute // the invocation of this method. while (last > 2) { thread.pushStackFrame(new JavaStackFrame(frames[last])); last--; } }