Friday, April 8, 2011

Debugging with the Clojure Debugging Toolkit

Overview

I use Emacs for my Clojure development, and have been using the Emacs front end to the CDT. The CDT and Emacs lib can be found on github at https://github.com/georgejahad/cdt.

Setup

The CDT requires that the JVM be started with a debugging socket open. I use the clojure-maven-plugin (https://github.com/talios/clojure-maven-plugin) for my build/dependancy managment, and configure the <clojureoptions> to specify the socket port (in this case 8031).

...
    <plugin>
      <groupId>com.theoryinpractise</groupId>
      <artifactId>clojure-maven-plugin</artifactId>
      <version>1.3.6</version>
        <configuration>
          <sourceDirectories>
            <sourceDirectory>src/main/clojure</sourceDirectory>
          </sourceDirectories>
        <clojureOptions>-Xmx1G -agentlib:jdwp=transport=dt_socket,address=8031,server=y,suspend=n</clojureOptions> 
       </configuration>
      <executions>
        <execution>
           <id>compile-clojure</id>
    <phase>compile</phase>
      <goals>
        <goal>compile</goal>
      </goals>
        </execution>
     </executions>
   </plugin>
...

The only quirk that I have noticed configuring it this way is that the the JVM arguments are passed into the compile goal as well as the repl/swank goal, so you will see the debug port open once during compilation, then close and re-open when the repl or swank is running.

My clojure sources are located in a standard maven classpath.
...
     <build>
       <sourceDirectory>src/main/clojure</sourceDirectory>
       <testSourceDirectory>src/test/clojure</testSourceDirectory>
       <resources>
  <resource>
    <directory>src/main/clojure</directory>
  </resource>
  <resource>
    <directory>src/main/resources</directory>
  </resource>
       </resources>
       <testResources>
  <testResource>
    <directory>src/test/clojure</directory>
  </testResource>
       </testResource>
...
I set up my debugging classpath to include the ./src/main/clojure directory relative to the current directory where my sourceDirectory in maven is setup. I have placed the clojure and clojure-contrib sources into my classpath as well. When I am ready to debug, I run this elisp function from the root directory of my project to set the source paths prior to running M-x cdt.
(defun cdt-set-source-path ()
  (interactive)
  (setq cdt-source-path 
 (reduce (lambda (acc f)
    (concat (expand-file-name acc) ":" (expand-file-name f)))
  '("./src/main/clojure"
    "~/.emacs.d/site-lisp/cdt/clojure/clojure-1.2.0/src/jvm"
    "~/.emacs.d/site-lisp/cdt/clojure/clojure-1.2.0/src/clj"
    "~/.emacs.d/site-lisp/cdt/clojure/clojure-contrib-1.2.0/src/main/clojure")
You can also set the cdt-sourch-path via the REPL attached to the debug port via the clojure function:
(set-source-path path)
Where path is the string representation of the classpath.

Usage

Below is a list of CDT functions and their Emacs front end keybindings if applicable.


;; set breakpoints
(line-bp fname line)  ; C-x C-a C-b    set Breakpoint, on the current line
(set-catch Exception :all)  ; break on any exception

;; delete breakpoints
(delete-all-breakpoints)

;; stepping
(stepi)       ; C-x C-a C-i step the smallest possible Increment
(step)        ; C-x C-a C-s Step
(step-over)   ; C-x C-a C-n Next
(finish)      ; C-x C-a C-f Runs to the end of the current function
              ; C-x C-a C-g     Go/continue

;; evaluation
(print-bps)   
(print-frame) 
(print-frames)

;; evaluate an expression in the context of the stackframe
(reval sexpr) 

Example

I have found myself using the debugger mostly when troubleshooting web/compojure applications. In these situations, I am able to reproduce the conditions that cause the application bug, and then set a break point to examine the state of my running application. I have created a simple compojure application that can be found at http://github.com/ffailla/cdt-example that I will use to demostrate how I use the CDT to evaluate a running web application.

cdt-example.clj
(ns ffailla.cdtexample
  (:use compojure.core, ring.adapter.jetty)
  (:require [compojure.route :as route]))

(defn make-map [arg]
  (apply array-map (range (Integer. arg))))

(defn test-fn [arg1 arg2]
  (let [a (str arg1 " abcdefg")
 b (make-map arg2)]
    [a b]))

(defroutes main-routes
  (GET "/" {params :params}
       (let [arg1 (or (params "arg1") "test string arg")
      arg2 (or (params "arg2") 10)]
  (apply str (interpose "\n" (test-fn arg1 arg2)))))
  (route/not-found "Page not found"))

(defn start []
  (run-jetty main-routes {:port 8081 :join? false}))

I first run M-x cdt-set-source-path from the project root directory. This will set the classpath for the cdt to my project sources as well as the clojure sources. Then run M-x cdt to start the debugger, entering the debug port that I specified in my pom.xml file. I now have a buffer called *gud-clojure.main* that I can use.

Current directory is /Users/ffailla/dev/cdt-example/
Clojure 1.2.0
user=> nil
user=> "/Users/ffailla/dev/cdt-example/src/main/clojure:/Users/ffailla/.emacs.d/site-lisp/cdt/clojure/clojure-1.2.0/src/jvm:/Users/ffailla/.emacs.d/site-lisp/cdt/clojure/clojure-1.2.0/src/clj:/Users/ffailla/.emacs.d/site-lisp/cdt/clojure/clojure-contrib-1.2.0/src/main/clojure"
user=> starting event handler
nil

Now I'll set some line break points. This can also be done via C-x C-a C-b.

user=> (line-bp "/Users/ffailla/dev/cdt-example/src/main/clojure/ffailla/cdtexample/clj", 17)
bp set on (#<LocationImpl ffailla.cdtexample$fn__1730$fn__1731:17> #<LocationImpl ffailla.cdtexample$fn__1823$fn__1824:17> #<LocationImpl ffailla.cdtexample$fn__1845$fn__1846:17> #<LocationImpl ffailla.cdtexample$fn__1921$fn__1922:17>)
nil
user=> (line-bp "/Users/ffailla/dev/cdt-example/src/main/clojure/ffailla/cdtexample/clj", 10)
bp set on (#<LocationImpl ffailla.cdtexample$test_fn:10> #<LocationImpl ffailla.cdtexample$test_fn:10>)
nil
user=> (line-bp "/Users/ffailla/dev/cdt-example/src/main/clojure/ffailla/cdtexample/clj", 6)
bp set on (#<LocationImpl ffailla.cdtexample$make_map:6> #<LocationImpl ffailla.cdtexample$make_map:6>)
nil
When I make a GET request via curl http://localhost:8081/, the CDT show the following:

user=> 

Breakpoint # hit

CDT location is /Users/ffailla/dev/cdt-example/src/main/clojure/ffailla/cdtexample.clj:17:0

  0 ffailla.cdtexample$fn__1730$fn__1731 invoke [route-params--441--auto--1737 route--439--auto-- map--1732 params temp--3586--auto--1738 request--440--auto-- request--440--auto--1736 arg1 arg2 this] cdtexample.clj:17
Lets evaluate some variables
user=> (reval params)
nil
user=> (reval arg1)
"test string arg"
user=> (reval arg2)
10
Lets step to the next breakpoint
user=> (step-over)
nil
user=> 

Breakpoint # hit

CDT location is /Users/ffailla/dev/cdt-example/src/main/clojure/ffailla/cdtexample.clj:10:0

  0 ffailla.cdtexample$test_fn invoke [this arg1 arg2] cdtexample.clj:10
Here is a situation I do not understand, why is the reval of arg1 nil, yet arg2 is not? They both have non-nil values.

user=> (reval arg1)
nil

user=> (reval arg2)
10
And local let variables do not appear to be available

user=> (reval a)
"remote exception: java.lang.Exception: Unable to resolve symbol: a in this context (NO_SOURCE_FILE:0)"
Now I'll step over to the next break point and inspect the argument passed in.

user=> (step-over)
nil
user=> 

Breakpoint #<BreakpointEventImpl BreakpointEvent@ffailla.cdtexample$make_map:6 in thread 2115942479@qtp0-0> hit

CDT location is /Users/ffailla/dev/cdt-example/src/main/clojure/ffailla/cdtexample.clj:6:0

  0 ffailla.cdtexample$make_map invoke [this arg] cdtexample.clj:6

user=> (reval arg)
10
I can view my entire stack frame or just my current

user=> (print-frames)
  0 ffailla.cdtexample$make_map invoke [this arg] cdtexample.clj:6
  1 ffailla.cdtexample$test_fn invoke [this arg1 arg2] cdtexample.clj:10
  2 ffailla.cdtexample$fn__1730$fn__1731 invoke [route-params--441--auto--1737 route--439--auto-- map--1732 params temp--3586--auto--1738 request--440--auto-- request--440--auto--1736 arg1 arg2 this] cdtexample.clj:17
  3 compojure.core$routes$fn__444$fn__445 invoke [this request p1--443#] core.clj:71
  4 clojure.core$some invoke [this coll pred] core.clj:2053
  5 compojure.core$routes$fn__444 invoke [this handlers request] core.clj:71
  6 ring.middleware.params$wrap_params$fn__163 invoke [this handler opts request encoding] params.clj:76
  7 ring.middleware.cookies$wrap_cookies$fn__333 invoke [this handler request] cookies.clj:124
  8 ring.adapter.jetty$proxy_handler$fn__531 invoke [this handler target request response dispatch] jetty.clj:17
  9 ring.adapter.jetty.proxy$org.mortbay.jetty.handler.AbstractHandler$0 handle [] source not found:-1
 10 org.mortbay.jetty.handler.HandlerWrapper handle [this dispatch target response request] HandlerWrapper.java:152
 11 org.mortbay.jetty.Server handle [this target connection] Server.java:324
 12 org.mortbay.jetty.HttpConnection handleRequest [this threadName info error retrying] HttpConnection.java:534
 13 org.mortbay.jetty.HttpConnection$RequestHandler headerComplete [this] HttpConnection.java:864
 14 org.mortbay.jetty.HttpParser parseNext [this array total-filled length ch] HttpParser.java:533
 15 org.mortbay.jetty.HttpParser parseAvailable [this] HttpParser.java:207
 16 org.mortbay.jetty.HttpConnection handle [this more-in-buffer io continuation no-progress] HttpConnection.java:403
 17 org.mortbay.jetty.bio.SocketConnector$Connection run [this] SocketConnector.java:228
 18 org.mortbay.thread.QueuedThreadPool$PoolThread run [this todo idle job] QueuedThreadPool.java:522
nil

user=> (print-frame)
  0 ffailla.cdtexample$make_map invoke [this arg] cdtexample.clj:6
nil

Conclusion

The CDT is a very powerful tool, allowing you to inspect and evaluate the running state of oyur program at a particular stack frame. There are still some quirks which I have not investigated yet, such as why local let variables are not available, and why are some function args avaiable for inspection while others are not. More to come...