Lazy-spy: Clojure logging/spy for lazy sequences

May 23, 2010

Clojure.contrib’s logging/spy macro is really useful for quick investigation of bugs with unclear stack traces, and to check that intermediate values in a calculation are being returned and composed correctly. Lazy sequences don’t get logged correctly, however:

> (log/spy [1 2 3 4 5])
[1 2 3 4 5] ;;; prints " [1 2 3 4 5] => [1 2 3 4 5]" to the log
> (log/spy (take 3 [1 2 3 4 5]))
(1 2 3) ;;; prints "(take 3 [1 2 3 4 5]) => clojure.lang.LazySeq@8592" to the log

The spy macro logs a string realization of the sequence per se, rather than its constituents. In the case of a concrete, fully realized sequence such as the literal vector in the first example, all values are known in advance, and the vector’s string realization in the log can helpfully be its actual contents. In the case of the lazy sequence returned by take, however, we get a less than helpful class name and some sort of instance identifier code rather than the actual contents of the sequence. A lazy sequence saves resources by merely promising to provide the values when asked. If they’re never asked for, they’re never computed. Since they haven’t been computed, they can’t be printed. A lazy sequence can also potentially be infinitely long, another good reason why they are not realized by default when converting the sequence to a string.

In our case, we don’t care about the resource usage, and we’re sure the sequence is finite. We want to force all values to be computed for manual inspection. (There are several ways of going about this.) The following modification of the spy macro converts the lazy sequence into a regular seq:

(defmacro lazy-spy
  "Evaluates expr and outputs the form and its result to the debug log.
   If the result is a lazy sequence, it is realized concretely in the log.
   Returns the result of expr."
  [expr]
  `(let [a# ~expr] (log/log :debug (str '~expr " => "
                                    (if (= clojure.lang.LazySeq (class a#))
                                      (seq a#)
                                       a#)))
        a#))

This gives us:

> (lazy-spy  (take 3 [1 2 3 4 5]))
(1 2 3) ;;; prints "(take 3 [1 2 3 4 5]) => (1 2 3)" to the log

Popularity: 20% [?]

tags: ,
posted in Tech by Paul Legato

Follow comments via the RSS Feed | Leave a comment | Trackback URL

Leave Your Comment

 
Copyright © 2009 Paul Legato. All rights reserved. Theme based on Shlomi Noach, openark.org