debugging, logging, ... and code sections

[Frantisek Sodomka]

Hello!
It is very common pattern to include parts of code which are used for
specific purposes - for example debugging, logging, etc. While these parts
can be used when developing code, they can be removed from finished
application. One way is to comment these parts out, when we are done.
Since commenting can be tedious and error-prone, it makes sense to make a
macro for this:

(def *debug* true) ; true/false

(defmacro debug [& body]
(if *debug*
`(do ~@body)))

(defn myfn [x]
(debug
(println "Print some debug info...")
(print "x = ") (prn x))
(* 2 x))

(myfn 5)

To extend this idea little further, lets define "code sections":

(def *section-tags* {:debug true :log0 true :log1 false})

(defmacro section [tag & body]
(if (*section-tags* tag)
`(do ~@body)))

(defn myfn [x]
(section :debug
(println "debugging info...")
(print "x = ") (prn x))
(section :log0
(println "logging info..."))
(section :log1
(println "detailed logging info..."))
(* 2 x))

(myfn 10)

Latest addition for libs to boot.clj also has this pattern, when using
*loading-verbosely* flag.

Any comments welcome, Frantisek

[Parth Malwankar]

I like something along the lines of Python decorators[1] as
that keeps the logic of the function from being lost in the
instrumentation code.

E.g.
(def *verbose* true)

(defn print-decorate [f]
(fn [& args]
(println f "called with" args)
(apply f args)))

(defn foo [x] (* 2 x))

(when *verbose*
(def foo (print-decorate foo)))

With *verbose* true:

user=> (load-file "foo.clj")
#'user/foo
user=> (foo 2)
user.foo__2372@5388b5 called with (2)
4

With *verbose* false:

user=> (load-file "foo.clj")
nil
user=> (foo 2)
4

Perhaps this approach can be improvised further but
I myself am somewhat of a Clojure noob.

I suspect the boot.clj code (especially in the early part of
the file) may not be most ideomatic Clojure code as
Clojure is still booting itself.

On a somewhat related note. Getting the function name at the
Clojure prompt seems to work:

user=> (:name (meta (var foo)))
foo

However if I try to improvise print-decorate by putting
in the above approach, I get an exception while loading
the file.

(defn print-decorate [f]
(fn [& args]
(println (:name (meta (var f))) "called with" args)
(apply f args)))

clojure.lang.Compiler$CompilerException: foo.clj:5: Unable to resolve
var: f in
this context

Could someone explain what I am doing wrong here?
How can I get the function name at runtime in print-decorate?

Full exception log below.

Parth
[1] http://www.ibm.com/developerworks/linux/library/l-cpdecor.html

user=> (load-file "foo.clj")
java.lang.Exception: Unable to resolve var: f in this context
clojure.lang.Compiler$CompilerException: foo.clj:5: Unable to resolve
var: f in this context
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3821)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyze(Compiler.java:3627)
at clojure.lang.Compiler.access$100(Compiler.java:37)
at clojure.lang.Compiler$InvokeExpr.parse(Compiler.java:2630)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3816)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyze(Compiler.java:3627)
at clojure.lang.Compiler.access$100(Compiler.java:37)
at clojure.lang.Compiler$InvokeExpr.parse(Compiler.java:2630)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3816)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyze(Compiler.java:3627)
at clojure.lang.Compiler.access$100(Compiler.java:37)
at clojure.lang.Compiler$InvokeExpr.parse(Compiler.java:2630)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3816)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyze(Compiler.java:3627)
at clojure.lang.Compiler.access$100(Compiler.java:37)
at clojure.lang.Compiler$BodyExpr$Parser.parse(Compiler.java:
3340)
at clojure.lang.Compiler$FnMethod.parse(Compiler.java:3187)
at clojure.lang.Compiler$FnMethod.access$1200(Compiler.java:
3098)
at clojure.lang.Compiler$FnExpr.parse(Compiler.java:2729)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3812)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3804)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyze(Compiler.java:3627)
at clojure.lang.Compiler.access$100(Compiler.java:37)
at clojure.lang.Compiler$BodyExpr$Parser.parse(Compiler.java:
3340)
at clojure.lang.Compiler$FnMethod.parse(Compiler.java:3187)
at clojure.lang.Compiler$FnMethod.access$1200(Compiler.java:
3098)
at clojure.lang.Compiler$FnExpr.parse(Compiler.java:2729)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3812)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3804)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.access$200(Compiler.java:37)
at clojure.lang.Compiler$DefExpr$Parser.parse(Compiler.java:
335)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3814)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3804)
at clojure.lang.Compiler.analyze(Compiler.java:3654)
at clojure.lang.Compiler.analyze(Compiler.java:3627)
at clojure.lang.Compiler.eval(Compiler.java:3851)
at clojure.lang.Compiler.load(Compiler.java:4136)
at clojure.lang.Compiler.loadFile(Compiler.java:4103)
at clojure.lang.RT$3.invoke(RT.java:285)
at user.eval__2409.invoke(Unknown Source)
at clojure.lang.Compiler.eval(Compiler.java:3847)
at clojure.lang.Repl.main(Repl.java:75)
Caused by: java.lang.Exception: Unable to resolve var: f in this
context
at clojure.lang.Compiler$TheVarExpr$Parser.parse(Compiler.java:
457)
at clojure.lang.Compiler.analyzeSeq(Compiler.java:3814)
... 50 more

