While debugging Clojure can be tough, its macro capabilities and its fast edit-rerun cycle in the REPL can give you enhanced insight into exceptions and traces.
In this post, I want to share some notes from my own experience debugging Clojure programs.
Then to try how it works, we load the file into the REPL and type the following [1] :
Uh oh. There are two problems here. First, what does this error message mean? What’s ISeq and what’s java.lang. Long? Second, it’s not clear where it is actually failing (thanks for that pointer to RT.java though, Clojure!) Let’s address the second problem first. The magic incantation to show the stack trace of the last exception is calling the pst function:
So now things become more clear. The call (first n) must be bad, and bad in a way that tries to coerce clojure into creating an ISeq from a Long. In other words, we’re passing a number into a function that expects a sequence, and this is, indeed, bad. Learning to map from Clojure values and types to the JVM’s expectations will take time and grit – especially if you (like me) don’t have much Java experience. I suggest doing a bit of reading on Clojure/Java interoperability, and about other Java-isms Clojure inherits; it ain’t pretty, and you may not always want to use it, but being familiar with the terms can go a long way in deciphering cryptic stack traces.
For a more detailed treatment of this debugging issue, I highly recommend Aphyr’s article on debugging Clojure .
Let’s invoke the foo function in a different way that demonstrates another issue with debugging Clojure:
OK, we know what to do next:
So the exception comes from line 9, which is:
This exception also tells us it comes from clojure.lang. Numbers.gt from which we can infer it’s the > operator that is complaining. But imagine for a second that we had two forms with the same operator on that line:
If we got a NullPointerException about an addition, we wouldn’t know which one fails. Luckily, Clojure comes with a very useful module that helps debugging – tools.trace. In this particular case, we’d use the trace-forms macro which tells us which nested form (expression) is failing. We can modify our function to be:
And now when called with nil, we get:
This gets us into the more general domain of debugging, where the tricks and tools programmers use are as varied as the bugs hiding in our programs. When it comes to debugging, I’m firmly in the printf camp; I rarely prefer debuggers over printf-based debugging [3] , and Clojure is no exception. In fact, due to the way Clojure programs look (nested forms) , I find that debuggers are even less useful in Clojure than in other languages. On the other hand, Clojure’s macros make it possible to trace/print stuff in a very nice way.
For example, I find that it’s useful to be able to turn debugging printouts on and off frequently. So I have this trusty code in my utilities:
Calls to printfv can be freely scattered around the code; by default, they will not print anything. When I do want to see what these printfvs have to say, another macro comes useful:
Here’s how it works; Suppose we’ve written this factorial function, with a debugging printout:
Now, if we just call it as usual from the REPL, we get:
But if we want to actually see the debugging output, we call:
This optional verbosity is perfect when you’re in the middle of a furious bug hunt, adding printfvs in many places in your code. with-verbose can turn verbose logging on selectively and control the amount of debugging spew [4] .
This example brings us back to the tools.trace library, which provides another awesome tool that helps trace function calls (the bread and butter of Clojure programs) . Enter trace-vars. After importing it, all we need to do is invoke it on any functions we want traced; for example:
And now invoking our factorial produces:
We get to see the full call tree, including values of parameters and what each call returns. It even works for mutually-recursive functions:
Let’s try it:
Note how easy it to see what calls what. Quite often, bugs are uncovered simply by carefully studying the chain of function calls some input tickles in our code, and trace-vars is a very low-effort method to enable this kind of debugging.
Tracing function calls is great, but sometimes insufficient. It’s not uncommon to have cond forms in functions, and sometimes it’s pretty hard to know which condition was actually “taken” (this isn’t always easy to infer from the return value of the function) . We’ve seen how to explore where exceptions come from with trace-forms, but exceptions are just one kind of problem. The more difficult problem arises when the code throws no exceptions but still produces a wrong value.
I’ve mentioned how Clojure’s macro superpowers let us write very powerful debugging tools. What follows is another example.
Consider this toy code:
It happens to return 10 since the second condition fires. But suppose it stands for a much more complicated cond where it’s not obvious which condition was taken and where the return value came from. How do we go about debugging this?
Well, we can always add a printfv into every result expression (possibly wrapping in a do form) and see what fires. This would work, but it’s quite tiresome, especially for large conds. To do this automatically, we can write the following macro:
It behaves just like cond, while also printing out the condition that fired. If we replace the cond in the original example with condv and evaluate it, we’ll get:
Note the printout before the return value of 10: condv (> 20 10) – it shows us exactly which condition was taken.
While beginning Clojure programmers may find the debugging experience challenging, I believe that with some effort and perseverance it’s possible to get used to the unusual environment and even reach new levels of productivity by developing a set of debugging tools and techniques.
In this endeavor, Clojure’s macro capabilities are an extremely powerful ally.
