Anyone understand the logic of pushJavaStackFrames
Mark Evenson
evenson at panix.com
Sun Jan 1 11:11:34 UTC 2017
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."
More information about the armedbear-devel
mailing list