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
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 the stack 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--; } }
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 the
stack 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--; } }
Well, I've gone and made an attempt at a "less leaky" version. (It became an obsession :( )
Some features: - tries not to show internals of swank and abcl debugging calls - shows top of exception trace for java exceptions, marked with "!" to indicate they were caught. - names local functions, even if we only would see the java frame. - And some other nuisances. Read the code?
I am soliciting beta testers - need to see whether it holds up under stress of use by other. You will need to check out my branch of ABCL https://github.com/alanruttenberg/abcl.git - use branch "stage" and you will need my branch of slime https://github.com/alanruttenberg/slime/ - use branch "beta"
Build abcl with: ant abcl-aio.jar
There are a number of other debugging goodies here, also worth testing: - Better inspectors for some things, like java classes - View source and disassemble from debugger should work on every frame - Most definition sources are recorded, including those compiled in a buffer. Try edit definitions 'print-object and you will see all the methods and their source locations - slime-edit-callers
Alan
On Sun, Jan 1, 2017 at 6:11 AM, Mark Evenson evenson@panix.com wrote:
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 the
stack 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--; } }
-- "A screaming comes across the sky. It has happened before, but there is nothing to compare to it now."
On 1/3/17 00:35, Alan Ruttenberg wrote:
Well, I've gone and made an attempt at a "less leaky" version. (It became an obsession :( )
Very cool. I need to find some cycles to start working through your code.
One question: do you expect version of SLIME categorically fail completely with previous ABCL versions (i.e. those without ABCL-INTROSPECT)? Or were your able to special-case the new features in swank-abcl.lisp?
On Tue, Jan 3, 2017 at 6:57 AM, Mark Evenson evenson@panix.com wrote:
On 1/3/17 00:35, Alan Ruttenberg wrote:
Well, I've gone and made an attempt at a "less leaky" version. (It
became
an obsession :( )
Very cool. I need to find some cycles to start working through your code.
One question: do you expect version of SLIME categorically fail completely with previous ABCL versions (i.e. those without ABCL-INTROSPECT)? Or were your able to special-case the new features in swank-abcl.lisp?
I did a bit of special-casing, but for the new stacktrace - falls back to the old version if it isn't there (though current version (require)s abcl-introspect). No special-casing for new record-source-location stuff. I could see about making it work without abcl-introspect. IIRC there are only a couple of places that use it. But is it worth it, given that it will require the new version of ABCL for source-location?
Alan
btw, haven't updated https://gitlab.common-lisp.net/abcl/ -will do later
-- "A screaming comes across the sky. It has happened before, but there is nothing to compare to it now."
On 1/3/17 20:46, Alan Ruttenberg wrote:
On Tue, Jan 3, 2017 at 6:57 AM, Mark Evenson evenson@panix.com wrote:
On 1/3/17 00:35, Alan Ruttenberg wrote:
Well, I've gone and made an attempt at a "less leaky" version. (It
became
an obsession :( )
Very cool. I need to find some cycles to start working through your code.
One question: do you expect version of SLIME categorically fail completely with previous ABCL versions (i.e. those without ABCL-INTROSPECT)? Or were your able to special-case the new features in swank-abcl.lisp?
[…]
But is it worth it, given that it will require the new version of ABCL for source-location?
I will incur significant "support" cost if SLIME stops working for existing users, so I need to avoid that scenario if at all possible.
On Wed, Jan 4, 2017 at 7:19 AM, Mark Evenson evenson@panix.com wrote:
On 1/3/17 20:46, Alan Ruttenberg wrote:
On Tue, Jan 3, 2017 at 6:57 AM, Mark Evenson evenson@panix.com wrote:
On 1/3/17 00:35, Alan Ruttenberg wrote:
Well, I've gone and made an attempt at a "less leaky" version. (It
became
an obsession :( )
Very cool. I need to find some cycles to start working through your
code.
One question: do you expect version of SLIME categorically fail completely with previous ABCL versions (i.e. those without ABCL-INTROSPECT)? Or were your able to special-case the new features in swank-abcl.lisp?
[…]
But is it worth it, given that it will require the new version of ABCL
for
source-location?
I will incur significant "support" cost if SLIME stops working for existing users, so I need to avoid that scenario if at all possible.
I'll look into it.
Rather than cluttering up the newer version what do you think of having slime include the older version and have the swank loader conditionally load old or new depending on the ABCL version?
There is also slime maintenance cost associated with having it be backward compatible.
An alternative is to check in a compatible version of slime as part of each ABCL release. This requires a bit of thought about managing the case where someone wants to run multiple different lisp implementations in the same emacs, thought I'm.not sure how prevalent this is.
Alan
On Wed, Jan 4, 2017 at 10:53 AM Alan Ruttenberg alanruttenberg@gmail.com wrote:
On Wed, Jan 4, 2017 at 7:19 AM, Mark Evenson evenson@panix.com wrote:
On 1/3/17 20:46, Alan Ruttenberg wrote:
On Tue, Jan 3, 2017 at 6:57 AM, Mark Evenson evenson@panix.com wrote:
On 1/3/17 00:35, Alan Ruttenberg wrote:
Well, I've gone and made an attempt at a "less leaky" version. (It
became
an obsession :( )
Very cool. I need to find some cycles to start working through your
code.
One question: do you expect version of SLIME categorically fail
completely with previous ABCL versions (i.e. those without
ABCL-INTROSPECT)? Or were your able to special-case the new features in
swank-abcl.lisp?
[…]
But is it worth it, given that it will require the new version of ABCL
for
source-location?
I will incur significant "support" cost if SLIME stops working for
existing users, so I need to avoid that scenario if at all possible.
I'll look into it.
On Wed, Jan 4, 2017 at 5:31 PM, Alan Ruttenberg alanruttenberg@gmail.com wrote:
Rather than cluttering up the newer version what do you think of having slime include the older version and have the swank loader conditionally load old or new depending on the ABCL version?
There is also slime maintenance cost associated with having it be backward compatible.
FWIW, swank-sbcl.lisp typically accrues conditionals for dealing with older versions until sufficient time has passed (usually years) and said conditionals become a nuisance.
Having two different swank implementations for older and newer ABCLs seems worse than conditionals in terms of maintenance costs. swank-sbcl.lisp contains various tricks for making conditionals more manageable. Perhaps some of those practices might help in this case?
I'll have a look - thanks.
Its a fairly high overhaul rather than a few incremental improvements which is why I'm a bit reluctant. SBCL is rather more mature than ABCL①... On Wed, Jan 4, 2017 at 12:56 PM Luís Oliveira luismbo@gmail.com wrote:
On Wed, Jan 4, 2017 at 5:31 PM, Alan Ruttenberg alanruttenberg@gmail.com wrote:
Rather than cluttering up the newer version what do you think of having slime include the older version and have the swank loader conditionally
load
old or new depending on the ABCL version?
There is also slime maintenance cost associated with having it be
backward
compatible.
FWIW, swank-sbcl.lisp typically accrues conditionals for dealing with older versions until sufficient time has passed (usually years) and said conditionals become a nuisance.
Having two different swank implementations for older and newer ABCLs seems worse than conditionals in terms of maintenance costs. swank-sbcl.lisp contains various tricks for making conditionals more manageable. Perhaps some of those practices might help in this case?
-- Luís Oliveira http://kerno.org/~luis/
armedbear-devel@common-lisp.net