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...

No comments: