Improving Clojure Feedback : Stack Traces
Join the DZone community and get the full member experience.Join For Free
Perhaps no subject in software development is as important to me as feedback, which to my mind, is the language, library, or framework providing information back to the developer when things go wrong. A language, library, or framework that provides poor feedback is creating barriers to its own adoption.
There's a possibly apocryphal legend about early FORTRAN compilers. Back in the day (thankfully, even earlier than my personal back in the day), you would code up your FORTRAN code on punch cards and deliver them to an operator. At some convenient time (for the operator), the compiler would be started and fed the stack of cards. Assuming the cards had not been bent, folded, spindled, or mutilated ... and that the program itself contained no errors, you would get a compiled program somewhere. If anything failed, you would simply get the error message "FAIL". Nothing else.
That's bad feedback.
It's important to feel that you are in control of your own tools; that's part of the love/hate relationship so many developers have with their IDEs: the IDEs certainly enable a lot of productivity ... but what you always end up remembering is when the IDE gets in the way of some really critical, really difficult stuff. Or when it crashes mysteriously at a critical moment. Or when it just won't dosomething and won't tell you why not.
Likewise, any tool (or language, library, or framework) that provides bad feedback, especially when things go wrong, is building a perception that it is hard to use overall. We're a fickle bunch ... we'll be off to find the Next Big Thing instead.
Which brings us to my favorite programming language, Clojure. When things are going right in Clojure they are going very, veryright. However, when things go wrong in Clojure it can be very painful.
First of all, Clojure's basic mechanism for any kind of error is to simply throw an exception. Since Clojure is a Lisp, the difference between compile time and runtime is not so easily distinguished ... a running Clojure program is often loading source and compiling code as well as running the application.
And what happens to exceptions? They are thrown in one piece of code and, more often than not, caught, wrapped, and re-thrown in containing stack frames. Ultimately, this whole stack of exceptions gets spewed out to the console.
This isn't quite bad as that FORTRAN compiler; however, even on my big 30" cinema display, a Clojure compilation failure always sends me scrolling backwards in my terminal window to see the actual error and (with more than a pinch of luck) the file name and line number containing the error.
It's much worse when it comes to runtime failures in my own code; it is likely that the exceptions will be nested even deeper than the number of levels intituted by the Clojure compiler and REPL. Beyond that is the issue of laziness ... program execution goes a little topsy-turvey from your code due to laziness, as what code is executing is typically driven by what particular bit of lazily-computed data is needed at any particular instant. That takes a little getting used to for new Clojure developers.
And so, deep in your code, you passed a string when a keyword was expected, or you passed a map when a seq was expected, or any number of other similar situations ... and now you are faced with an exception and its stack trace.
Here's the ugly not-so-secret of Clojure: it's a light and tasty frosting on top of a cake of sawdust and rusty gears: Java. Every Clojure function must be converted into a Java class in order to execute within the JVM. Java places somewhat arbitrary limits on the class and method names: Where Clojure loves dashes in function names, Java doesn't allow them. Likewise, Clojure loves all kind of other punctuation, with functions named "+" or "string?", that Java forbids as well.
Clojure mangles the Clojure namespace and function names to fit into the Java world, and nothing in the exception reporting chain does anything to make the result any prettier. Here's an example:
user=> (throw (make-exception)) SQLException Database failure SELECT FOO, BAR, BAZ FROM GNIP failed with ABC123 user/jdbc-update (user.clj:6) user=> (.printStackTrace *e) java.lang.RuntimeException: Request handling exception at user$make_exception.invoke(user.clj:30) at user$eval1349.invoke(form-init6244416188680788244.clj:1) at clojure.lang.Compiler.eval(Compiler.java:6619) at clojure.lang.Compiler.eval(Compiler.java:6582) at clojure.core$eval.invoke(core.clj:2852) at clojure.main$repl$read_eval_print__6588$fn__6591.invoke(main.clj:259) at clojure.main$repl$read_eval_print__6588.invoke(main.clj:259) at clojure.main$repl$fn__6597.invoke(main.clj:277) at clojure.main$repl.doInvoke(main.clj:277) at clojure.lang.RestFn.invoke(RestFn.java:1096) at clojure.tools.nrepl.middleware.interruptible_eval$evaluate$fn__765.invoke(interruptible_eval.clj:56) at clojure.lang.AFn.applyToHelper(AFn.java:159) at clojure.lang.AFn.applyTo(AFn.java:151) at clojure.core$apply.invoke(core.clj:617) at clojure.core$with_bindings_STAR_.doInvoke(core.clj:1788) at clojure.lang.RestFn.invoke(RestFn.java:425) at clojure.tools.nrepl.middleware.interruptible_eval$evaluate.invoke(interruptible_eval.clj:41) at clojure.tools.nrepl.middleware.interruptible_eval$interruptible_eval$fn__806$fn__809.invoke(interruptible_eval.clj:171) at clojure.core$comp$fn__4154.invoke(core.clj:2330) at clojure.tools.nrepl.middleware.interruptible_eval$run_next$fn__799.invoke(interruptible_eval.clj:138) at clojure.lang.AFn.run(AFn.java:24) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:724) Caused by: java.lang.RuntimeException: Failure updating row at user$update_row.invoke(user.clj:22) ... 24 more Caused by: java.sql.SQLException: Database failure SELECT FOO, BAR, BAZ FROM GNIP failed with ABC123 at user$jdbc_update.invoke(user.clj:6) at user$make_jdbc_update_worker$reify__170.do_work(user.clj:17) ... 25 more nil user=>
All the information is available ... but you have to work to get at it: You need to mentally de-mangle the Java class names back to Clojure namespaces and function names. You have to ignore a lot of stack frames that are really the infrastructure supporting Clojure on top of Java. You have to assemble the meaningful stack trace (the last and deepest one) from the parts it extends off of the prior stack traces. You have to ignore the numeric ids tacked on to the end of names to help ensure uniqueness.
This is not great feedback.
What if we could provide just a little bit better feedback? What if we could do a lot of that name-demangling automatically, and present the same data in a more helpful way? That's what I've been working on as part of the io.aviso:pretty library for Clojure.
Pretty can be used to format that same exception just a little bit nicer:
The exact format is still in-flux because it is currently so wide; fortunate, the interesting stuff is always to the left!
This same approach appears in the related io.aviso:twixt library, modified to take advantage of how much more richly data can be presented in a web page:
However, this is just the start. Providing truly useful feedback is more than just putting a patch on exception reporting. It requires attention to detail throughout the tool. This has been the case for Apache Tapestry, where a significant amount of the framework is about detecting and reporting errors in a useful way.
Twixt has a set of utilities to address this as well; a way of tracking what the application is doing so that exceptions can be reported. The end result is an "operations trace" that can nest to an arbitrary depth and is used to reconstruct how the application arrived at the point of failure.
This extra layer of code can pay big dividends when things go wrong; the nesting of operations can be critical to understanding the underlying problem; the operations trace combines the very local scope of the failure with a larger scope that explains why the failed code was invoked in the first place.
So I'm very excited by the possibilities, but to provide truly universal, useful feedback in Clojure may not be something that can be effectively added in from the outside: it has to be a priority for the core Clojure developers, and bred into the fabric of the Clojure compiler and runtime. That's something I'd love to see ... or help with.
Published at DZone with permission of Howard Lewis Ship, DZone MVB. See the original article here.
Opinions expressed by DZone contributors are their own.