9. Simplifying Logging with a Macro
One of the distinguishing characteristics of a Lisp-language like Clojure is the parenthesis. The benefit of this is minimal syntax, where everything is a list. Xerox Parc alumni and Apple Fellow Alan Kay called this characteristic a homoiconic language. In addition to simple syntax, we can treat code as data and data as code. One of the primary means to treat code as data is a macro.
In this chapter we’ll give you some examples of how you can use macros in your day-to-day work. We’ll start with a logging application and then look at a more advanced use in the next chapter. Note that there are better ways to achieve both these goals in Clojure, and we’ll mention those as well. The point is being able to recognize the use case where a macro would be useful, and then knowing how to apply Clojure to that use case.
Assumptions
In this chapter we make the following assumptions:
You have Leiningen installed.
You are ready for the idea that macros are easily overused and should be used sparingly.
Benefits
The primary benefit of macros is the ability to extend the compiler. The two features that macros have that functions do not are that
they don’t automatically evaluate their arguments and
macros can evaluate their contents at macro-expansion time or at runtime.
1. Create a new Leiningen project logging-macro-demo in your projects directory, and change to that directory:
lein new app logging-macro-demo
cd logging-macro-demo
2. Modify the file project.clj to look like the following:
(defproject logging-macro-demo "0.1.0-SNAPSHOT"
:dependencies [[org.clojure/clojure "1.7.0-beta2"]
[org.clojure/math.numeric-tower "0.0.4"]
[clojurewerkz/money "1.6.0"]]
:main ^:skip-aot logging-macro-demo.core
:target-path "target/%s"
:profiles {:uberjar {:aot :all}})
3. Enter the following into the file src/logging_macro_demo/core.clj:
(ns logging-macro-demo.core
(:require [clojure.math.numeric-tower :as math]
[clojurewerkz.money.amounts :refer [amount-of]]
[clojurewerkz.money.currencies :refer [USD]]
[clojurewerkz.money.format :as mf])
(:gen-class))
(defn round
"Given value and a precision return a rounded number."
[d precision]
(let [factor (Math/pow 10 precision)]
(/ (Math/floor (* d factor)) factor)))
(defn format-currency
"Do decimal currency formatting using the
Clojurewerkz/Joda currency library."
[input] (mf/format (amount-of USD (round input 2))))
(def balances [3367.01 7839.76 326478.01 23479.15])
(defn indices
"Given a predicate function and a collection, return a list of collection
indexes that satisfy the predicate."
[pred coll]
(keep-indexed #(when (pred %2) %1) coll))
(defmacro my-debug
"Call with a function definition and this will add logging to the start and
end."
[arg]
(let [param-index (first (indices vector? arg))
first-half (take (inc param-index) arg)
body (drop (inc param-index) arg)
func-name (second arg)
params (nth arg param-index)
new-print-args-statement `(println (str "(" '~func-name " " ~params
")"))
last-statement (take-last 1 body)
body-remainder (drop-last 1 body)
print-last-statement `(println (str '~func-name " result: " ~(first
last-statement)))
new-function (concat first-half
(list new-print-args-statement)
body-remainder
(list print-last-statement)
last-statement)]
`(do
(println "param-index: " ~param-index)
(println "first-half: " ~first-half)
(println "body: " '~body)
(println "func-name: " '~func-name)
(println "params: " '~params)
(println "new-print-statement: " '~new-print-args-statement)
(println "last-statement: " (first '~last-statement))
(println "body-remainder: " ~body-remainder)
(println "print-last-statement: " '~print-last-statement)
(println "new-function: " '~new-function)
(eval '~new-function))))
(my-debug (defn add-meaning "Douglas Adams reference" [arg] (+ 42 arg)))
(defmacro my-debug-sm
"Call with a function definition and this will add logging to the start and
end."
[arg]
(let [param-index (first (indices vector? arg))
first-half (take (inc param-index) arg)
body (drop (inc param-index) arg)
func-name (second arg)
params (nth arg param-index)
new-print-args-statement `(println (str "(" '~func-name " " ~params
")"))
last-statement (take-last 1 body)
body-remainder (drop-last 1 body)
print-last-statement `(println (str '~func-name " result: " ~(first
last-statement)))
new-function (concat first-half
(list new-print-args-statement)
body-remainder
(list print-last-statement)
last-statement)]
`(do
(eval '~new-function))))
(my-debug-sm (defn apply-interest
"Compound interest formula."
[years interest-rate input-balance]
(* input-balance (math/expt (+ 1 (float interest-rate)) years))))
(my-debug-sm (defn round-and-format
"Set decimal places and currency formatting."
[val]
(format-currency (round val 2))))
(def apply-interest-curry (partial apply-interest 1 0.4 ))
(defn -main
"Run the macro demo for function logging by a syntax tree walk."
[& args]
(println (add-meaning 1))
(println (map round-and-format
(map apply-interest-curry balances))))
Testing the Solution
To test the solution, run the following on the command line from the project directory:
lein run
You should get the following result:
param-index: 3
first-half: #'logging-macro-demo.core/add-meaning
body: ((+ 42 arg))
func-name: add-meaning
params: [arg]
new-print-statement: (clojure.core/println (clojure.core/str ( (quote add-
meaning) [arg] )))
last-statement: (+ 42 arg)
body-remainder: ()
print-last-statement: (clojure.core/println (clojure.core/str (quote add-meaning)
result: (+ 42 arg)))
new-function: (defn add-meaning Douglas Adams reference [arg] (clojure.core/
println (clojure.core/str ( (quote add-meaning) [arg] ))) (clojure.core/println
(clojure.core/str (quote add-meaning) result: (+ 42 arg))) (+ 42 arg))
(add-meaning [1])
add-meaning result: 43
43
((apply-interest [1 0.4 3367.01])
apply-interest result: 4713.814020068944
(apply-interest [1 0.4 7839.76])
apply-interest result: 10975.66404672861
(apply-interest [1 0.4 326478.01])
apply-interest result: 457069.2159459606
(apply-interest [1 0.4 23479.15])
apply-interest result: 32870.81013994664
(round-and-format [4713.814020068944])
round-and-format result: $4,713.81
(round-and-format [10975.66404672861])
round-and-format result: $10,975.66
(round-and-format [457069.2159459606])
round-and-format result: $457,069.21
(round-and-format [32870.81013994664])
round-and-format result: $32,870.81
$4,713.81 $10,975.66 $457,069.21 $32,870.81)
What we see here in the first half (up to and including 43) is the call to the first version of our debug macro—with a simple function that adds 42 to a number passed to it. What we see is the process by which this version of the macro breaks up the function passed to it into components and then splices in two sets of logging, one at the start to show the input arguments and one at the end to print the result.
The second half of what we see here is a simplified version of our macro, with less logging, but applied to a more complex scenario. We take two functions we have applied our simplified logging macro to, a compound interest function and a formatting function. We map the compound interest function over a vector of balances where we see in our logs above apply-interest, and then we see the formatting mapped over it again for the round-and-format. In both cases, we see the input arguments and result of each function call.
[org.clojure/math.numeric-tower "0.0.4"]
[clojurewerkz/money "1.6.0"]]
The numeric-tower library gave us access to the functions math/expt that we used in the apply-interest function and the round function.
The ClojureWerkz money library gave us access to the functions mf/format and amount-of, and the USD value used in our dollars function for currency formatting.
In our file src/logging_macro_demo/core.clj the namespace declaration pulls in the numeric-tower library used for our apply-interest and round functions. The file also pulls in several different parts of the clojurewerkz.money library that we use for the format-currency function. It also finishes with a gen-class keyword used when this library is packaged to create a compiled Java class for this namespace.
Next we added functions for rounding values and formatting currency, round and format-currency. Then we added a list of balances to apply our compound interest calculation to balances. Next we added a function indices to return the indexes of a predicate in a collection. We use this in our parsing macro to work out where the argument vector is, in case the function has a docstring.
Our first debug macro, mydebug, is something of a monster. It is very long in order to explicitly lay out each step of parsing the function declaration. The macro is split in half, with a large let-block taking up the first half, and println function calls showing all the steps in the second half. (In the second version of this macro, we will leave out all the println calls because they create a lot of noise.) The final part of the function is the eval, which runs the new spliced-together version of the macro we have constructed.
In the first third of the let-block (up to new-print-args-statement) we parse out the argument vector, then create a println statement that prints these values, so we can insert it as the first line in the function.
In the second third of the let-block, we do a similar thing with the last line of the function by creating a println function call that prints this value. This will be inserted on the next-to-last line of the function definition.
In the last third of the let-block, we splice it all together with
the function header,
the println showing arguments,
the body of the function apart from the last line,
the println statement showing the last line, and
the final result.
This macro has taken an unevaluated function definition as an argument and modified it slightly to add debugging information about the inputs and outputs.
To test this, we use a macro-call passing in a function add-meaning that adds 42 to the number passed in. We see this function at work with the call to add-meaning with the function call in the –main function:
(println (add-meaning 1))
This gives the following result:
param-index: 3
first-half: #'logging-macro-demo.core/add-meaning
body: ((+ 42 arg))
func-name: add-meaning
params: [arg]
new-print-statement: (clojure.core/println (clojure.core/str ( (quote add-
meaning) [arg] )))
last-statement: (+ 42 arg)
body-remainder: ()
print-last-statement: (clojure.core/println (clojure.core/str (quote add-meaning)
result: (+ 42 arg)))
new-function: (defn add-meaning Douglas Adams reference [arg] (clojure.core/
println (clojure.core/str ( (quote add-meaning) [arg] ))) (clojure.core/println
(clojure.core/str (quote add-meaning) result: (+ 42 arg))) (+ 42 arg))
(add-meaning [1])
add-meaning result: 43
43
In this we see the location of the parameter index 3. We see the body of the function with ((+ 42 arg)). We get the function name and the list of arguments. We then see the println statement with a str function call the list of arguments expanded to show the full namespaces. We then see the last statement in the function (+ 42 arg). We see the body before the last statement, in this case an empty set of parentheses. We then see a new println statement to be added before the last statement. Then we see the fully spliced-together function. After that we see the function call showing the parameters, the function result, and the results of the println in the –main function, 43.
Next we take the same function my-debug and remove all the println macro logging to remove the noise to create my-debug-sm.
Next we’ll test this out with two function declarations, apply-interest for compound interest and round-and-format for formatting decimals into currency:
Now we want to run our functions that have been run through our macro through a map function. Normally we’d just declare a function in-line using the # reader macro. In this case this will trip up the map function. Instead we’ll curry our function call using the higher order function partial. We do this in the def apply-interest-curry.
The function partial returns a function that wraps the function call that will apply any additional arguments passed in to the rest of the function. Perfect for when it is called by map and passed in a single argument.
Finally, we have our –main function, which is called by the Leiningen project.clj. This is called when we run lein run on the command line. On the first println statement we call our add-meaning function above that gives the full breakdown of how the function works. On the second println we map our apply-interest-curry partial over the balances. This gives us the middle set of results:
((apply-interest [1 0.4 3367.01])
apply-interest result: 4713.814020068944
(apply-interest [1 0.4 7839.76])
apply-interest result: 10975.66404672861
(apply-interest [1 0.4 326478.01])
apply-interest result: 457069.2159459606
(apply-interest [1 0.4 23479.15])
apply-interest result: 32870.81013994664
Then we use map again over the results of this to format the results using round-and-format, and we see the final set of results like this:
(round-and-format [4713.814020068944])
round-and-format result: $4,713.81
(round-and-format [10975.66404672861])
round-and-format result: $10,975.66
(round-and-format [457069.2159459606])
round-and-format result: $457,069.21
(round-and-format [32870.81013994664])
round-and-format result: $32,870.81
In this we see the inputs and outputs each time the function is mapped over.
Finally, we see our results returned from the println statement in the –main function:
$4,713.81 $10,975.66 $457,069.21 $32,870.81)
Not bad for a day’s work.
Conclusion
We’ve looked at the benefits of code as data and data as code in a language like Clojure, and we’ve applied our knowledge of macros to solve two problems. We looked at using macros to add logging to a function we were debugging.
As a side note, two classic uses of macros in Clojure, logging and database transactions, are also classic use cases for Aspect Orientation when using an Object-Oriented language like Java. Other use cases for macros would map to situations where you might do code generation in Java, or just where you want to add a new syntax feature to your Clojure code (which isn’t possible in Java; you’ll have to wait until they release a new version).
In your day-to-day work in Clojure, this wouldn’t be your go-to solution. Instead you’d use the trace1 macro from tools.trace. The point is to have an understanding of the uses and limits of macros.
1. Trace is available for download and instructions for use are at https://github.com/clojure/tools.trace.