Pretty-printing in Clojure logs

Cross-posted from Zolo Labs.

Logging is an obvious requirement when it comes to being able to debug non-trivial systems. We’ve been thinking a lot about logging, thanks to the large-scale, distributed nature of the Zolodeck architecture. Unfortunately, when logging larger Clojure data-structures, I often find some kinds of log statements a bit hard to decipher. For instance, consider a map m that looked like this:

{:a 1,
:c {:a 1, :c {:a 1, :b 2}, :b 2},
:b [2 3],
:d [{:a 1, :c 3, :b 2} {:a [1 2 3], :b {:a 1, :b 2}}]}

view raw
m.clj
hosted with ❤ by GitHub

When you log things like m (shown here with println for simplicity), you may end up needing to understand this:

user> (println m "blah blah" m)
{:a 1, :c {:a 1, :c {:a 1, :b 2}, :b 2}, :b [2 3], :d [{:a 1, :c 3, :b 2} {:a [1 2 3], :b {:a 1, :b 2}}]} blah blah {:a 1, :c {:a 1, :c {:a 1, :b 2}, :b 2}, :b [2 3], :d [{:a 1, :c 3, :b 2} {:a [1 2 3], :b {:a 1, :b 2}}]}

view raw
m_printed.clj
hosted with ❤ by GitHub

Aaugh, look at that second line! Where does the data-structure begin and end? What is nested, and what’s top-level? And this problem gets progressively worse as the size and nested-ness of such data-structures grow. I wrote this following function to help alleviate some of the pain:

(defn pp-str [& things]
(let [s (with-out-str (pprint things))]
(-> s
(.substring 0 (-> s .length dec dec))
(.replace "(" " ")
(str "\n"))))

view raw
pp_str.clj
hosted with ❤ by GitHub

Remember to include clojure.pprint. And here’s how you use it:

user> (println (pp-str m "blah blah" m))
{:a 1,
:c {:a 1, :c {:a 1, :b 2}, :b 2},
:b [2 3],
:d [{:a 1, :c 3, :b 2} {:a [1 2 3], :b {:a 1, :b 2}}]}
"blah blah"
{:a 1,
:c {:a 1, :c {:a 1, :b 2}, :b 2},
:b [2 3],
:d [{:a 1, :c 3, :b 2} {:a [1 2 3], :b {:a 1, :b 2}}]}

view raw
pp_str_usage.clj
hosted with ❤ by GitHub

That’s it, really. Not a big deal, not a particularly clever function. But it’s much better to see this structured and formatted log statement when you’re poring over log files in the middle of the night.

Just note that you want to use this sparingly. I first modified things to make ALL log statements automatically wrap everything being logged with pp-str: it immediately halved the performance of everything. pp-str isn’t cheap (actually, pprint isn’t cheap). So use with caution, where you really need it!

Now go sign-up for Zolodeck!

One thought on “Pretty-printing in Clojure logs

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s