November 7, 2017

Debugging made simple

  1. Printing to the console (yes, really)
  2. The environment
    1. The REPL
    2. The parentheses
  3. When printing just doesn't cut it: The Debug Atom
  4. A library is born
  5. Conclusion
  6. Further reading

A common question for people comming to clojure is "How do I figure out what's wrong with my code?", and while there are step debuggers and whatnot, I don't tend to use them. In ruby I do, and anyone coming from ruby is probably gonna ask:

Where's my binding.pry?!

Have you tried ...?

Printing to the console (yes, really)

In pure clojure/clojurescript, the "stuff" in the program is mostly represented by the built-in edn types, everything from users, sku's and line items to html to clojure code itself to the ast in the clojurescript compiler.

Because they are all immutable and have a literal representation, you usually get really far by simply printing the thing you're unsure about.

If I have a frobnicate function I can check what is being passed to it:

(defn frobnicate [user]
  (prn user)
  ;; code
  )

;; Prints something like
{:user/email "fulano@example.com",
 :user/roles #{:admin :user}
 :user/scores [42 12]}

;; Note: prn is for printing so it can be read back by the clojure reader,
;;       so for debugging you should use prn instead of println.

Which is nice, but prn returns nil and the thing we're unsure of what is is not always in an implicit do.

(defn parse-post
  [meta content]
  (let [[foo post] (do-stuff something meta content)
    (merge foo (frobnicate bar post))))

I suspect that there's something off about what frobnicate returned here, but to print that out to the console I have to re-order my code. If I re-order my code, there's a chance that I'll accidentally change it's meaning.

It'd be nice to work around that somehow.

(defn p< [x] (prn x) x)

(defn parse-post
  [meta content]
  (let [[foo post] (do-stuff something meta content)]
    (merge foo (p< (frobnicate bar post)))))

Now I can see what frobnicate returned, and my code didn't change its meaning.

Sometimes you want to know about two things somewhere in the code, or even more things, and it'd be nice to label them so you can tell them apart at the repl.

(defn p<
  ([x] (prn x) x)
  ([msg x] (prn msg) (p< x)))

(defn parse-post
  [meta content]
  (let [[foo post] (p< "do-stuff => " (do-stuff something meta content))]
    (merge foo (p< "frobnicate => " (frobnicate bar post)))))

A surprisingly large amount of the time, that's all it takes. It's usually the first thing I do to test my assumptions about a piece of code.

Again, this is different from doing println(foo.frobnicate(bar)) in java. If something is represented with the standard EDN data-structures you can know everything about them by just reading what's printed and in idiomatic clojure almost everything is just EDN.

This debugging method being effective depends on the dev environment fulfilling some basic requirements though, so let's take a quick detour and talk about that.

The environment

The REPL

Like Stuart Halloway explains in his post, what I think of as repl driven development is to have a repl with my whole program loaded that's connected to my editor with at least two operations I can do from within my source file.

  • Evaluate file
  • Evaluate last form (what comes immediately before my cursor)

This should be possible to set up in any clojure editor/IDE, it's not just for emacs cultists.

The way I usually develop is by having the source file open in one window/tab (frame in emacs) and a repl connected to it open in another. I don't type in the repl itself, I interact with it by writing code directly in the file and executing parts of it.

(ns foo.core
  (:require
   [clojure.string :as str]))

;; I put things that are starting to take shape at
;; the top level of the file.

(defn do-something [& xs]
  (filterv even? xs))

(defn transmogrify [x]
  (->> (iterate (partial + 3) x) (take 3) (apply do-something)))

(comment

  ;; Things that are more experimental live wrapped inside of a comment
  ;; macro. That way I can evaluate the whole file without stuff blowing up.

  ;; This is what I would otherwise write in the repl prompt.
  ;; Things like getting some data to mess around with.
  (def some-data (slurp "https://example.com"))

  ;; I build my functions up bit by bit.
  (->> (iterate (partial + 3) 39) (take 3))

  ;; And put put my cursor at the end of of code I want to try out
  ;; and hit evaluate last form.
  ;; The result is shown right there, inside the file.
  ;; (The cursor is represented by |)
  (->> (iterate (partial + 3) 39) (take 3))| => (39 42 45)

  ;; I print stuff in the repl if it's big, or something
  ;; I want to remember.
  (prn (do-something (re-seq #"\d+" some-data)))

  ;; It's very easy, after poking at my functions like this,
  ;; to solidify this experimentation into tests.

  ;; I see that it does what it's supposed to do
  (transmogrify 39) | => [42]

  ;; So before I commit I copy this into test/foo/core-test.clj as
  (is (= [42] (transmogrify 39)))

  ;; I usually remove this part before committing, but sometimes
  ;; leaving a part of it can help explain something to future readers.

  )

Your mileage may vary, but I find this way of working to be Very Nice.

The parentheses

The other thing that you need is something that manages both your parens and indentation for you. In my opinion this is not optional in a lisp.

If you're starting out it'll feel really strange for a little while, not very long, and you'll forever thank yourself when it starts to feel natural.

If you think paredit is not for you then you need to become the kind of person that paredit is for.

The parens are how the editor knows the structure of your code and the indentation is how you visualize the nesting.

When you auto-indent, you can see if the nesting is wrong by looking at the indentation. Also you'll learn to properly format the code so it's easy for people to understand.

Now, as with most things, your mileage may vary. You might be perfectly happy with the hack, compile, run cycle and love manually balancing parentheses. And that's fine. These techniques just won't work as well.

When printing just doesn't cut it: The Debug Atom

Sometimes it's not enough just to look at something, you want to poke at it as well. Maybe it's some opaque java object. Maybe it's very big and impractical to print. A nice approach to this is the "debug atom" pattern.

(def a (atom ::nothing))

;; Again I want to know what the call to frobnicate returns
(defn parse-post
  [meta content]
  (let [[foo post] (do-stuff something meta content)]
    (merge foo (reset! a (frobnicate bar post)))))

(comment
  ;; Now I can access the return value from frobnicate here
  @a
  )

reset! returns the value it puts into the atom, so we can just wrap it around things right out of the box without changing the meaning of our code. That's nice.

Notice how the atom starts out with a namespaced keyword inside. That's to distinguish between frobnicate returning nil and not getting called at all.

If you want to know more than one value, you can simply use more than one atom.

(def do-stuff-a (atom ::nothing))
(def frobnicate-a (atom ::nothing))

(defn parse-post
  [meta content]
  (let [[foo post] (reset! do-stuff-a (do-stuff something meta content))]
    (merge foo (reset! frobnicate-a (frobnicate bar post)))))

(comment
  @do-stuff-a
  @frobnicate-a
  )

And voila, a minimal complexity, vanilla clojure(script) alternative to debuggers.

A library is born

Multiple debug atoms are slightly verbose though, and I've typed the characters (defn p< [x] (prn x) x) way too many times.

So I wrote a tiny library. The current version is [madstap/hugin "0.1.4"].

It's called hugin after one of the norse god Odin's ravens. They fly around the world gathering information, then report it back to him.

The debug atom setup it uses is slightly different:

(ns hugin.dbg)

(defonce a (atom {}))

(defn a<
  ([x] (a< ::default x))
  ([k x]
   (swap! a assoc k x)
   x))

(defn a>
  ([] (a> ::default))
  ([k] (get @a k ::nothing)))

(defn nuke []
  (reset! a {}))

There is only one atom, with functions wrapping the access to it. This makes it less verbose which is especially nice for debugging. It also makes it possible to have a nuke function that resets everything.

If I want a single value I can do that:

(ns foo.core
  (:require
   [hugin.dbg :as dbg]))

(defn parse-post
  [meta content]
  (let [[foo post] (do-stuff something meta content)]
    (merge foo (dbg/a< (frobnicate bar post)))))

(comment
  (dbg/a>)
  )

Or multiple values:

(defn parse-post
  [meta content]
  (let [[foo post] (dbg/a< :do-stuff (do-stuff something meta content))]
    (merge foo (dbg/a< :frobnicate (frobnicate bar post)))))

(comment
  (dbg/a> :do-stuff)
  (dbg/a> :frobnicate)
  )

Sometimes you want to know about a succession of values. Inside a of a reduce or a loop. The things coming off of a core.async channel. Maybe you're making a webapp and want to see the succession of requests to a specific endpoint.

Hugin has got you covered. (He is a nice raven.)

(ns hugin.dbg)

,,,

;; This could do with a better name,
;; please don't hesitate to suggest one in the comments.
(defn aconj<
  ([x] (aconj< ::default x))
  ([k v]
   (swap! a update k (fnil conj []) v)
   v))

And it is used like this:

(defn do-things [xs]
  (reduce (fn [acc x]
            (merge acc (dbg/aconj< (do-stuff x))))
          {}, xs))

(comment
  ;; Now this returns a vector of all the return values
  ;; from calling (do-stuff x) for each x
  (dbg/a>) ;=> [,,,]
  )

It also combines nicely with transducers.

(def foo-xf
  (comp (map frobnicate)
        (map dbg/aconj<)
        (filter odd?)))

(comment
  ;; Returns a vector of the things that passed through foo-fx
  (dbg/a>) ;=> [,,,]
  )

Conclusion

A little clojure goes a long way, and this is true of debugging as much as anything. The combination of immutable values, data structure literals and the fact that almost everything in clojure is an expression that returns a value (modulo syntax inside macros) is what makes this possible.

The way that reset! works out of the box for this kind of debugging is very nice, and the rest of the stuff in this post and in hugin is trivial to implement.

I hope that this post adds to the common knowledge available on this subject. If you haven't already you should check out the other blog posts listed below, they're all well written and add talk about different aspects of debugging.

Further reading

Tags: clojure debugging