[Frantisek Sodomka]

I found that Rich wrote a simple tracing facility:
http://groups.google.com/group/clojure/browse_frm/thread/fd315d9dfdb8c32c/7479682cdf3a1b97

What I had in mind is to literally turn on and off parts of code. This way
I can play with design by contract:

(def *section-tags* {:require true})

(defmacro section [tag & body]
(if (*section-tags* tag)
`(do ~@body)))

(defn mysqrt [x]
(section :require
(if (< x 0)
(throw (new Exception "mysqrt: x >= 0"))))
(Math/sqrt x))

----

user=> (mysqrt 2)
1.4142135623730951

user=> (mysqrt -1)
java.lang.Exception: mysqrt: x >= 0

Frantisek

[Meikel Brandmeyer]

Hello Parth,

> (defn print-decorate [f]
> (fn [& args]
> (println (:name (meta (var f))) "called with" args)
> (apply f args)))

f is not a toplevel binding, but only a local variable. This is the
issue here,
I think. Please try the following.

> (defn print-decorate [f]
> (fn [& args]

> (println (:name (meta f)) "called with" args)
> (apply (var-get f) args)))

This has to be called with the Var not the function itself. It gives me:

---8<---
foo=> (defn bar [x] x)
#'foo/bar
user=> (foo/bar 5)
5
user=> (def bar (print-decorate #'foo/bar))
#'user/bar
user=> (bar 5)
bar called with (5)
5
---8<---

Please note also the namespace change in between! :)

Sincerely
Meikel

[Stephen C. Gilardi]

On Aug 31, 2008, at 4:34 AM, Frantisek Sodomka wrote:

To extend this idea little further, lets define "code sections":

I like the idea a lot. I believe the "Aspect oriented programming" folks call these kinds of "outside the main flow" items "aspects". I think it would be good to have aspects defined in each namespace rather than globally.  (One might also argue for "in addition to" globally.)

Here's an "aspects.clj" that resolves '+aspects+ at "compile time" in the namespace where the function that uses it is defined:

(ns aspects)

(defmacro aspect [tag & body]

  (when-let aspects# (ns-resolve *ns* '+aspects+)

    (when (aspects# tag)

      (cons 'do body))))

And a test:

(ns aspects.test

 (:use aspects))

(def +aspects+ #{:debug :log0 :log1})

(defn myfn [x]

  (aspect :debug

          (printf "debugging info... (x = %s)\n" x))

  (aspect :log0

          (println "logging info..."))

  (aspect :log1

          (println "detailed logging info..."))

  (* 2 x))

(myfn 10)

And a run:

user=> (require 'aspects.test :reload-all)

debugging info... (x = 10)

logging info...

detailed logging info...

nil

user=>

The code is written such that if +aspects+ is not defined in a namespace, calls to "aspect" in that namespace generate no code. One cool thing this leverages in Clojure is that +aspects+ can be either a set (as shown) or a map from keyword to (generalized) boolean.

Latest addition for libs to boot.clj also has this pattern, when using *loading-verbosely* flag.

That's a little different in that *loading-verbosely* is intended to be dynamically bound at runtime rather than baked in at compile time. I recall Rich suggesting recently that he prefers to see the * prefix and suffix on symbols that are intended to be dynamically bound. Here I'm suggesting that a + prefix and suffix be used for compile-time constants. I've seen precedent for in Common Lisp.

Any comments welcome, Frantisek

I think this is a fine idea that deserves some more discussion and would make a good addition to clojure-contrib. Are you signed up to contribute there yet?

--Steve

[Frantisek Sodomka]

Yes, the name and semantics of aspects fits for it more. I like that. I am
going to sign up for contributing soon.

I am low on time currently, so feel free to extend this idea further. As
soon as Rich gets agreement, you can use it :-)

Frantisek